Skip to content

Commit

Permalink
api/monitor: Adding log format to monitor command and debug (#15536)
Browse files Browse the repository at this point in the history
* 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>
  • Loading branch information
davidadeleon and ccapurso committed Jun 3, 2022
1 parent b552543 commit daf620d
Show file tree
Hide file tree
Showing 11 changed files with 158 additions and 8 deletions.
13 changes: 11 additions & 2 deletions api/sys_monitor.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,19 +4,28 @@ import (
"bufio"
"context"
"fmt"
"net/http"

"github.com/hashicorp/vault/sdk/helper/logging"
)

// Monitor returns a channel that outputs strings containing the log messages
// coming from the server.
func (c *Sys) Monitor(ctx context.Context, logLevel string) (chan string, error) {
r := c.c.NewRequest("GET", "/v1/sys/monitor")
func (c *Sys) Monitor(ctx context.Context, logLevel string, logFormat string) (chan string, error) {
r := c.c.NewRequest(http.MethodGet, "/v1/sys/monitor")

if logLevel == "" {
r.Params.Add("log_level", "info")
} else {
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)
if err != nil {
return nil, err
Expand Down
7 changes: 7 additions & 0 deletions changelog/15536.txt
Original file line number Diff line number Diff line change
@@ -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
```
15 changes: 13 additions & 2 deletions command/debug.go
Original file line number Diff line number Diff line change
Expand Up @@ -93,6 +93,9 @@ type DebugCommand struct {
flagOutput 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
// to a file at the end.
debugIndex *debugIndex
Expand Down Expand Up @@ -180,6 +183,14 @@ func (c *DebugCommand) Flags() *FlagSets {
"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
}

Expand Down Expand Up @@ -1053,14 +1064,14 @@ func (c *DebugCommand) captureError(target string, err error) {
}

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 {
c.captureError("log", err)
return
}
defer out.Close()

logCh, err := c.cachedClient.Sys().Monitor(ctx, "trace")
logCh, err := c.cachedClient.Sys().Monitor(ctx, "trace", c.logFormat)
if err != nil {
c.captureError("log", err)
return
Expand Down
19 changes: 17 additions & 2 deletions command/monitor.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,8 @@ var (
type MonitorCommand struct {
*BaseCommand

logLevel string
logLevel string
logFormat string

// ShutdownCh is used to capture interrupt signal and end streaming
ShutdownCh chan struct{}
Expand Down Expand Up @@ -55,6 +56,13 @@ func (c *MonitorCommand) Flags() *FlagSets {
"(in order of detail) are \"trace\", \"debug\", \"info\", \"warn\"" +
" 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
}
Expand Down Expand Up @@ -88,6 +96,13 @@ func (c *MonitorCommand) Run(args []string) int {
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()
if err != nil {
c.UI.Error(err.Error())
Expand All @@ -100,7 +115,7 @@ func (c *MonitorCommand) Run(args []string) int {
var logCh chan string
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
logCh, err = client.Sys().Monitor(ctx, c.logLevel)
logCh, err = client.Sys().Monitor(ctx, c.logLevel, c.logFormat)
if err != nil {
c.UI.Error(fmt.Sprintf("Error starting monitor: %s", err))
return 1
Expand Down
41 changes: 41 additions & 0 deletions helper/monitor/monitor_test.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package monitor

import (
"encoding/json"
"fmt"
"strings"
"testing"
Expand Down Expand Up @@ -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) {
t.Parallel()

Expand Down
44 changes: 43 additions & 1 deletion http/sys_monitor_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package http

import (
"context"
"encoding/json"
"strings"
"testing"
"time"
Expand Down Expand Up @@ -35,13 +36,38 @@ 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) {
logger := log.NewInterceptLogger(&log.LoggerOptions{
Output: log.DefaultOutput,
Level: log.Debug,
JSONFormat: logging.ParseEnvLogFormat() == logging.JSONFormat,
})

lf := logging.ParseEnvLogFormat().String()

cluster := vault.NewTestCluster(t, nil, &vault.TestClusterOptions{HandlerFunc: Handler, Logger: logger})
cluster.Start()
defer cluster.Cleanup()
Expand All @@ -52,16 +78,32 @@ func TestSysMonitorStreamingLogs(t *testing.T) {
debugCount := 0
ctx, cancel := context.WithTimeout(context.Background(), 90*time.Second)
defer cancel()
logCh, err := client.Sys().Monitor(ctx, "DEBUG")
logCh, err := client.Sys().Monitor(ctx, "DEBUG", lf)
if err != nil {
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)

for {
select {
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]") {
debugCount++
}
Expand Down
10 changes: 9 additions & 1 deletion vault/logical_system.go
Original file line number Diff line number Diff line change
Expand Up @@ -3236,6 +3236,14 @@ func (b *SystemBackend) handleMonitor(ctx context.Context, req *logical.Request,
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)
if !ok {
// http.ResponseWriter is wrapped in wrapGenericHandler, so let's
Expand All @@ -3250,7 +3258,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)

mon, err := monitor.NewMonitor(512, logger, &log.LoggerOptions{
Expand Down
6 changes: 6 additions & 0 deletions vault/logical_system_paths.go
Original file line number Diff line number Diff line change
Expand Up @@ -1382,6 +1382,12 @@ func (b *SystemBackend) monitorPath() *framework.Path {
Description: "Log level to view system logs at. Currently supported values are \"trace\", \"debug\", \"info\", \"warn\", \"error\".",
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{
logical.ReadOperation: b.handleMonitor,
Expand Down
3 changes: 3 additions & 0 deletions website/content/api-docs/system/monitor.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -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`
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

```shell-session
Expand Down
4 changes: 4 additions & 0 deletions website/content/docs/commands/debug.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -138,6 +138,10 @@ flags](/docs/commands) included on all commands.
- `-interval` `(int or time string: "30s")` - The polling interval at which to
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
which to collect metrics data. The default is 10s.

Expand Down
4 changes: 4 additions & 0 deletions website/content/docs/commands/monitor.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -41,3 +41,7 @@ flags](/docs/commands) included on all commands.
- `-log-level` `(string: "info")` - Monitor the Vault server at this log level.
Valid log levels are (in order of detail) "trace", "debug", "info",
"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.

0 comments on commit daf620d

Please sign in to comment.