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

…15791)

* 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>

Co-authored-by: Chris Capurso <1036769+ccapurso@users.noreply.github.com>
Co-authored-by: Jason O'Donnell <2160810+jasonodonnell@users.noreply.github.com>

api/sys_monitor.go

@@ -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

changelog/15536.txt

@@ -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
+```

command/debug.go

@@ -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
@@ -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
 }
 
@@ -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

command/monitor.go

@@ -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{}
@@ -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
 }
@@ -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())
@@ -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

helper/monitor/monitor_test.go

@@ -1,6 +1,7 @@
 package monitor
 
 import (
+	"encoding/json"
 	"fmt"
 	"strings"
 	"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) {
 	t.Parallel()
 

http/sys_monitor_test.go

@@ -2,6 +2,7 @@ package http
 
 import (
 	"context"
+	"encoding/json"
 	"strings"
 	"testing"
 	"time"
@@ -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()
@@ -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++
 			}

vault/logical_system.go

@@ -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
@@ -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{

vault/logical_system_paths.go

@@ -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,

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

@@ -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

website/content/docs/commands/debug.mdx

@@ -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.
 

website/content/docs/commands/monitor.mdx

@@ -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.