Skip to content

Commit

Permalink
Revert "Automatically track subloggers in allLoggers (#22038)"
Browse files Browse the repository at this point in the history
This reverts commit 4c8cc87.
  • Loading branch information
hghaf099 committed Nov 3, 2023
1 parent 1c9090b commit 563eb6b
Show file tree
Hide file tree
Showing 19 changed files with 70 additions and 139 deletions.
3 changes: 0 additions & 3 deletions changelog/22038.txt

This file was deleted.

37 changes: 5 additions & 32 deletions command/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -44,7 +44,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"
Expand Down Expand Up @@ -119,7 +118,6 @@ type ServerCommand struct {
licenseReloadedCh chan (error) // for tests

allLoggers []hclog.Logger
logging.SubloggerAdder

flagConfigs []string
flagRecovery bool
Expand Down Expand Up @@ -454,26 +452,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 {
Expand Down Expand Up @@ -608,7 +586,6 @@ func (c *ServerCommand) runRecoveryMode() int {
DisableMlock: config.DisableMlock,
RecoveryMode: c.flagRecovery,
ClusterAddr: config.ClusterAddr,
AllLoggers: c.allLoggers,
}

core, newCoreError := vault.NewCore(coreConfig)
Expand Down Expand Up @@ -832,6 +809,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)
Expand All @@ -847,6 +825,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.
Expand Down Expand Up @@ -1139,6 +1118,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") != "",
Expand Down Expand Up @@ -1316,10 +1296,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 entEnableFourClusterDev(c, &coreConfig, info, infoKeys, os.Getenv("VAULT_DEV_TEMP_DIR"))
}
Expand Down Expand Up @@ -1407,10 +1383,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
Expand Down Expand Up @@ -1890,7 +1862,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)
Expand Down Expand Up @@ -2639,6 +2610,7 @@ func setSeal(c *ServerCommand, config *server.Config, infoKeys []string, info ma
}

sealLogger := c.logger.ResetNamed(fmt.Sprintf("seal.%s", configSeal.Type))
c.allLoggers = append(c.allLoggers, sealLogger)

allSealKmsConfigs = append(allSealKmsConfigs, configSeal)
var wrapperInfoKeys []string
Expand Down Expand Up @@ -2847,6 +2819,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)
Expand Down
12 changes: 0 additions & 12 deletions helper/logging/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -48,17 +48,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 {
Expand Down Expand Up @@ -159,7 +148,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
Expand Down
54 changes: 12 additions & 42 deletions helper/testhelpers/corehelpers/corehelpers.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,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"
Expand Down Expand Up @@ -459,32 +458,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 {
Expand All @@ -508,29 +481,26 @@ 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

testLogger := &TestLogger{
Path: logPath,
File: logFile,
InterceptLogger: logger,
sink: sink,
}

t.Cleanup(func() {
testLogger.StopLogging()
Expand Down
1 change: 1 addition & 0 deletions vault/activity_log.go
Original file line number Diff line number Diff line change
Expand Up @@ -1101,6 +1101,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() {
Expand Down
2 changes: 2 additions & 0 deletions vault/audit.go
Original file line number Diff line number Diff line change
Expand Up @@ -391,6 +391,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)

disableEventLogger, err := parseutil.ParseBool(os.Getenv(featureFlagDisableEventLogger))
if err != nil {
Expand Down Expand Up @@ -517,6 +518,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":
Expand Down
1 change: 1 addition & 0 deletions vault/auth.go
Original file line number Diff line number Diff line change
Expand Up @@ -997,6 +997,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,
Expand Down
3 changes: 3 additions & 0 deletions vault/cluster.go
Original file line number Diff line number Diff line change
Expand Up @@ -323,6 +323,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")
Expand All @@ -331,6 +332,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
Expand Down
39 changes: 18 additions & 21 deletions vault/core.go
Original file line number Diff line number Diff line change
Expand Up @@ -862,13 +862,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 {
Expand Down Expand Up @@ -1055,7 +1048,11 @@ 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.router.rollbackMetricsMountName = c.rollbackMountPathMetrics

c.inFlightReqData = &InFlightRequests{
Expand Down Expand Up @@ -1208,6 +1205,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)
Expand All @@ -1233,6 +1233,7 @@ func NewCore(conf *CoreConfig) (*Core, error) {

// Quotas
quotasLogger := conf.Logger.Named("quotas")
c.allLoggers = append(c.allLoggers, quotasLogger)

detectDeadlocks := slices.Contains(c.detectDeadlocks, "quotas")
c.quotaManager, err = quotas.NewManager(quotasLogger, c.quotaLeaseWalker, c.metricSink, detectDeadlocks)
Expand All @@ -1252,18 +1253,16 @@ 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
}
c.events = events
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
}

Expand Down Expand Up @@ -1322,6 +1321,8 @@ func (c *Core) configureCredentialsBackends(backends map[string]logical.Factory,
}

credentialBackends[mountTypeToken] = func(ctx context.Context, config *logical.BackendConfig) (logical.Backend, error) {
tsLogger := logger.Named("token")
c.AddLogger(tsLogger)
return NewTokenStore(ctx, logger.Named("token"), c, config)
}

Expand Down Expand Up @@ -1350,6 +1351,8 @@ func (c *Core) configureLogicalBackends(backends map[string]logical.Factory, log

// System
logicalBackends[mountTypeSystem] = func(ctx context.Context, config *logical.BackendConfig) (logical.Backend, error) {
sysBackendLogger := logger.Named("system")
c.AddLogger(sysBackendLogger)
b := NewSystemBackend(c, logger.Named("system"))
if err := b.Setup(ctx, config); err != nil {
return nil, err
Expand All @@ -1359,6 +1362,8 @@ func (c *Core) configureLogicalBackends(backends map[string]logical.Factory, log

// Identity
logicalBackends[mountTypeIdentity] = func(ctx context.Context, config *logical.BackendConfig) (logical.Backend, error) {
identityLogger := logger.Named("identity")
c.AddLogger(identityLogger)
return NewIdentityStore(ctx, c, config, logger.Named("identity"))
}

Expand Down Expand Up @@ -3203,14 +3208,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()
Expand Down
Loading

0 comments on commit 563eb6b

Please sign in to comment.