Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 1 commit into from
Nov 3, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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 @@ -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"
Expand Down Expand Up @@ -116,7 +115,6 @@ type ServerCommand struct {
licenseReloadedCh chan (error) // for tests

allLoggers []hclog.Logger
logging.SubloggerAdder

flagConfigs []string
flagRecovery bool
Expand Down Expand Up @@ -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 {
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand All @@ -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.
Expand Down Expand Up @@ -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") != "",
Expand Down Expand Up @@ -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"))
}
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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(),
})
Expand Down Expand Up @@ -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)
Expand Down
12 changes: 0 additions & 12 deletions helper/logging/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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
Expand Down
55 changes: 11 additions & 44 deletions helper/testhelpers/corehelpers/corehelpers.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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 {
Expand All @@ -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() {
Expand Down
1 change: 1 addition & 0 deletions vault/activity_log.go
Original file line number Diff line number Diff line change
Expand Up @@ -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() {
Expand Down
2 changes: 2 additions & 0 deletions vault/audit.go
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand Down Expand Up @@ -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":
Expand Down
1 change: 1 addition & 0 deletions vault/auth.go
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
3 changes: 3 additions & 0 deletions vault/cluster.go
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand All @@ -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
Expand Down
44 changes: 20 additions & 24 deletions vault/core.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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{},
Expand Down Expand Up @@ -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)
Expand All @@ -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 {
Expand All @@ -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
}
Expand All @@ -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
}

Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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
}
Expand All @@ -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
Expand Down Expand Up @@ -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()
Expand Down
Loading