Add endpoints to provide ability to modify logging verbosity (#16111)

* add func to set level for specific logger

* add endpoints to modify log level

* initialize base logger with IndependentLevels

* test to ensure other loggers remain unchanged

* add DELETE loggers endpoints to revert back to config

* add API docs page

* add changelog entry

* remove extraneous line

* add log level field to Core struct

* add godoc for getLogLevel

* add some loggers to c.allLoggers
This commit is contained in:
Chris Capurso 2022-06-27 11:39:53 -04:00 committed by GitHub
parent 2e56c7fe0a
commit 9501d44ed5
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
13 changed files with 587 additions and 17 deletions

3
changelog/16111.txt Normal file
View File

@ -0,0 +1,3 @@
```release-note:improvement
core: Add `sys/loggers` and `sys/loggers/:name` endpoints to provide ability to modify logging verbosity
```

View File

@ -460,8 +460,9 @@ func (c *ServerCommand) runRecoveryMode() int {
}
c.logger = hclog.NewInterceptLogger(&hclog.LoggerOptions{
Output: c.gatedWriter,
Level: level,
Output: c.gatedWriter,
Level: level,
IndependentLevels: true,
// Note that if logFormat is either unspecified or standard, then
// the resulting logger's format will be standard.
JSONFormat: logFormat == logging.JSONFormat,
@ -592,6 +593,7 @@ func (c *ServerCommand) runRecoveryMode() int {
Physical: backend,
StorageType: config.Storage.Type,
Seal: barrierSeal,
LogLevel: logLevelString,
Logger: c.logger,
DisableMlock: config.DisableMlock,
RecoveryMode: c.flagRecovery,
@ -1116,14 +1118,16 @@ func (c *ServerCommand) Run(args []string) int {
if c.flagDevThreeNode || c.flagDevFourCluster {
c.logger = hclog.NewInterceptLogger(&hclog.LoggerOptions{
Mutex: &sync.Mutex{},
Output: c.gatedWriter,
Level: hclog.Trace,
Mutex: &sync.Mutex{},
Output: c.gatedWriter,
Level: hclog.Trace,
IndependentLevels: true,
})
} else {
c.logger = hclog.NewInterceptLogger(&hclog.LoggerOptions{
Output: c.gatedWriter,
Level: level,
Output: c.gatedWriter,
Level: level,
IndependentLevels: true,
// Note that if logFormat is either unspecified or standard, then
// the resulting logger's format will be standard.
JSONFormat: logFormat == logging.JSONFormat,

View File

@ -42,9 +42,10 @@ func NewVaultLogger(level log.Level) log.Logger {
// writer and a Vault formatter
func NewVaultLoggerWithWriter(w io.Writer, level log.Level) log.Logger {
opts := &log.LoggerOptions{
Level: level,
Output: w,
JSONFormat: ParseEnvLogFormat() == JSONFormat,
Level: level,
IndependentLevels: true,
Output: w,
JSONFormat: ParseEnvLogFormat() == JSONFormat,
}
return log.New(opts)
}

View File

@ -318,14 +318,19 @@ func (c *Core) startClusterListener(ctx context.Context) error {
networkLayer := c.clusterNetworkLayer
if networkLayer == nil {
networkLayer = cluster.NewTCPLayer(c.clusterListenerAddrs, c.logger.Named("cluster-listener.tcp"))
tcpLogger := c.logger.Named("cluster-listener.tcp")
networkLayer = cluster.NewTCPLayer(c.clusterListenerAddrs, tcpLogger)
c.AddLogger(tcpLogger)
}
listenerLogger := c.logger.Named("cluster-listener")
c.clusterListener.Store(cluster.NewListener(networkLayer,
c.clusterCipherSuites,
c.logger.Named("cluster-listener"),
listenerLogger,
5*c.clusterHeartbeatInterval))
c.AddLogger(listenerLogger)
err := c.getClusterListener().Run(ctx)
if err != nil {
return err

View File

@ -408,6 +408,9 @@ type Core struct {
baseLogger log.Logger
logger log.Logger
// log level provided by config, CLI flag, or env
logLevel string
// Disables the trace display for Sentinel checks
sentinelTraceDisabled bool
@ -665,6 +668,8 @@ type CoreConfig struct {
SecureRandomReader io.Reader
LogLevel string
Logger log.Logger
// Disables the trace display for Sentinel checks
@ -848,6 +853,7 @@ func CreateCore(conf *CoreConfig) (*Core, error) {
standbyStopCh: new(atomic.Value),
baseLogger: conf.Logger,
logger: conf.Logger.Named("core"),
logLevel: conf.LogLevel,
defaultLeaseTTL: conf.DefaultLeaseTTL,
maxLeaseTTL: conf.MaxLeaseTTL,
@ -1034,6 +1040,10 @@ func NewCore(conf *CoreConfig) (*Core, error) {
c.loginMFABackend = NewLoginMFABackend(c, conf.Logger)
if c.loginMFABackend.mfaLogger != nil {
c.AddLogger(c.loginMFABackend.mfaLogger)
}
logicalBackends := make(map[string]logical.Factory)
for k, f := range conf.LogicalBackends {
logicalBackends[k] = f
@ -2816,6 +2826,19 @@ func (c *Core) SetLogLevel(level log.Level) {
}
}
func (c *Core) SetLogLevelByName(name string, level log.Level) error {
c.allLoggersLock.RLock()
defer c.allLoggersLock.RUnlock()
for _, logger := range c.allLoggers {
if logger.Name() == name {
logger.SetLevel(level)
return nil
}
}
return fmt.Errorf("logger %q does not exist", name)
}
// SetConfig sets core's config object to the newly provided config.
func (c *Core) SetConfig(conf *server.Config) {
c.rawConfig.Store(conf)

View File

@ -313,9 +313,12 @@ func getNumExpirationWorkers(c *Core, l log.Logger) int {
// NewExpirationManager creates a new ExpirationManager that is backed
// using a given view, and uses the provided router for revocation.
func NewExpirationManager(c *Core, view *BarrierView, e ExpireLeaseStrategy, logger log.Logger) *ExpirationManager {
jobManager := fairshare.NewJobManager("expire", getNumExpirationWorkers(c, logger), logger.Named("job-manager"), c.metricSink)
managerLogger := logger.Named("job-manager")
jobManager := fairshare.NewJobManager("expire", getNumExpirationWorkers(c, logger), managerLogger, c.metricSink)
jobManager.Start()
c.AddLogger(managerLogger)
exp := &ExpirationManager{
core: c,
router: c.router,
@ -1268,7 +1271,8 @@ func (m *ExpirationManager) Renew(ctx context.Context, leaseID string, increment
// RenewToken is used to renew a token which does not need to
// invoke a logical backend.
func (m *ExpirationManager) RenewToken(ctx context.Context, req *logical.Request, te *logical.TokenEntry,
increment time.Duration) (*logical.Response, error) {
increment time.Duration,
) (*logical.Response, error) {
defer metrics.MeasureSince([]string{"expire", "renew-token"}, time.Now())
tokenNS, err := NamespaceByID(ctx, te.NamespaceID, m.core)

View File

@ -4436,6 +4436,112 @@ func (b *SystemBackend) handleVersionHistoryList(ctx context.Context, req *logic
return logical.ListResponseWithInfo(respKeys, respKeyInfo), nil
}
// getLogLevel returns the hclog.Level that corresponds with the provided level string.
// This differs hclog.LevelFromString in that it supports additional level strings so
// that in remains consistent with the handling found in the "vault server" command.
func getLogLevel(logLevel string) (log.Level, error) {
var level log.Level
switch logLevel {
case "trace":
level = log.Trace
case "debug":
level = log.Debug
case "notice", "info", "":
level = log.Info
case "warn", "warning":
level = log.Warn
case "err", "error":
level = log.Error
default:
return level, fmt.Errorf("unrecognized log level %q", logLevel)
}
return level, nil
}
func (b *SystemBackend) handleLoggersWrite(ctx context.Context, req *logical.Request, d *framework.FieldData) (*logical.Response, error) {
logLevelRaw, ok := d.GetOk("level")
if !ok {
return logical.ErrorResponse("level is required"), nil
}
logLevel := logLevelRaw.(string)
if logLevel == "" {
return logical.ErrorResponse("level is empty"), nil
}
level, err := getLogLevel(logLevel)
if err != nil {
return logical.ErrorResponse(fmt.Sprintf("invalid level provided: %s", err.Error())), nil
}
b.Core.SetLogLevel(level)
return nil, nil
}
func (b *SystemBackend) handleLoggersDelete(ctx context.Context, req *logical.Request, d *framework.FieldData) (*logical.Response, error) {
level, err := getLogLevel(b.Core.logLevel)
if err != nil {
return logical.ErrorResponse(fmt.Sprintf("log level from config is invalid: %s", err.Error())), nil
}
b.Core.SetLogLevel(level)
return nil, nil
}
func (b *SystemBackend) handleLoggersByNameWrite(ctx context.Context, req *logical.Request, d *framework.FieldData) (*logical.Response, error) {
nameRaw, nameOk := d.GetOk("name")
if !nameOk {
return logical.ErrorResponse("name is required"), nil
}
logLevelRaw, logLevelOk := d.GetOk("level")
if !logLevelOk {
return logical.ErrorResponse("level is required"), nil
}
logLevel := logLevelRaw.(string)
if logLevel == "" {
return logical.ErrorResponse("level is empty"), nil
}
level, err := getLogLevel(logLevel)
if err != nil {
return logical.ErrorResponse(fmt.Sprintf("invalid level provided: %s", err.Error())), nil
}
err = b.Core.SetLogLevelByName(nameRaw.(string), level)
if err != nil {
return logical.ErrorResponse(fmt.Sprintf("invalid params: %s", err.Error())), nil
}
return nil, nil
}
func (b *SystemBackend) handleLoggersByNameDelete(ctx context.Context, req *logical.Request, d *framework.FieldData) (*logical.Response, error) {
nameRaw, ok := d.GetOk("name")
if !ok {
return logical.ErrorResponse("name is required"), nil
}
level, err := getLogLevel(b.Core.logLevel)
if err != nil {
return logical.ErrorResponse(fmt.Sprintf("log level from config is invalid: %s", err.Error())), nil
}
err = b.Core.SetLogLevelByName(nameRaw.(string), level)
if err != nil {
return logical.ErrorResponse(fmt.Sprintf("invalid params: %s", err.Error())), nil
}
return nil, nil
}
func sanitizePath(path string) string {
if !strings.HasSuffix(path, "/") {
path += "/"

View File

@ -288,6 +288,50 @@ func (b *SystemBackend) configPaths() []*framework.Path {
},
},
},
{
Pattern: "loggers$",
Fields: map[string]*framework.FieldSchema{
"level": {
Type: framework.TypeString,
Description: "Log verbosity level. Supported values (in order of detail) are " +
"\"trace\", \"debug\", \"info\", \"warn\", and \"error\".",
},
},
Operations: map[logical.Operation]framework.OperationHandler{
logical.UpdateOperation: &framework.PathOperation{
Callback: b.handleLoggersWrite,
Summary: "Modify the log level for all existing loggers.",
},
logical.DeleteOperation: &framework.PathOperation{
Callback: b.handleLoggersDelete,
Summary: "Revert the all loggers to use log level provided in config.",
},
},
},
{
Pattern: "loggers/" + framework.MatchAllRegex("name"),
Fields: map[string]*framework.FieldSchema{
"name": {
Type: framework.TypeString,
Description: "The name of the logger to be modified.",
},
"level": {
Type: framework.TypeString,
Description: "Log verbosity level. Supported values (in order of detail) are " +
"\"trace\", \"debug\", \"info\", \"warn\", and \"error\".",
},
},
Operations: map[logical.Operation]framework.OperationHandler{
logical.UpdateOperation: &framework.PathOperation{
Callback: b.handleLoggersByNameWrite,
Summary: "Modify the log level of a single logger.",
},
logical.DeleteOperation: &framework.PathOperation{
Callback: b.handleLoggersByNameDelete,
Summary: "Revert a single logger to use log level provided in config.",
},
},
},
}
}

View File

@ -4556,3 +4556,274 @@ func TestProcessLimit(t *testing.T) {
}
}
}
func validateLevel(level string, logger hclog.Logger) bool {
switch level {
case "trace":
return logger.IsTrace()
case "debug":
return logger.IsDebug()
case "notice", "info", "":
return logger.IsInfo()
case "warn", "warning":
return logger.IsWarn()
case "err", "error":
return logger.IsError()
}
return false
}
func TestSystemBackend_Loggers(t *testing.T) {
testCases := []struct {
level string
expectError bool
}{
{
"trace",
false,
},
{
"debug",
false,
},
{
"notice",
false,
},
{
"info",
false,
},
{
"warn",
false,
},
{
"warning",
false,
},
{
"err",
false,
},
{
"error",
false,
},
{
"",
true,
},
{
"invalid",
true,
},
}
for _, tc := range testCases {
tc := tc
t.Run(fmt.Sprintf("all-loggers-%s", tc.level), func(t *testing.T) {
t.Parallel()
core, b, _ := testCoreSystemBackend(t)
config := core.GetCoreConfigInternal()
req := &logical.Request{
Path: "loggers",
Operation: logical.UpdateOperation,
Data: map[string]interface{}{
"level": tc.level,
},
}
resp, err := b.HandleRequest(namespace.RootContext(nil), req)
respIsError := resp != nil && resp.IsError()
if err != nil || (!tc.expectError && respIsError) {
t.Fatalf("unexpected error, err: %v, resp: %#v", err, resp)
}
if tc.expectError && !respIsError {
t.Fatalf("expected response error, resp: %#v", resp)
}
if !tc.expectError {
for _, logger := range core.allLoggers {
if !validateLevel(tc.level, logger) {
t.Fatalf("expected logger %q to be %q", logger.Name(), tc.level)
}
}
}
req = &logical.Request{
Path: fmt.Sprintf("loggers"),
Operation: logical.DeleteOperation,
}
resp, err = b.HandleRequest(namespace.RootContext(nil), req)
if err != nil || (resp != nil && resp.IsError()) {
t.Fatalf("unexpected error, err: %v, resp: %#v", err, resp)
}
for _, logger := range core.allLoggers {
if !validateLevel(config.LogLevel, logger) {
t.Errorf("expected level of logger %q to match original config", logger.Name())
}
}
})
}
}
func TestSystemBackend_LoggersByName(t *testing.T) {
testCases := []struct {
logger string
level string
expectWriteError bool
expectDeleteError bool
}{
{
"core",
"trace",
false,
false,
},
{
"token",
"debug",
false,
false,
},
{
"audit",
"notice",
false,
false,
},
{
"expiration",
"info",
false,
false,
},
{
"policy",
"warn",
false,
false,
},
{
"activity",
"warning",
false,
false,
},
{
"identity",
"err",
false,
false,
},
{
"rollback",
"error",
false,
false,
},
{
"system",
"",
true,
false,
},
{
"quotas",
"invalid",
true,
false,
},
{
"",
"info",
true,
true,
},
{
"does_not_exist",
"error",
true,
true,
},
}
for _, tc := range testCases {
tc := tc
t.Run(fmt.Sprintf("loggers-by-name-%s", tc.logger), func(t *testing.T) {
t.Parallel()
core, b, _ := testCoreSystemBackend(t)
config := core.GetCoreConfigInternal()
req := &logical.Request{
Path: fmt.Sprintf("loggers/%s", tc.logger),
Operation: logical.UpdateOperation,
Data: map[string]interface{}{
"name": tc.logger,
"level": tc.level,
},
}
resp, err := b.HandleRequest(namespace.RootContext(nil), req)
respIsError := resp != nil && resp.IsError()
if err != nil || (!tc.expectWriteError && respIsError) {
t.Fatalf("unexpected error, err: %v, resp: %#v", err, resp)
}
if tc.expectWriteError && !respIsError {
t.Fatalf("expected response error, resp: %#v", resp)
}
if !tc.expectWriteError {
for _, logger := range core.allLoggers {
if logger.Name() != tc.logger && !validateLevel(config.LogLevel, logger) {
t.Errorf("expected level of logger %q to be unchanged", logger.Name())
}
if !validateLevel(tc.level, logger) {
t.Fatalf("expected logger %q to be %q", logger.Name(), tc.level)
}
}
}
req = &logical.Request{
Path: fmt.Sprintf("loggers/%s", tc.logger),
Operation: logical.DeleteOperation,
Data: map[string]interface{}{
"name": tc.logger,
},
}
resp, err = b.HandleRequest(namespace.RootContext(nil), req)
respIsError = resp != nil && resp.IsError()
if err != nil || (!tc.expectDeleteError && respIsError) {
t.Fatalf("unexpected error, err: %v, resp: %#v", err, resp)
}
if tc.expectDeleteError && !respIsError {
t.Fatalf("expected response error, resp: %#v", resp)
}
if !tc.expectDeleteError {
for _, logger := range core.allLoggers {
if !validateLevel(config.LogLevel, logger) {
t.Errorf("expected level of logger %q to match original config", logger.Name())
}
}
}
})
}
}

View File

@ -220,6 +220,7 @@ func (c *Core) startPeriodicRaftTLSRotate(ctx context.Context) error {
c.raftTLSRotationStopCh = make(chan struct{})
logger := c.logger.Named("raft")
c.AddLogger(logger)
if c.isRaftHAOnly() {
return c.raftTLSRotateDirect(ctx, logger, c.raftTLSRotationStopCh)

View File

@ -1197,11 +1197,13 @@ func NewTestLogger(t testing.T) *TestLogger {
// We send nothing on the regular logger, that way we can later deregister
// the sink to stop logging during cluster cleanup.
logger := log.NewInterceptLogger(&log.LoggerOptions{
Output: ioutil.Discard,
Output: ioutil.Discard,
IndependentLevels: true,
})
sink := log.NewSinkAdapter(&log.LoggerOptions{
Output: output,
Level: log.Trace,
Output: output,
Level: log.Trace,
IndependentLevels: true,
})
logger.RegisterSink(sink)
return &TestLogger{

View File

@ -0,0 +1,102 @@
---
layout: api
page_title: /sys/loggers - HTTP API
description: The `/sys/loggers` endpoint is used modify the verbosity level of logging.
---
# `/sys/loggers`
The `/sys/loggers` endpoint is used modify the verbosity level of logging.
## Modify verbosity level of all loggers
| Method | Path |
| :------ | :------------- |
| `POST` | `/sys/loggers` |
### Parameters
- `level` `(string: <required>)`  Specifies the log verbosity level to be set for all loggers.
Supported values (in order of detail) are `"trace"`, `"debug"`, `"info"`, `"warn"`, and `"error"`.
### Sample Payload
```json
{
"level": "debug",
}
```
### Sample Request
```shell-session
$ curl \
--header "X-Vault-Token: ..." \
--request POST \
--data @payload.json \
http://127.0.0.1:8200/v1/sys/loggers
```
## Modify verbosity level of a single logger
| Method | Path |
| :------ | :------------------- |
| `POST` | `/sys/loggers/:name` |
### Parameters
- `name` `(string: <required>)`  Specifies the logger to be modified (e.g. `audit`, `core`, `expiration`).
- `level` `(string: <required>)`  Specifies the log verbosity level to be set for the provided logger.
Supported values (in order of detail) are `"trace"`, `"debug"`, `"info"`, `"warn"`, and `"error"`.
### Sample Payload
```json
{
"level": "debug",
}
```
### Sample Request
```shell-session
$ curl \
--header "X-Vault-Token: ..." \
--request POST \
--data @payload.json \
http://127.0.0.1:8200/v1/sys/loggers/core
```
## Revert verbosity of all loggers to configured level
| Method | Path |
| :-------- | :------------- |
| `DELETE` | `/sys/loggers` |
### Sample Request
```shell-session
$ curl \
--header "X-Vault-Token: ..." \
--request DELETE \
http://127.0.0.1:8200/v1/sys/loggers
```
## Revert verbosity of a single logger to configured level
| Method | Path |
| :-------- | :------------------- |
| `DELETE` | `/sys/loggers/:name` |
### Parameters
- `name` `(string: <required>)`  Specifies the logger to be modified (e.g. `audit`, `core`, `expiration`).
### Sample Request
```shell-session
$ curl \
--header "X-Vault-Token: ..." \
--request DELETE \
http://127.0.0.1:8200/v1/sys/loggers/core
```

View File

@ -482,6 +482,10 @@
"title": "<code>/sys/license/status</code>",
"path": "system/license"
},
{
"title": "<code>/sys/loggers</code>",
"path": "system/loggers"
},
{
"title": "<code>/sys/managed-keys <sup>ENT</sup></code>",
"path": "system/managed-keys"