From 5e51af924487dc71d62c975fe1e9cc01f1f82282 Mon Sep 17 00:00:00 2001 From: Sergey Vilgelm Date: Mon, 29 Aug 2022 05:23:48 -0700 Subject: [PATCH] logger: Configure timestamp format (#5050) With this, we allow the user to configure the logger's timestamp format by: * cli argument `log-timestamp-format` * environment variable `OPA_LOG_TIMESTAMP_FORMAT` Fixes #2413. Signed-off-by: Sergey Vilgelm --- cmd/exec.go | 18 ++++++---- cmd/internal/exec/exec.go | 3 +- cmd/run.go | 12 +++++-- cmd/run_test.go | 72 +++++++++++++++++++++++++++++++++++++ docs/content/cli.md | 4 +-- internal/logging/logging.go | 9 ++--- runtime/runtime.go | 11 +++--- 7 files changed, 109 insertions(+), 20 deletions(-) diff --git a/cmd/exec.go b/cmd/exec.go index c3c9556b93..f908287905 100644 --- a/cmd/exec.go +++ b/cmd/exec.go @@ -8,6 +8,8 @@ import ( "os" "path/filepath" + "github.com/spf13/cobra" + "github.com/open-policy-agent/opa/cmd/internal/exec" "github.com/open-policy-agent/opa/internal/config" internal_logging "github.com/open-policy-agent/opa/internal/logging" @@ -19,7 +21,6 @@ import ( "github.com/open-policy-agent/opa/plugins/status" "github.com/open-policy-agent/opa/sdk" "github.com/open-policy-agent/opa/util" - "github.com/spf13/cobra" ) func init() { @@ -69,13 +70,14 @@ e.g., opa exec --decision /foo/bar/baz ...`, cmd.Flags().StringVarP(¶ms.Decision, "decision", "", "", "set decision to evaluate") cmd.Flags().VarP(params.LogLevel, "log-level", "l", "set log level") cmd.Flags().Var(params.LogFormat, "log-format", "set log format") + cmd.Flags().StringVar(¶ms.LogTimestampFormat, "log-timestamp-format", "", "set log timestamp format (OPA_LOG_TIMESTAMP_FORMAT environment variable)") RootCommand.AddCommand(cmd) } func runExec(params *exec.Params) error { - stdLogger, consoleLogger, err := setupLogging(params.LogLevel.String(), params.LogFormat.String()) + stdLogger, consoleLogger, err := setupLogging(params.LogLevel.String(), params.LogFormat.String(), params.LogTimestampFormat) if err != nil { return fmt.Errorf("config error: %w", err) } @@ -126,22 +128,26 @@ func triggerPlugins(ctx context.Context, opa *sdk.OPA, names []string) error { return nil } -func setupLogging(level, format string) (logging.Logger, logging.Logger, error) { +func setupLogging(level, format, timestampFormat string) (logging.Logger, logging.Logger, error) { lvl, err := internal_logging.GetLevel(level) if err != nil { return nil, nil, err } - logging.Get().SetFormatter(internal_logging.GetFormatter(format)) + if timestampFormat == "" { + timestampFormat = os.Getenv("OPA_LOG_TIMESTAMP_FORMAT") + } + + logging.Get().SetFormatter(internal_logging.GetFormatter(format, timestampFormat)) logging.Get().SetLevel(lvl) stdLogger := logging.New() stdLogger.SetLevel(lvl) - stdLogger.SetFormatter(internal_logging.GetFormatter(format)) + stdLogger.SetFormatter(internal_logging.GetFormatter(format, timestampFormat)) consoleLogger := logging.New() - consoleLogger.SetFormatter(internal_logging.GetFormatter(format)) + consoleLogger.SetFormatter(internal_logging.GetFormatter(format, timestampFormat)) return stdLogger, consoleLogger, nil } diff --git a/cmd/internal/exec/exec.go b/cmd/internal/exec/exec.go index ea12593fed..d8502024f0 100644 --- a/cmd/internal/exec/exec.go +++ b/cmd/internal/exec/exec.go @@ -23,6 +23,7 @@ type Params struct { OutputFormat *util.EnumFlag // output format (default: pretty) LogLevel *util.EnumFlag // log level for plugins LogFormat *util.EnumFlag // log format for plugins + LogTimestampFormat string // log timestamp format for plugins BundlePaths []string // explicit paths of bundles to inject into the configuration Decision string // decision to evaluate (overrides default decision set by configuration) } @@ -40,7 +41,7 @@ func NewParams(w io.Writer) *Params { // // NOTE(tsandall): consider expanding functionality: // -// * specialized output formats (e.g., pretty/non-JSON outputs) +// * specialized output formats (e.g., pretty/non-JSON outputs) // * exit codes set by convention or policy (e.g,. non-empty set => error) // * support for new input file formats beyond JSON and YAML func Exec(ctx context.Context, opa *sdk.OPA, params *Params) error { diff --git a/cmd/run.go b/cmd/run.go index 7c2fd7ef30..c62096c331 100644 --- a/cmd/run.go +++ b/cmd/run.go @@ -40,6 +40,7 @@ type runCmdParams struct { minTLSVersion *util.EnumFlag logLevel *util.EnumFlag logFormat *util.EnumFlag + logTimestampFormat string algorithm string scope string pubKey string @@ -186,6 +187,7 @@ To skip bundle verification, use the --skip-verify flag. runCommand.Flags().Var(cmdParams.minTLSVersion, "min-tls-version", "set minimum TLS version to be used by OPA's server") runCommand.Flags().VarP(cmdParams.logLevel, "log-level", "l", "set log level") runCommand.Flags().Var(cmdParams.logFormat, "log-format", "set log format") + runCommand.Flags().StringVar(&cmdParams.logTimestampFormat, "log-timestamp-format", "", "set log timestamp format (OPA_LOG_TIMESTAMP_FORMAT environment variable)") runCommand.Flags().IntVar(&cmdParams.rt.GracefulShutdownPeriod, "shutdown-grace-period", 10, "set the time (in seconds) that the server will wait to gracefully shut down") runCommand.Flags().IntVar(&cmdParams.rt.ShutdownWaitPeriod, "shutdown-wait-period", 0, "set the time (in seconds) that the server will wait before initiating shutdown") addConfigOverrides(runCommand.Flags(), &cmdParams.rt.ConfigOverrides) @@ -254,9 +256,15 @@ func initRuntime(ctx context.Context, params runCmdParams, args []string) (*runt params.rt.Authorization = authorizationScheme[params.authorization.String()] params.rt.MinTLSVersion = minTLSVersions[params.minTLSVersion.String()] params.rt.Certificate = cert + + timestampFormat := params.logTimestampFormat + if timestampFormat == "" { + timestampFormat = os.Getenv("OPA_LOG_TIMESTAMP_FORMAT") + } params.rt.Logging = runtime.LoggingConfig{ - Level: params.logLevel.String(), - Format: params.logFormat.String(), + Level: params.logLevel.String(), + Format: params.logFormat.String(), + TimestampFormat: timestampFormat, } params.rt.Paths = args params.rt.Filter = loaderFilter{ diff --git a/cmd/run_test.go b/cmd/run_test.go index 65eab289ab..9d54d836eb 100644 --- a/cmd/run_test.go +++ b/cmd/run_test.go @@ -7,8 +7,12 @@ package cmd import ( "bytes" "context" + "encoding/json" + "strings" "testing" + "time" + "github.com/open-policy-agent/opa/logging" "github.com/open-policy-agent/opa/test/e2e" ) @@ -100,6 +104,74 @@ func TestInitRuntimeVerifyNonBundle(t *testing.T) { } } +func TestRunServerCheckLogTimestampFormat(t *testing.T) { + for _, format := range []string{time.Kitchen, time.RFC3339Nano} { + t.Run(format, func(t *testing.T) { + t.Run("parameter", func(t *testing.T) { + params := newTestRunParams() + params.logTimestampFormat = format + checkLogTimeStampFormat(t, params, format) + }) + t.Run("environment variable", func(t *testing.T) { + t.Setenv("OPA_LOG_TIMESTAMP_FORMAT", format) + params := newTestRunParams() + checkLogTimeStampFormat(t, params, format) + }) + }) + } +} + +func checkLogTimeStampFormat(t *testing.T, params runCmdParams, format string) { + ctx, cancel := context.WithCancel(context.Background()) + + rt, err := initRuntime(ctx, params, nil) + if err != nil { + t.Fatalf("Unexpected error: %v", err) + } + var buf bytes.Buffer + logger := rt.Manager.Logger().(*logging.StandardLogger) + logger.SetOutput(&buf) + testRuntime := e2e.WrapRuntime(ctx, cancel, rt) + + done := make(chan bool) + go func() { + err := rt.Serve(ctx) + if err != nil { + t.Errorf("Unexpected error: %s", err) + } + done <- true + }() + + err = testRuntime.WaitForServer() + if err != nil { + t.Fatalf("Unexpected error: %s", err) + } + + validateBasicServe(t, testRuntime) + + cancel() + <-done + + for _, line := range strings.Split(buf.String(), "\n") { + line = strings.TrimSpace(line) + if line == "" { + continue + } + var rec struct { + Time string `json:"time"` + } + if err := json.Unmarshal([]byte(line), &rec); err != nil { + t.Fatalf("incorrect log message %s: %v", line, err) + } + if rec.Time == "" { + t.Fatalf("the time field is empty in log message: %s", line) + } + if _, err := time.Parse(format, rec.Time); err != nil { + t.Fatalf("incorrect timestamp format %q: %v", rec.Time, err) + } + } +} + func newTestRunParams() runCmdParams { params := newRunParams() params.rt.GracefulShutdownPeriod = 1 diff --git a/docs/content/cli.md b/docs/content/cli.md index be248e38a7..05b4d869e0 100755 --- a/docs/content/cli.md +++ b/docs/content/cli.md @@ -594,6 +594,7 @@ opa exec [ [...]] [flags] -h, --help help for exec --log-format {text,json,json-pretty} set log format (default json) -l, --log-level {debug,info,error} set log level (default error) + --log-timestamp-format string set log timestamp format (OPA_LOG_TIMESTAMP_FORMAT environment variable) --set stringArray override config values on the command line (use commas to specify multiple values) --set-file stringArray override config values with files on the command line (use commas to specify multiple values) ``` @@ -824,6 +825,7 @@ opa run [flags] --ignore strings set file and directory names to ignore during loading (e.g., '.*' excludes hidden files) --log-format {text,json,json-pretty} set log format (default json) -l, --log-level {debug,info,error} set log level (default info) + --log-timestamp-format string set log timestamp format (OPA_LOG_TIMESTAMP_FORMAT environment variable) -m, --max-errors int set the number of errors to allow before compilation fails early (default 10) --min-tls-version {1.0,1.1,1.2,1.3} set minimum TLS version to be used by OPA's server (default 1.2) --pprof enables pprof endpoints @@ -1071,5 +1073,3 @@ opa version [flags] -c, --check check for latest OPA release -h, --help help for version ``` - - diff --git a/internal/logging/logging.go b/internal/logging/logging.go index 93e12591f3..f97686cf44 100644 --- a/internal/logging/logging.go +++ b/internal/logging/logging.go @@ -10,8 +10,9 @@ import ( "fmt" "strings" - "github.com/open-policy-agent/opa/logging" "github.com/sirupsen/logrus" + + "github.com/open-policy-agent/opa/logging" ) func GetLevel(level string) (logging.Level, error) { @@ -29,14 +30,14 @@ func GetLevel(level string) (logging.Level, error) { } } -func GetFormatter(format string) logrus.Formatter { +func GetFormatter(format, timestampFormat string) logrus.Formatter { switch format { case "text": return &prettyFormatter{} case "json-pretty": - return &logrus.JSONFormatter{PrettyPrint: true} + return &logrus.JSONFormatter{PrettyPrint: true, TimestampFormat: timestampFormat} default: - return &logrus.JSONFormatter{} + return &logrus.JSONFormatter{TimestampFormat: timestampFormat} } } diff --git a/runtime/runtime.go b/runtime/runtime.go index 836d5eb3e1..f03df1757b 100644 --- a/runtime/runtime.go +++ b/runtime/runtime.go @@ -213,8 +213,9 @@ type Params struct { // LoggingConfig stores the configuration for OPA's logging behaviour. type LoggingConfig struct { - Level string - Format string + Level string + Format string + TimestampFormat string } // NewParams returns a new Params object. @@ -267,7 +268,7 @@ func NewRuntime(ctx context.Context, params Params) (*Runtime, error) { // that the logging configuration is applied. Once we remove all usage of // the global logger and we remove the API that allows callers to access the // global logger, we can remove this. - logging.Get().SetFormatter(internal_logging.GetFormatter(params.Logging.Format)) + logging.Get().SetFormatter(internal_logging.GetFormatter(params.Logging.Format, params.Logging.TimestampFormat)) logging.Get().SetLevel(level) var logger logging.Logger @@ -277,7 +278,7 @@ func NewRuntime(ctx context.Context, params Params) (*Runtime, error) { } else { stdLogger := logging.New() stdLogger.SetLevel(level) - stdLogger.SetFormatter(internal_logging.GetFormatter(params.Logging.Format)) + stdLogger.SetFormatter(internal_logging.GetFormatter(params.Logging.Format, params.Logging.TimestampFormat)) logger = stdLogger } @@ -308,7 +309,7 @@ func NewRuntime(ctx context.Context, params Params) (*Runtime, error) { consoleLogger := params.ConsoleLogger if consoleLogger == nil { l := logging.New() - l.SetFormatter(internal_logging.GetFormatter(params.Logging.Format)) + l.SetFormatter(internal_logging.GetFormatter(params.Logging.Format, params.Logging.TimestampFormat)) consoleLogger = l }