Revert "Automatically track subloggers in allLoggers (#22038)" (#24004)

This reverts commit 4c8cc87.

command/server.go

@@ -37,7 +37,6 @@ import (
 	"github.com/hashicorp/vault/helper/builtinplugins"
 	"github.com/hashicorp/vault/helper/constants"
 	"github.com/hashicorp/vault/helper/experiments"
-	"github.com/hashicorp/vault/helper/logging"
 	loghelper "github.com/hashicorp/vault/helper/logging"
 	"github.com/hashicorp/vault/helper/metricsutil"
 	"github.com/hashicorp/vault/helper/namespace"
@@ -116,7 +115,6 @@ type ServerCommand struct {
 	licenseReloadedCh chan (error)    // for tests
 
 	allLoggers []hclog.Logger
-	logging.SubloggerAdder
 
 	flagConfigs            []string
 	flagRecovery           bool
@@ -431,26 +429,6 @@ func (c *ServerCommand) parseConfig() (*server.Config, []configutil.ConfigError,
 	return config, configErrors, nil
 }
 
-// AppendToAllLoggers is registered with the base logger to handle creation of
-// new subloggers through the phases of server startup. There are three phases
-// we need to handle: (1) Before CoreConfig is created, new subloggers are added
-// to c.allLoggers; (2) After CoreConfig is created, new subloggers are added to
-// CoreConfig.AllLoggers; (3) After Core instantiation, new subloggers are
-// appended to Core.allLoggers. This logic is managed by the SubloggerAdder
-// interface.
-//
-// NOTE: Core.allLoggers must be set to CoreConfig.allLoggers after NewCore to
-// keep track of new subloggers added before c.SubloggerAdder gets reassigned to
-// the Core implementation.
-func (c *ServerCommand) AppendToAllLoggers(sub hclog.Logger) hclog.Logger {
-	if c.SubloggerAdder == nil {
-		c.allLoggers = append(c.allLoggers, sub)
-		return sub
-	}
-
-	return c.SubloggerHook(sub)
-}
-
 func (c *ServerCommand) runRecoveryMode() int {
 	config, configErrors, err := c.parseConfig()
 	if err != nil {
@@ -600,7 +578,6 @@ func (c *ServerCommand) runRecoveryMode() int {
 		DisableMlock: config.DisableMlock,
 		RecoveryMode: c.flagRecovery,
 		ClusterAddr:  config.ClusterAddr,
-		AllLoggers:   c.allLoggers,
 	}
 
 	core, newCoreError := vault.NewCore(coreConfig)
@@ -824,6 +801,7 @@ func (c *ServerCommand) setupStorage(config *server.Config) (physical.Backend, e
 	}
 
 	namedStorageLogger := c.logger.Named("storage." + config.Storage.Type)
+	c.allLoggers = append(c.allLoggers, namedStorageLogger)
 	backend, err := factory(config.Storage.Config, namedStorageLogger)
 	if err != nil {
 		return nil, fmt.Errorf("Error initializing storage of type %s: %w", config.Storage.Type, err)
@@ -839,6 +817,7 @@ func beginServiceRegistration(c *ServerCommand, config *server.Config) (sr.Servi
 	}
 
 	namedSDLogger := c.logger.Named("service_registration." + config.ServiceRegistration.Type)
+	c.allLoggers = append(c.allLoggers, namedSDLogger)
 
 	// Since we haven't even begun starting Vault's core yet,
 	// we know that Vault is in its pre-running state.
@@ -1108,6 +1087,7 @@ func (c *ServerCommand) Run(args []string) int {
 
 	// create GRPC logger
 	namedGRPCLogFaker := c.logger.Named("grpclogfaker")
+	c.allLoggers = append(c.allLoggers, namedGRPCLogFaker)
 	grpclog.SetLogger(&grpclogFaker{
 		logger: namedGRPCLogFaker,
 		log:    os.Getenv("VAULT_GRPC_LOGGING") != "",
@@ -1267,10 +1247,6 @@ func (c *ServerCommand) Run(args []string) int {
 		return c.enableThreeNodeDevCluster(&coreConfig, info, infoKeys, c.flagDevListenAddr, os.Getenv("VAULT_DEV_TEMP_DIR"))
 	}
 
-	// Keep track of new subloggers in coreConfig.AllLoggers until we hand it
-	// off to core
-	c.SubloggerAdder = &coreConfig
-
 	if c.flagDevFourCluster {
 		return enableFourClusterDev(c, &coreConfig, info, infoKeys, c.flagDevListenAddr, os.Getenv("VAULT_DEV_TEMP_DIR"))
 	}
@@ -1358,10 +1334,6 @@ func (c *ServerCommand) Run(args []string) int {
 
 	}
 
-	// Now we can use the core SubloggerHook to add any new subloggers to
-	// core.allLoggers
-	c.SubloggerAdder = core
-
 	// Copy the reload funcs pointers back
 	c.reloadFuncs = coreConfig.ReloadFuncs
 	c.reloadFuncsLock = coreConfig.ReloadFuncsLock
@@ -1811,7 +1783,6 @@ func (c *ServerCommand) configureLogging(config *server.Config) (hclog.Intercept
 		LogRotateDuration: logRotateDuration,
 		LogRotateBytes:    config.LogRotateBytes,
 		LogRotateMaxFiles: config.LogRotateMaxFiles,
-		SubloggerHook:     c.AppendToAllLoggers,
 	}
 
 	return loghelper.Setup(logCfg, c.logWriter)
@@ -2476,6 +2447,7 @@ func setSeal(c *ServerCommand, config *server.Config, infoKeys []string, info ma
 
 		var seal vault.Seal
 		sealLogger := c.logger.ResetNamed(fmt.Sprintf("seal.%s", sealType))
+		c.allLoggers = append(c.allLoggers, sealLogger)
 		defaultSeal := vault.NewDefaultSeal(&vaultseal.Access{
 			Wrapper: aeadwrapper.NewShamirWrapper(),
 		})
@@ -2534,6 +2506,7 @@ func initHaBackend(c *ServerCommand, config *server.Config, coreConfig *vault.Co
 		}
 
 		namedHALogger := c.logger.Named("ha." + config.HAStorage.Type)
+		c.allLoggers = append(c.allLoggers, namedHALogger)
 		habackend, err := factory(config.HAStorage.Config, namedHALogger)
 		if err != nil {
 			return false, fmt.Errorf("Error initializing HA storage of type %s: %s", config.HAStorage.Type, err)

helper/logging/logger.go

@@ -45,17 +45,6 @@ type LogConfig struct {
 
 	// LogRotateMaxFiles is the maximum number of past archived log files to keep
 	LogRotateMaxFiles int
-
-	// SubloggerHook handles creation of new subloggers, automatically appending
-	// them to core's running list of allLoggers.
-	// see: server.AppendToAllLoggers for more details.
-	SubloggerHook func(log.Logger) log.Logger
-}
-
-// SubloggerAdder is an interface which facilitates tracking of new subloggers
-// added between phases of server startup.
-type SubloggerAdder interface {
-	SubloggerHook(logger log.Logger) log.Logger
 }
 
 func (c *LogConfig) isLevelInvalid() bool {
@@ -156,7 +145,6 @@ func Setup(config *LogConfig, w io.Writer) (log.InterceptLogger, error) {
 		IndependentLevels: true,
 		Output:            io.MultiWriter(writers...),
 		JSONFormat:        config.isFormatJson(),
-		SubloggerHook:     config.SubloggerHook,
 	})
 
 	return logger, nil

helper/testhelpers/corehelpers/corehelpers.go

@@ -15,7 +15,6 @@ import (
 	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/vault/audit"
 	"github.com/hashicorp/vault/builtin/credential/approle"
-	"github.com/hashicorp/vault/helper/logging"
 	"github.com/hashicorp/vault/plugins/database/mysql"
 	"github.com/hashicorp/vault/sdk/framework"
 	"github.com/hashicorp/vault/sdk/helper/consts"
@@ -388,32 +387,6 @@ type TestLogger struct {
 	Path string
 	File *os.File
 	sink hclog.SinkAdapter
-	// For managing temporary start-up state
-	sync.RWMutex
-	AllLoggers []hclog.Logger
-	logging.SubloggerAdder
-}
-
-// RegisterSubloggerAdder checks to see if the provided logger interface is a
-// TestLogger and re-assigns the SubloggerHook implementation if so.
-func RegisterSubloggerAdder(logger hclog.Logger, adder logging.SubloggerAdder) {
-	if l, ok := logger.(*TestLogger); ok {
-		l.Lock()
-		l.SubloggerAdder = adder
-		l.Unlock()
-	}
-}
-
-// AppendToAllLoggers appends the sub logger to allLoggers, or if the TestLogger
-// is assigned to a SubloggerAdder implementation, it calls the underlying hook.
-func (l *TestLogger) AppendToAllLoggers(sub hclog.Logger) hclog.Logger {
-	l.Lock()
-	defer l.Unlock()
-	if l.SubloggerAdder == nil {
-		l.AllLoggers = append(l.AllLoggers, sub)
-		return sub
-	}
-	return l.SubloggerHook(sub)
 }
 
 func NewTestLogger(t testing.T) *TestLogger {
@@ -437,31 +410,25 @@ func NewTestLogger(t testing.T) *TestLogger {
 		output = logFile
 	}
 
-	sink := hclog.NewSinkAdapter(&hclog.LoggerOptions{
-		Output:            output,
-		Level:             hclog.Trace,
-		IndependentLevels: true,
-	})
-
-	testLogger := &TestLogger{
-		Path: logPath,
-		File: logFile,
-		sink: sink,
-	}
-
 	// We send nothing on the regular logger, that way we can later deregister
 	// the sink to stop logging during cluster cleanup.
 	logger := hclog.NewInterceptLogger(&hclog.LoggerOptions{
 		Output:            io.Discard,
 		IndependentLevels: true,
 		Name:              t.Name(),
-		SubloggerHook:     testLogger.AppendToAllLoggers,
 	})
-
+	sink := hclog.NewSinkAdapter(&hclog.LoggerOptions{
+		Output:            output,
+		Level:             hclog.Trace,
+		IndependentLevels: true,
+	})
 	logger.RegisterSink(sink)
-	testLogger.InterceptLogger = logger
-
-	return testLogger
+	return &TestLogger{
+		Path:            logPath,
+		File:            logFile,
+		InterceptLogger: logger,
+		sink:            sink,
+	}
 }
 
 func (tl *TestLogger) StopLogging() {

vault/activity_log.go

@@ -1090,6 +1090,7 @@ func (c *Core) setupActivityLog(ctx context.Context, wg *sync.WaitGroup) error {
 // this function should be called with activityLogLock.
 func (c *Core) setupActivityLogLocked(ctx context.Context, wg *sync.WaitGroup) error {
 	logger := c.baseLogger.Named("activity")
+	c.AddLogger(logger)
 
 	if os.Getenv("VAULT_DISABLE_ACTIVITY_LOG") != "" {
 		if c.CensusLicensingEnabled() {

vault/audit.go

@@ -378,6 +378,7 @@ func (c *Core) persistAudit(ctx context.Context, table *MountTable, localOnly bo
 // initialize the audit backends
 func (c *Core) setupAudits(ctx context.Context) error {
 	brokerLogger := c.baseLogger.Named("audit")
+	c.AddLogger(brokerLogger)
 	broker := NewAuditBroker(brokerLogger)
 
 	c.auditLock.Lock()
@@ -486,6 +487,7 @@ func (c *Core) newAuditBackend(ctx context.Context, entry *MountEntry, view logi
 	}
 
 	auditLogger := c.baseLogger.Named("audit")
+	c.AddLogger(auditLogger)
 
 	switch entry.Type {
 	case "file":

vault/auth.go

@@ -994,6 +994,7 @@ func (c *Core) newCredentialBackend(ctx context.Context, entry *MountEntry, sysV
 	conf["plugin_version"] = entry.Version
 
 	authLogger := c.baseLogger.Named(fmt.Sprintf("auth.%s.%s", t, entry.Accessor))
+	c.AddLogger(authLogger)
 	pluginEventSender, err := c.events.WithPlugin(entry.namespace, &logical.EventPluginInfo{
 		MountClass:    consts.PluginTypeCredential.String(),
 		MountAccessor: entry.Accessor,

vault/cluster.go

@@ -320,6 +320,7 @@ func (c *Core) startClusterListener(ctx context.Context) error {
 	if networkLayer == nil {
 		tcpLogger := c.logger.Named("cluster-listener.tcp")
 		networkLayer = cluster.NewTCPLayer(c.clusterListenerAddrs, tcpLogger)
+		c.AddLogger(tcpLogger)
 	}
 
 	listenerLogger := c.logger.Named("cluster-listener")
@@ -328,6 +329,8 @@ func (c *Core) startClusterListener(ctx context.Context) error {
 		listenerLogger,
 		5*c.clusterHeartbeatInterval))
 
+	c.AddLogger(listenerLogger)
+
 	err := c.getClusterListener().Run(ctx)
 	if err != nil {
 		return err

vault/core.go

@@ -870,13 +870,6 @@ type CoreConfig struct {
 	NumRollbackWorkers int
 }
 
-// SubloggerHook implements the SubloggerAdder interface. This implementation
-// manages CoreConfig.AllLoggers state prior to (and during) NewCore.
-func (c *CoreConfig) SubloggerHook(logger log.Logger) log.Logger {
-	c.AllLoggers = append(c.AllLoggers, logger)
-	return logger
-}
-
 // GetServiceRegistration returns the config's ServiceRegistration, or nil if it does
 // not exist.
 func (c *CoreConfig) GetServiceRegistration() sr.ServiceRegistration {
@@ -1064,7 +1057,10 @@ func CreateCore(conf *CoreConfig) (*Core, error) {
 
 	c.shutdownDoneCh.Store(make(chan struct{}))
 
+	c.allLoggers = append(c.allLoggers, c.logger)
+
 	c.router.logger = c.logger.Named("router")
+	c.allLoggers = append(c.allLoggers, c.router.logger)
 
 	c.inFlightReqData = &InFlightRequests{
 		InFlightReqMap:   &sync.Map{},
@@ -1214,6 +1210,9 @@ func NewCore(conf *CoreConfig) (*Core, error) {
 
 	// MFA method
 	c.loginMFABackend = NewLoginMFABackend(c, conf.Logger)
+	if c.loginMFABackend.mfaLogger != nil {
+		c.AddLogger(c.loginMFABackend.mfaLogger)
+	}
 
 	// Logical backends
 	c.configureLogicalBackends(conf.LogicalBackends, conf.Logger, conf.AdministrativeNamespacePath)
@@ -1239,6 +1238,7 @@ func NewCore(conf *CoreConfig) (*Core, error) {
 
 	// Quotas
 	quotasLogger := conf.Logger.Named("quotas")
+	c.allLoggers = append(c.allLoggers, quotasLogger)
 
 	detectDeadlocks := false
 	for _, v := range c.detectDeadlocks {
@@ -1264,7 +1264,10 @@ func NewCore(conf *CoreConfig) (*Core, error) {
 	}
 
 	// Events
-	events, err := eventbus.NewEventBus(conf.Logger.Named("events"))
+	eventsLogger := conf.Logger.Named("events")
+	c.allLoggers = append(c.allLoggers, eventsLogger)
+	// start the event system
+	events, err := eventbus.NewEventBus(eventsLogger)
 	if err != nil {
 		return nil, err
 	}
@@ -1273,11 +1276,6 @@ func NewCore(conf *CoreConfig) (*Core, error) {
 		c.events.Start()
 	}
 
-	// Make sure we're keeping track of the subloggers added above. We haven't
-	// yet registered core to the server command's SubloggerAdder, so any new
-	// subloggers will be in conf.AllLoggers.
-	c.allLoggers = conf.AllLoggers
-
 	return c, nil
 }
 
@@ -1336,7 +1334,9 @@ func (c *Core) configureCredentialsBackends(backends map[string]logical.Factory,
 	}
 
 	credentialBackends[mountTypeToken] = func(ctx context.Context, config *logical.BackendConfig) (logical.Backend, error) {
-		return NewTokenStore(ctx, logger.Named("token"), c, config)
+		tsLogger := logger.Named("token")
+		c.AddLogger(tsLogger)
+		return NewTokenStore(ctx, tsLogger, c, config)
 	}
 
 	c.credentialBackends = credentialBackends
@@ -1364,7 +1364,9 @@ func (c *Core) configureLogicalBackends(backends map[string]logical.Factory, log
 
 	// System
 	logicalBackends[mountTypeSystem] = func(ctx context.Context, config *logical.BackendConfig) (logical.Backend, error) {
-		b := NewSystemBackend(c, logger.Named("system"))
+		sysBackendLogger := logger.Named("system")
+		c.AddLogger(sysBackendLogger)
+		b := NewSystemBackend(c, sysBackendLogger)
 		if err := b.Setup(ctx, config); err != nil {
 			return nil, err
 		}
@@ -1373,7 +1375,9 @@ func (c *Core) configureLogicalBackends(backends map[string]logical.Factory, log
 
 	// Identity
 	logicalBackends[mountTypeIdentity] = func(ctx context.Context, config *logical.BackendConfig) (logical.Backend, error) {
-		return NewIdentityStore(ctx, c, config, logger.Named("identity"))
+		identityLogger := logger.Named("identity")
+		c.AddLogger(identityLogger)
+		return NewIdentityStore(ctx, c, config, identityLogger)
 	}
 
 	c.logicalBackends = logicalBackends
@@ -3143,14 +3147,6 @@ func (c *Core) AddLogger(logger log.Logger) {
 	c.allLoggers = append(c.allLoggers, logger)
 }
 
-// SubloggerHook implements the SubloggerAdder interface. We add this method to
-// the server command after NewCore returns with a Core object. The hook keeps
-// track of newly added subloggers without manual calls to c.AddLogger.
-func (c *Core) SubloggerHook(logger log.Logger) log.Logger {
-	c.AddLogger(logger)
-	return logger
-}
-
 // SetLogLevel sets logging level for all tracked loggers to the level provided
 func (c *Core) SetLogLevel(level log.Level) {
 	c.allLoggersLock.RLock()