From 0c92905f443375270c5eb7b881c20e00067be36c Mon Sep 17 00:00:00 2001 From: Ilia Babanov Date: Mon, 6 Nov 2023 10:20:50 +0100 Subject: [PATCH 1/3] Log process id in each log entry This will help differentiate multiple cli commands that write to the same log file. Noticed that the root module wasn't using the common log utilities, refactored it to avoid missing log arguments --- cmd/root/root.go | 16 ++++------------ libs/log/logger.go | 2 ++ libs/log/sdk.go | 2 ++ 3 files changed, 8 insertions(+), 12 deletions(-) diff --git a/cmd/root/root.go b/cmd/root/root.go index 38eb42ccb0..b3283f5bd4 100644 --- a/cmd/root/root.go +++ b/cmd/root/root.go @@ -6,8 +6,6 @@ import ( "os" "strings" - "log/slog" - "github.com/databricks/cli/internal/build" "github.com/databricks/cli/libs/cmdio" "github.com/databricks/cli/libs/log" @@ -51,10 +49,7 @@ func New(ctx context.Context) *cobra.Command { return err } - logger := log.GetLogger(ctx) - logger.Info("start", - slog.String("version", build.GetInfo().Version), - slog.String("args", strings.Join(os.Args, ", "))) + log.Infof(ctx, "Starting execution with version: %s, arguments: %s", build.GetInfo().Version, strings.Join(os.Args, ", ")) // Configure progress logger ctx, err = progressLoggerFlag.initializeContext(ctx) @@ -106,14 +101,11 @@ func Execute(cmd *cobra.Command) { // Log exit status and error // We only log if logger initialization succeeded and is stored in command // context - if logger, ok := log.FromContext(cmd.Context()); ok { + if _, ok := log.FromContext(cmd.Context()); ok { if err == nil { - logger.Info("completed execution", - slog.String("exit_code", "0")) + log.Infof(ctx, "Completed execution with exit code 0") } else { - logger.Error("failed execution", - slog.String("exit_code", "1"), - slog.String("error", err.Error())) + log.Errorf(ctx, "Failed execution with exit code 1, error: %s", err.Error()) } } diff --git a/libs/log/logger.go b/libs/log/logger.go index 43a30e92bf..2b9f7a8c81 100644 --- a/libs/log/logger.go +++ b/libs/log/logger.go @@ -3,6 +3,7 @@ package log import ( "context" "fmt" + "os" "runtime" "time" @@ -25,6 +26,7 @@ func log(logger *slog.Logger, ctx context.Context, level slog.Level, msg string) // skip [runtime.Callers, this function, this function's caller]. runtime.Callers(3, pcs[:]) r := slog.NewRecord(time.Now(), level, msg, pcs[0]) + r.AddAttrs(slog.Int("pid", os.Getpid())) if ctx == nil { ctx = context.Background() } diff --git a/libs/log/sdk.go b/libs/log/sdk.go index e1b1ffed46..70b94942e8 100644 --- a/libs/log/sdk.go +++ b/libs/log/sdk.go @@ -3,6 +3,7 @@ package log import ( "context" "fmt" + "os" "runtime" "time" @@ -38,6 +39,7 @@ func (s slogAdapter) log(logger *slog.Logger, ctx context.Context, level slog.Le runtime.Callers(4, pcs[:]) r := slog.NewRecord(time.Now(), level, msg, pcs[0]) r.AddAttrs(slog.Bool("sdk", true)) + r.AddAttrs(slog.Int("pid", os.Getpid())) if ctx == nil { ctx = context.Background() } From bcd4aa90e6d6c3afd22c065dab1358aadbb4305a Mon Sep 17 00:00:00 2001 From: Ilia Babanov Date: Mon, 6 Nov 2023 19:06:50 +0100 Subject: [PATCH 2/3] Inject pid into a logger using With instead --- cmd/root/logger.go | 3 ++- cmd/root/root.go | 15 +++++++++++---- libs/log/logger.go | 2 -- libs/log/sdk.go | 2 -- 4 files changed, 13 insertions(+), 9 deletions(-) diff --git a/cmd/root/logger.go b/cmd/root/logger.go index dca07ca4be..0ad6756afb 100644 --- a/cmd/root/logger.go +++ b/cmd/root/logger.go @@ -5,6 +5,7 @@ import ( "fmt" "io" "log/slog" + "os" "github.com/databricks/cli/libs/cmdio" "github.com/databricks/cli/libs/env" @@ -113,7 +114,7 @@ func (f *logFlags) initializeContext(ctx context.Context) (context.Context, erro return nil, err } - slog.SetDefault(slog.New(handler)) + slog.SetDefault(slog.New(handler).With(slog.Int("pid", os.Getpid()))) return log.NewContext(ctx, slog.Default()), nil } diff --git a/cmd/root/root.go b/cmd/root/root.go index b3283f5bd4..dba33b8709 100644 --- a/cmd/root/root.go +++ b/cmd/root/root.go @@ -3,6 +3,7 @@ package root import ( "context" "fmt" + "log/slog" "os" "strings" @@ -49,7 +50,10 @@ func New(ctx context.Context) *cobra.Command { return err } - log.Infof(ctx, "Starting execution with version: %s, arguments: %s", build.GetInfo().Version, strings.Join(os.Args, ", ")) + logger := log.GetLogger(ctx) + logger.Info("start", + slog.String("version", build.GetInfo().Version), + slog.String("args", strings.Join(os.Args, ", "))) // Configure progress logger ctx, err = progressLoggerFlag.initializeContext(ctx) @@ -101,11 +105,14 @@ func Execute(cmd *cobra.Command) { // Log exit status and error // We only log if logger initialization succeeded and is stored in command // context - if _, ok := log.FromContext(cmd.Context()); ok { + if logger, ok := log.FromContext(cmd.Context()); ok { if err == nil { - log.Infof(ctx, "Completed execution with exit code 0") + logger.Info("completed execution", + slog.String("exit_code", "0")) } else { - log.Errorf(ctx, "Failed execution with exit code 1, error: %s", err.Error()) + logger.Error("failed execution", + slog.String("exit_code", "1"), + slog.String("error", err.Error())) } } diff --git a/libs/log/logger.go b/libs/log/logger.go index 2b9f7a8c81..43a30e92bf 100644 --- a/libs/log/logger.go +++ b/libs/log/logger.go @@ -3,7 +3,6 @@ package log import ( "context" "fmt" - "os" "runtime" "time" @@ -26,7 +25,6 @@ func log(logger *slog.Logger, ctx context.Context, level slog.Level, msg string) // skip [runtime.Callers, this function, this function's caller]. runtime.Callers(3, pcs[:]) r := slog.NewRecord(time.Now(), level, msg, pcs[0]) - r.AddAttrs(slog.Int("pid", os.Getpid())) if ctx == nil { ctx = context.Background() } diff --git a/libs/log/sdk.go b/libs/log/sdk.go index 70b94942e8..e1b1ffed46 100644 --- a/libs/log/sdk.go +++ b/libs/log/sdk.go @@ -3,7 +3,6 @@ package log import ( "context" "fmt" - "os" "runtime" "time" @@ -39,7 +38,6 @@ func (s slogAdapter) log(logger *slog.Logger, ctx context.Context, level slog.Le runtime.Callers(4, pcs[:]) r := slog.NewRecord(time.Now(), level, msg, pcs[0]) r.AddAttrs(slog.Bool("sdk", true)) - r.AddAttrs(slog.Int("pid", os.Getpid())) if ctx == nil { ctx = context.Background() } From 1a8d05c4d8a3a8995b72c3d19f042dbb25899b2a Mon Sep 17 00:00:00 2001 From: Ilia Babanov Date: Mon, 6 Nov 2023 19:21:51 +0100 Subject: [PATCH 3/3] Reformat imports to their old state --- cmd/root/root.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/cmd/root/root.go b/cmd/root/root.go index dba33b8709..38eb42ccb0 100644 --- a/cmd/root/root.go +++ b/cmd/root/root.go @@ -3,10 +3,11 @@ package root import ( "context" "fmt" - "log/slog" "os" "strings" + "log/slog" + "github.com/databricks/cli/internal/build" "github.com/databricks/cli/libs/cmdio" "github.com/databricks/cli/libs/log"