From a65da54933a39f1b62e8b3a100c0f0cf23bd8fa6 Mon Sep 17 00:00:00 2001 From: Devin Carr Date: Mon, 16 Jun 2025 21:25:13 +0000 Subject: [PATCH] TUN-9371: Add logging format as JSON Closes TUN-9371 --- cmd/cloudflared/cliutil/logger.go | 20 ++++++++++++----- cmd/cloudflared/flags/flags.go | 5 +++++ cmd/cloudflared/tail/cmd.go | 27 +++++++++++++--------- logger/configuration.go | 8 +++++-- logger/console.go | 37 +++++++++++++++++++++++++++++++ logger/console_test.go | 33 +++++++++++++++++++++++++++ logger/create.go | 14 ++++++++++++ 7 files changed, 126 insertions(+), 18 deletions(-) create mode 100644 logger/console.go create mode 100644 logger/console_test.go diff --git a/cmd/cloudflared/cliutil/logger.go b/cmd/cloudflared/cliutil/logger.go index 6fbcf352..0fb4a54b 100644 --- a/cmd/cloudflared/cliutil/logger.go +++ b/cmd/cloudflared/cliutil/logger.go @@ -4,25 +4,32 @@ import ( "github.com/urfave/cli/v2" "github.com/urfave/cli/v2/altsrc" - cfdflags "github.com/cloudflare/cloudflared/cmd/cloudflared/flags" + "github.com/cloudflare/cloudflared/cmd/cloudflared/flags" ) var ( debugLevelWarning = "At debug level cloudflared will log request URL, method, protocol, content length, as well as, all request and response headers. " + "This can expose sensitive information in your logs." + + FlagLogOutput = &cli.StringFlag{ + Name: flags.LogFormatOutput, + Usage: "Output format for the logs (default, json)", + Value: flags.LogFormatOutputValueDefault, + EnvVars: []string{"TUNNEL_MANAGEMENT_OUTPUT", "TUNNEL_LOG_OUTPUT"}, + } ) func ConfigureLoggingFlags(shouldHide bool) []cli.Flag { return []cli.Flag{ altsrc.NewStringFlag(&cli.StringFlag{ - Name: cfdflags.LogLevel, + Name: flags.LogLevel, Value: "info", Usage: "Application logging level {debug, info, warn, error, fatal}. " + debugLevelWarning, EnvVars: []string{"TUNNEL_LOGLEVEL"}, Hidden: shouldHide, }), altsrc.NewStringFlag(&cli.StringFlag{ - Name: cfdflags.TransportLogLevel, + Name: flags.TransportLogLevel, Aliases: []string{"proto-loglevel"}, // This flag used to be called proto-loglevel Value: "info", Usage: "Transport logging level(previously called protocol logging level) {debug, info, warn, error, fatal}", @@ -30,22 +37,23 @@ func ConfigureLoggingFlags(shouldHide bool) []cli.Flag { Hidden: shouldHide, }), altsrc.NewStringFlag(&cli.StringFlag{ - Name: cfdflags.LogFile, + Name: flags.LogFile, Usage: "Save application log to this file for reporting issues.", EnvVars: []string{"TUNNEL_LOGFILE"}, Hidden: shouldHide, }), altsrc.NewStringFlag(&cli.StringFlag{ - Name: cfdflags.LogDirectory, + Name: flags.LogDirectory, Usage: "Save application log to this directory for reporting issues.", EnvVars: []string{"TUNNEL_LOGDIRECTORY"}, Hidden: shouldHide, }), altsrc.NewStringFlag(&cli.StringFlag{ - Name: cfdflags.TraceOutput, + Name: flags.TraceOutput, Usage: "Name of trace output file, generated when cloudflared stops.", EnvVars: []string{"TUNNEL_TRACE_OUTPUT"}, Hidden: shouldHide, }), + FlagLogOutput, } } diff --git a/cmd/cloudflared/flags/flags.go b/cmd/cloudflared/flags/flags.go index 7c919f05..a7bf1b7e 100644 --- a/cmd/cloudflared/flags/flags.go +++ b/cmd/cloudflared/flags/flags.go @@ -138,6 +138,11 @@ const ( // LogDirectory is the command line flag to define the directory where application logs will be stored. LogDirectory = "log-directory" + // LogFormatOutput allows the command line logs to be output as JSON. + LogFormatOutput = "output" + LogFormatOutputValueDefault = "default" + LogFormatOutputValueJSON = "json" + // TraceOutput is the command line flag to set the name of trace output file TraceOutput = "trace-output" diff --git a/cmd/cloudflared/tail/cmd.go b/cmd/cloudflared/tail/cmd.go index d7f5a429..6c376033 100644 --- a/cmd/cloudflared/tail/cmd.go +++ b/cmd/cloudflared/tail/cmd.go @@ -4,6 +4,7 @@ import ( "encoding/json" "errors" "fmt" + "io" "net/http" "net/url" "os" @@ -97,12 +98,6 @@ func buildTailCommand(subcommands []*cli.Command) *cli.Command { Value: "", EnvVars: []string{"TUNNEL_MANAGEMENT_TOKEN"}, }, - &cli.StringFlag{ - Name: "output", - Usage: "Output format for the logs (default, json)", - Value: "default", - EnvVars: []string{"TUNNEL_MANAGEMENT_OUTPUT"}, - }, &cli.StringFlag{ Name: "management-hostname", Usage: "Management hostname to signify incoming management requests", @@ -128,6 +123,7 @@ func buildTailCommand(subcommands []*cli.Command) *cli.Command { EnvVars: []string{"TUNNEL_ORIGIN_CERT"}, Value: credentials.FindDefaultOriginCertPath(), }, + cliutil.FlagLogOutput, }, Subcommands: subcommands, } @@ -171,10 +167,21 @@ func createLogger(c *cli.Context) *zerolog.Logger { if levelErr != nil { level = zerolog.InfoLevel } - log := zerolog.New(zerolog.ConsoleWriter{ - Out: colorable.NewColorable(os.Stderr), - TimeFormat: time.RFC3339, - }).With().Timestamp().Logger().Level(level) + var writer io.Writer + switch c.String(cfdflags.LogFormatOutput) { + case cfdflags.LogFormatOutputValueJSON: + // zerolog by default outputs as JSON + writer = os.Stderr + case cfdflags.LogFormatOutputValueDefault: + // "default" and unset use the same logger output format + fallthrough + default: + writer = zerolog.ConsoleWriter{ + Out: colorable.NewColorable(os.Stderr), + TimeFormat: time.RFC3339, + } + } + log := zerolog.New(writer).With().Timestamp().Logger().Level(level) return &log } diff --git a/logger/configuration.go b/logger/configuration.go index d406a220..e8a5b2e4 100644 --- a/logger/configuration.go +++ b/logger/configuration.go @@ -17,6 +17,7 @@ type Config struct { type ConsoleConfig struct { noColor bool + asJSON bool } type FileConfig struct { @@ -48,6 +49,7 @@ func createDefaultConfig() Config { return Config{ ConsoleConfig: &ConsoleConfig{ noColor: false, + asJSON: false, }, FileConfig: &FileConfig{ Dirname: "", @@ -67,11 +69,12 @@ func createDefaultConfig() Config { func CreateConfig( minLevel string, disableTerminal bool, + formatJSON bool, rollingLogPath, nonRollingLogFilePath string, ) *Config { var console *ConsoleConfig if !disableTerminal { - console = createConsoleConfig() + console = createConsoleConfig(formatJSON) } var file *FileConfig @@ -95,9 +98,10 @@ func CreateConfig( } } -func createConsoleConfig() *ConsoleConfig { +func createConsoleConfig(formatJSON bool) *ConsoleConfig { return &ConsoleConfig{ noColor: false, + asJSON: formatJSON, } } diff --git a/logger/console.go b/logger/console.go new file mode 100644 index 00000000..af93f845 --- /dev/null +++ b/logger/console.go @@ -0,0 +1,37 @@ +package logger + +import ( + "bytes" + "fmt" + "io" + + jsoniter "github.com/json-iterator/go" +) + +var json = jsoniter.ConfigCompatibleWithStandardLibrary + +// consoleWriter allows us the simplicity to prevent duplicate json keys in the logger events reported. +// +// By default zerolog constructs the json event in parts by appending each additional key after the first. It +// doesn't have any internal state or struct of the json message representation so duplicate keys can be +// inserted without notice and no pruning will occur before writing the log event out to the io.Writer. +// +// To help prevent these duplicate keys, we will decode the json log event and then immediately re-encode it +// again as writing it to the output io.Writer. Since we encode it to a map[string]any, duplicate keys +// are pruned. We pay the cost of decoding and encoding the log event for each time, but helps prevent +// us from needing to worry about adding duplicate keys in the log event from different areas of code. +type consoleWriter struct { + out io.Writer +} + +func (c *consoleWriter) Write(p []byte) (n int, err error) { + var evt map[string]any + d := json.NewDecoder(bytes.NewReader(p)) + d.UseNumber() + err = d.Decode(&evt) + if err != nil { + return n, fmt.Errorf("cannot decode event: %s", err) + } + e := json.NewEncoder(c.out) + return len(p), e.Encode(evt) +} diff --git a/logger/console_test.go b/logger/console_test.go new file mode 100644 index 00000000..df3579f0 --- /dev/null +++ b/logger/console_test.go @@ -0,0 +1,33 @@ +package logger + +import ( + "bytes" + "strings" + "testing" + + "github.com/rs/zerolog" +) + +func TestConsoleLoggerDuplicateKeys(t *testing.T) { + r := bytes.NewBuffer(make([]byte, 500)) + logger := zerolog.New(&consoleWriter{out: r}).With().Timestamp().Logger() + logger.Debug().Str("test", "1234").Int("number", 45).Str("test", "5678").Msg("log message") + + event, err := r.ReadString('\n') + if err != nil { + t.Error(err) + } + + if !strings.Contains(event, "\"test\":\"5678\"") { + t.Errorf("log event missing key 'test': %s", event) + } + if !strings.Contains(event, "\"number\":45") { + t.Errorf("log event missing key 'number': %s", event) + } + if !strings.Contains(event, "\"time\":") { + t.Errorf("log event missing key 'time': %s", event) + } + if !strings.Contains(event, "\"level\":\"debug\"") { + t.Errorf("log event missing key 'level': %s", event) + } +} diff --git a/logger/create.go b/logger/create.go index fdb4495d..2ae67ab9 100644 --- a/logger/create.go +++ b/logger/create.go @@ -149,10 +149,21 @@ func createFromContext( logLevel := c.String(logLevelFlagName) logFile := c.String(cfdflags.LogFile) logDirectory := c.String(logDirectoryFlagName) + var logFormatJSON bool + switch c.String(cfdflags.LogFormatOutput) { + case cfdflags.LogFormatOutputValueJSON: + logFormatJSON = true + case cfdflags.LogFormatOutputValueDefault: + // "default" and unset use the same logger output format + fallthrough + default: + logFormatJSON = false + } loggerConfig := CreateConfig( logLevel, disableTerminal, + logFormatJSON, logDirectory, logFile, ) @@ -177,6 +188,9 @@ func Create(loggerConfig *Config) *zerolog.Logger { } func createConsoleLogger(config ConsoleConfig) io.Writer { + if config.asJSON { + return &consoleWriter{out: os.Stderr} + } consoleOut := os.Stderr return zerolog.ConsoleWriter{ Out: colorable.NewColorable(consoleOut),