api/monitor: Adding log format to monitor command and debug (#15536)

* Correct handling of "unspecified" log level

* Setting log-format default on monitor path

* Create changelog file

* Update website/content/api-docs/system/monitor.mdx

Co-authored-by: Chris Capurso <1036769+ccapurso@users.noreply.github.com>

Co-authored-by: Chris Capurso <1036769+ccapurso@users.noreply.github.com>
This commit is contained in:
davidadeleon 2022-05-24 13:10:53 -04:00 committed by GitHub
parent 9dd1a4ff93
commit 0026788d4b
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
11 changed files with 156 additions and 7 deletions

View File

@ -5,11 +5,13 @@ import (
"context" "context"
"fmt" "fmt"
"net/http" "net/http"
"github.com/hashicorp/vault/sdk/helper/logging"
) )
// Monitor returns a channel that outputs strings containing the log messages // Monitor returns a channel that outputs strings containing the log messages
// coming from the server. // coming from the server.
func (c *Sys) Monitor(ctx context.Context, logLevel string) (chan string, error) { func (c *Sys) Monitor(ctx context.Context, logLevel string, logFormat string) (chan string, error) {
r := c.c.NewRequest(http.MethodGet, "/v1/sys/monitor") r := c.c.NewRequest(http.MethodGet, "/v1/sys/monitor")
if logLevel == "" { if logLevel == "" {
@ -18,6 +20,12 @@ func (c *Sys) Monitor(ctx context.Context, logLevel string) (chan string, error)
r.Params.Add("log_level", logLevel) r.Params.Add("log_level", logLevel)
} }
if logFormat == "" || logFormat == logging.UnspecifiedFormat.String() {
r.Params.Add("log_format", "standard")
} else {
r.Params.Add("log_format", logFormat)
}
resp, err := c.c.RawRequestWithContext(ctx, r) resp, err := c.c.RawRequestWithContext(ctx, r)
if err != nil { if err != nil {
return nil, err return nil, err

7
changelog/15536.txt Normal file
View File

@ -0,0 +1,7 @@
```release-note:improvement
api/monitor: Add log_format option to allow for logs to be emitted in JSON format
```
```release-note:improvement
command/debug: Add log_format flag to allow for logs to be emitted in JSON format
```

View File

@ -93,6 +93,9 @@ type DebugCommand struct {
flagOutput string flagOutput string
flagTargets []string flagTargets []string
// logFormat defines the output format for Monitor
logFormat string
// debugIndex is used to keep track of the index state, which gets written // debugIndex is used to keep track of the index state, which gets written
// to a file at the end. // to a file at the end.
debugIndex *debugIndex debugIndex *debugIndex
@ -180,6 +183,14 @@ func (c *DebugCommand) Flags() *FlagSets {
"replication-status, server-status, log.", "replication-status, server-status, log.",
}) })
f.StringVar(&StringVar{
Name: "log-format",
Target: &c.logFormat,
Default: "standard",
Usage: "Log format to be captured if \"log\" target specified. " +
"Supported values are \"standard\" and \"json\". The default is \"standard\".",
})
return set return set
} }
@ -1053,14 +1064,14 @@ func (c *DebugCommand) captureError(target string, err error) {
} }
func (c *DebugCommand) writeLogs(ctx context.Context) { func (c *DebugCommand) writeLogs(ctx context.Context) {
out, err := os.OpenFile(filepath.Join(c.flagOutput, "vault.log"), os.O_CREATE, 0o600) out, err := os.OpenFile(filepath.Join(c.flagOutput, "vault.log"), os.O_CREATE|os.O_WRONLY, 0o600)
if err != nil { if err != nil {
c.captureError("log", err) c.captureError("log", err)
return return
} }
defer out.Close() defer out.Close()
logCh, err := c.cachedClient.Sys().Monitor(ctx, "trace") logCh, err := c.cachedClient.Sys().Monitor(ctx, "trace", c.logFormat)
if err != nil { if err != nil {
c.captureError("log", err) c.captureError("log", err)
return return

View File

@ -18,7 +18,8 @@ var (
type MonitorCommand struct { type MonitorCommand struct {
*BaseCommand *BaseCommand
logLevel string logLevel string
logFormat string
// ShutdownCh is used to capture interrupt signal and end streaming // ShutdownCh is used to capture interrupt signal and end streaming
ShutdownCh chan struct{} ShutdownCh chan struct{}
@ -55,6 +56,13 @@ func (c *MonitorCommand) Flags() *FlagSets {
"(in order of detail) are \"trace\", \"debug\", \"info\", \"warn\"" + "(in order of detail) are \"trace\", \"debug\", \"info\", \"warn\"" +
" and \"error\". These are not case sensitive.", " and \"error\". These are not case sensitive.",
}) })
f.StringVar(&StringVar{
Name: "log-format",
Target: &c.logFormat,
Default: "standard",
Completion: complete.PredictSet("standard", "json"),
Usage: "Output format of logs. Supported values are \"standard\" and \"json\".",
})
return set return set
} }
@ -88,6 +96,13 @@ func (c *MonitorCommand) Run(args []string) int {
return 1 return 1
} }
c.logFormat = strings.ToLower(c.logFormat)
validFormats := []string{"standard", "json"}
if !strutil.StrListContains(validFormats, c.logFormat) {
c.UI.Error(fmt.Sprintf("%s is an unknown log format. Valid log formats are: %s", c.logFormat, validFormats))
return 1
}
client, err := c.Client() client, err := c.Client()
if err != nil { if err != nil {
c.UI.Error(err.Error()) c.UI.Error(err.Error())
@ -100,7 +115,7 @@ func (c *MonitorCommand) Run(args []string) int {
var logCh chan string var logCh chan string
ctx, cancel := context.WithCancel(context.Background()) ctx, cancel := context.WithCancel(context.Background())
defer cancel() defer cancel()
logCh, err = client.Sys().Monitor(ctx, c.logLevel) logCh, err = client.Sys().Monitor(ctx, c.logLevel, c.logFormat)
if err != nil { if err != nil {
c.UI.Error(fmt.Sprintf("Error starting monitor: %s", err)) c.UI.Error(fmt.Sprintf("Error starting monitor: %s", err))
return 1 return 1

View File

@ -1,6 +1,7 @@
package monitor package monitor
import ( import (
"encoding/json"
"fmt" "fmt"
"strings" "strings"
"testing" "testing"
@ -38,6 +39,46 @@ func TestMonitor_Start(t *testing.T) {
} }
} }
func TestMonitor_JSONFormat(t *testing.T) {
t.Parallel()
logger := log.NewInterceptLogger(&log.LoggerOptions{
Level: log.Error,
})
m, _ := NewMonitor(512, logger, &log.LoggerOptions{
Level: log.Debug,
JSONFormat: true,
})
type jsonlog struct {
Level string `json:"@level"`
Message string `json:"@message"`
TimeStamp string `json:"@timestamp"`
}
jsonLog := &jsonlog{}
logCh := m.Start()
defer m.Stop()
go func() {
logger.Debug("test json log")
time.Sleep(10 * time.Millisecond)
}()
select {
case l := <-logCh:
err := json.Unmarshal(l, jsonLog)
if err != nil {
t.Fatal("Expected JSON log from channel")
}
require.Contains(t, jsonLog.Message, "test json log")
return
case <-time.After(5 * time.Second):
t.Fatal("Expected to receive from log channel")
}
}
func TestMonitor_Start_Unbuffered(t *testing.T) { func TestMonitor_Start_Unbuffered(t *testing.T) {
t.Parallel() t.Parallel()

View File

@ -2,6 +2,7 @@ package http
import ( import (
"context" "context"
"encoding/json"
"strings" "strings"
"testing" "testing"
"time" "time"
@ -35,6 +36,29 @@ func TestSysMonitorUnknownLogLevel(t *testing.T) {
} }
} }
func TestSysMonitorUnknownLogFormat(t *testing.T) {
cluster := vault.NewTestCluster(t, nil, &vault.TestClusterOptions{HandlerFunc: Handler})
cluster.Start()
defer cluster.Cleanup()
client := cluster.Cores[0].Client
request := client.NewRequest("GET", "/v1/sys/monitor")
request.Params.Add("log_format", "haha")
_, err := client.RawRequest(request)
if err == nil {
t.Fatal("expected to get an error, but didn't")
} else {
if !strings.Contains(err.Error(), "Code: 400") {
t.Fatalf("expected to receive a 400 error, but got %s instead", err)
}
if !strings.Contains(err.Error(), "unknown log format") {
t.Fatalf("expected to receive a message indicating an unknown log format, but got %s instead", err)
}
}
}
func TestSysMonitorStreamingLogs(t *testing.T) { func TestSysMonitorStreamingLogs(t *testing.T) {
logger := log.NewInterceptLogger(&log.LoggerOptions{ logger := log.NewInterceptLogger(&log.LoggerOptions{
Output: log.DefaultOutput, Output: log.DefaultOutput,
@ -42,6 +66,8 @@ func TestSysMonitorStreamingLogs(t *testing.T) {
JSONFormat: logging.ParseEnvLogFormat() == logging.JSONFormat, JSONFormat: logging.ParseEnvLogFormat() == logging.JSONFormat,
}) })
lf := logging.ParseEnvLogFormat().String()
cluster := vault.NewTestCluster(t, nil, &vault.TestClusterOptions{HandlerFunc: Handler, Logger: logger}) cluster := vault.NewTestCluster(t, nil, &vault.TestClusterOptions{HandlerFunc: Handler, Logger: logger})
cluster.Start() cluster.Start()
defer cluster.Cleanup() defer cluster.Cleanup()
@ -52,16 +78,32 @@ func TestSysMonitorStreamingLogs(t *testing.T) {
debugCount := 0 debugCount := 0
ctx, cancel := context.WithTimeout(context.Background(), 90*time.Second) ctx, cancel := context.WithTimeout(context.Background(), 90*time.Second)
defer cancel() defer cancel()
logCh, err := client.Sys().Monitor(ctx, "DEBUG") logCh, err := client.Sys().Monitor(ctx, "DEBUG", lf)
if err != nil { if err != nil {
t.Fatal(err) t.Fatal(err)
} }
type jsonlog struct {
Level string `json:"@level"`
Message string `json:"@message"`
TimeStamp string `json:"@timestamp"`
}
jsonLog := &jsonlog{}
timeCh := time.After(5 * time.Second) timeCh := time.After(5 * time.Second)
for { for {
select { select {
case log := <-logCh: case log := <-logCh:
if lf == "json" {
err := json.Unmarshal([]byte(log), jsonLog)
if err != nil {
t.Fatal("Expected JSON log from channel")
}
if strings.Contains(jsonLog.Level, "debug") {
debugCount++
}
}
if strings.Contains(log, "[DEBUG]") { if strings.Contains(log, "[DEBUG]") {
debugCount++ debugCount++
} }

View File

@ -3244,6 +3244,14 @@ func (b *SystemBackend) handleMonitor(ctx context.Context, req *logical.Request,
return logical.ErrorResponse("unknown log level"), nil return logical.ErrorResponse("unknown log level"), nil
} }
lf := data.Get("log_format").(string)
lowerLogFormat := strings.ToLower(lf)
validFormats := []string{"standard", "json"}
if !strutil.StrListContains(validFormats, lowerLogFormat) {
return logical.ErrorResponse("unknown log format"), nil
}
flusher, ok := w.ResponseWriter.(http.Flusher) flusher, ok := w.ResponseWriter.(http.Flusher)
if !ok { if !ok {
// http.ResponseWriter is wrapped in wrapGenericHandler, so let's // http.ResponseWriter is wrapped in wrapGenericHandler, so let's
@ -3258,7 +3266,7 @@ func (b *SystemBackend) handleMonitor(ctx context.Context, req *logical.Request,
} }
} }
isJson := b.Core.LogFormat() == "json" isJson := b.Core.LogFormat() == "json" || lf == "json"
logger := b.Core.Logger().(log.InterceptLogger) logger := b.Core.Logger().(log.InterceptLogger)
mon, err := monitor.NewMonitor(512, logger, &log.LoggerOptions{ mon, err := monitor.NewMonitor(512, logger, &log.LoggerOptions{

View File

@ -1388,6 +1388,12 @@ func (b *SystemBackend) monitorPath() *framework.Path {
Description: "Log level to view system logs at. Currently supported values are \"trace\", \"debug\", \"info\", \"warn\", \"error\".", Description: "Log level to view system logs at. Currently supported values are \"trace\", \"debug\", \"info\", \"warn\", \"error\".",
Query: true, Query: true,
}, },
"log_format": {
Type: framework.TypeString,
Description: "Output format of logs. Supported values are \"standard\" and \"json\". The default is \"standard\".",
Query: true,
Default: "standard",
},
}, },
Callbacks: map[logical.Operation]framework.OperationFunc{ Callbacks: map[logical.Operation]framework.OperationFunc{
logical.ReadOperation: b.handleMonitor, logical.ReadOperation: b.handleMonitor,

View File

@ -26,6 +26,9 @@ default, this is text.
- `log_level` `(string: "info")` Specifies the log level to use when streaming logs. This defaults to `info` - `log_level` `(string: "info")` Specifies the log level to use when streaming logs. This defaults to `info`
if not specified. if not specified.
- `log_format` `(string: "standard")` Specifies the log format to emit when streaming logs. Supported values are "standard" and "json". The default is `standard`.
if not specified.
### Sample Request ### Sample Request
```shell-session ```shell-session

View File

@ -138,6 +138,10 @@ flags](/docs/commands) included on all commands.
- `-interval` `(int or time string: "30s")` - The polling interval at which to - `-interval` `(int or time string: "30s")` - The polling interval at which to
collect profiling data and server state. The default is 30s. collect profiling data and server state. The default is 30s.
- `-log-format` `(string: "standard")` - Log format to be captured if "log"
target specified. Supported values are "standard" and "json". The default is
"standard".
- `-metrics-interval` `(int or time string: "10s")` - The polling interval at - `-metrics-interval` `(int or time string: "10s")` - The polling interval at
which to collect metrics data. The default is 10s. which to collect metrics data. The default is 10s.

View File

@ -41,3 +41,7 @@ flags](/docs/commands) included on all commands.
- `-log-level` `(string: "info")` - Monitor the Vault server at this log level. - `-log-level` `(string: "info")` - Monitor the Vault server at this log level.
Valid log levels are (in order of detail) "trace", "debug", "info", Valid log levels are (in order of detail) "trace", "debug", "info",
"warn", "error". If this option is not specified, "info" is used. "warn", "error". If this option is not specified, "info" is used.
- `-log-format` `(string: "standard")` - Format to emit logs.
Valid formats are "standard", and "json".
If this option is not specified, "standard" is used.