From 54e16d5f62ccd169c5f64319f3b174f6dc58e326 Mon Sep 17 00:00:00 2001 From: Denis Bilenko Date: Fri, 7 Feb 2025 12:29:40 +0100 Subject: [PATCH] Always print warnings and errors; clean up format (#2213) ## Changes - Print warnings and errors by default. - Fix ErrAlreadyPrinted not to be logged at Error level. - Format log messages as "Warn: message" instead of "WARN" to make it more readable and in-line with the rest of the output. - Only print attributes (pid, mutator, etc) and time when the overall level is debug (so --debug output has not changed much). ## Tests - Existing acceptance tests show how warning messages appear in various test case. - Added new test for `--debug` output. - Add sort_lines.py helper to avoid dependency on 'sort' which is locale-sensitive. --- acceptance/bin/sort_lines.py | 10 ++ acceptance/bundle/debug/databricks.yml | 2 + .../bundle/debug/out.stderr.parallel.txt | 15 +++ acceptance/bundle/debug/out.stderr.txt | 92 +++++++++++++++++++ acceptance/bundle/debug/output.txt | 7 ++ acceptance/bundle/debug/script | 4 + acceptance/bundle/debug/test.toml | 18 ++++ acceptance/bundle/git-permerror/output.txt | 9 ++ acceptance/bundle/git-permerror/test.toml | 2 +- bundle/artifacts/upload.go | 2 +- bundle/mutator.go | 2 +- bundle/mutator_read_only.go | 2 +- cmd/root/root.go | 11 ++- libs/flags/log_level_flag.go | 2 +- libs/flags/log_level_flag_test.go | 4 +- libs/log/handler/friendly.go | 60 ++++++------ 16 files changed, 206 insertions(+), 36 deletions(-) create mode 100755 acceptance/bin/sort_lines.py create mode 100644 acceptance/bundle/debug/databricks.yml create mode 100644 acceptance/bundle/debug/out.stderr.parallel.txt create mode 100644 acceptance/bundle/debug/out.stderr.txt create mode 100644 acceptance/bundle/debug/output.txt create mode 100644 acceptance/bundle/debug/script create mode 100644 acceptance/bundle/debug/test.toml diff --git a/acceptance/bin/sort_lines.py b/acceptance/bin/sort_lines.py new file mode 100755 index 000000000..9ac87feee --- /dev/null +++ b/acceptance/bin/sort_lines.py @@ -0,0 +1,10 @@ +#!/usr/bin/env python3 +""" +Helper to sort lines in text file. Similar to 'sort' but no dependence on locale or presence of 'sort' in PATH. +""" + +import sys + +lines = sys.stdin.readlines() +lines.sort() +sys.stdout.write("".join(lines)) diff --git a/acceptance/bundle/debug/databricks.yml b/acceptance/bundle/debug/databricks.yml new file mode 100644 index 000000000..2c9dd3c90 --- /dev/null +++ b/acceptance/bundle/debug/databricks.yml @@ -0,0 +1,2 @@ +bundle: + name: debug diff --git a/acceptance/bundle/debug/out.stderr.parallel.txt b/acceptance/bundle/debug/out.stderr.parallel.txt new file mode 100644 index 000000000..7dd770068 --- /dev/null +++ b/acceptance/bundle/debug/out.stderr.parallel.txt @@ -0,0 +1,15 @@ +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:SingleNodeCluster +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:artifact_paths +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:job_cluster_key_defined +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:job_task_cluster_spec +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:folder_permissions +10:07:59 Debug: ApplyReadOnly pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:validate_sync_patterns +10:07:59 Debug: Path /Workspace/Users/[USERNAME]/.bundle/debug/default/files has type directory (ID: 0) pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync +10:07:59 Debug: non-retriable error: pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync sdk=true +< {} pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync sdk=true +< {} pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync sdk=true +< } pid=12345 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync sdk=true diff --git a/acceptance/bundle/debug/out.stderr.txt b/acceptance/bundle/debug/out.stderr.txt new file mode 100644 index 000000000..9cac8bb2b --- /dev/null +++ b/acceptance/bundle/debug/out.stderr.txt @@ -0,0 +1,92 @@ +10:07:59 Info: start pid=12345 version=[DEV_VERSION] args="[CLI], bundle, validate, --debug" +10:07:59 Debug: Found bundle root at [TMPDIR] (file [TMPDIR]/databricks.yml) pid=12345 +10:07:59 Debug: Apply pid=12345 mutator=load +10:07:59 Info: Phase: load pid=12345 mutator=load +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=EntryPoint +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=scripts.preinit +10:07:59 Debug: No script defined for preinit, skipping pid=12345 mutator=load mutator=seq mutator=scripts.preinit +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=ProcessRootIncludes +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=ProcessRootIncludes mutator=seq +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=VerifyCliVersion +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=EnvironmentsToTargets +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=ComputeIdToClusterId +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=InitializeVariables +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=DefineDefaultTarget(default) +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=PythonMutator(load) +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=validate:unique_resource_keys +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=SelectDefaultTarget +10:07:59 Debug: Apply pid=12345 mutator=load mutator=seq mutator=SelectDefaultTarget mutator=SelectTarget(default) +10:07:59 Debug: Apply pid=12345 mutator= +10:07:59 Debug: Apply pid=12345 mutator=initialize +10:07:59 Info: Phase: initialize pid=12345 mutator=initialize +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=validate:AllResourcesHaveValues +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=RewriteSyncPaths +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=SyncDefaultPath +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=SyncInferRoot +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=PopulateCurrentUser +10:07:59 Debug: GET /api/2.0/preview/scim/v2/Me +< HTTP/1.1 200 OK +< { +< "id": "[USERID]", +< "userName": "[USERNAME]" +< } pid=12345 mutator=initialize mutator=seq mutator=PopulateCurrentUser sdk=true +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=LoadGitDetails +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ApplySourceLinkedDeploymentPreset +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=DefineDefaultWorkspaceRoot +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ExpandWorkspaceRoot +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=DefaultWorkspacePaths +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=PrependWorkspacePrefix +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=RewriteWorkspacePrefix +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=SetVariables +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=PythonMutator(init) +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=PythonMutator(load_resources) +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=PythonMutator(apply_mutators) +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ResolveVariableReferences +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ResolveResourceReferences +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ResolveVariableReferences +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=MergeJobClusters +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=MergeJobParameters +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=MergeJobTasks +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=MergePipelineClusters +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=MergeApps +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=CaptureSchemaDependency +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=CheckPermissions +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=SetRunAs +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=OverrideCompute +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ConfigureDashboardDefaults +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ConfigureVolumeDefaults +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ProcessTargetMode +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ApplyPresets +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=DefaultQueueing +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ExpandPipelineGlobPaths +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ConfigureWSFS +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=TranslatePaths +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=PythonWrapperWarning +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=apps.Validate +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ValidateSharedRootPermissions +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=ApplyBundlePermissions +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=FilterCurrentUserFromPermissions +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=metadata.AnnotateJobs +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=metadata.AnnotatePipelines +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=terraform.Initialize +10:07:59 Debug: Using Terraform from DATABRICKS_TF_EXEC_PATH at [TERRAFORM] pid=12345 mutator=initialize mutator=seq mutator=terraform.Initialize +10:07:59 Debug: Using Terraform CLI config from DATABRICKS_TF_CLI_CONFIG_FILE at [DATABRICKS_TF_CLI_CONFIG_FILE] pid=12345 mutator=initialize mutator=seq mutator=terraform.Initialize +10:07:59 Debug: Environment variables for Terraform: ...redacted... pid=12345 mutator=initialize mutator=seq mutator=terraform.Initialize +10:07:59 Debug: Apply pid=12345 mutator=initialize mutator=seq mutator=scripts.postinit +10:07:59 Debug: No script defined for postinit, skipping pid=12345 mutator=initialize mutator=seq mutator=scripts.postinit +10:07:59 Debug: Apply pid=12345 mutator=validate +10:07:59 Debug: GET /api/2.0/workspace/get-status?path=/Workspace/Users/[USERNAME]/.bundle/debug/default/files +< HTTP/1.1 404 Not Found +10:07:59 Debug: POST /api/2.0/workspace/mkdirs +> { +> "path": "/Workspace/Users/[USERNAME]/.bundle/debug/default/files" +> } +< HTTP/1.1 200 OK +10:07:59 Debug: GET /api/2.0/workspace/get-status?path=/Workspace/Users/[USERNAME]/.bundle/debug/default/files +< HTTP/1.1 200 OK +< { +< "object_type": "DIRECTORY", +< "path": "/Workspace/Users/[USERNAME]/.bundle/debug/default/files" +10:07:59 Info: completed execution pid=12345 exit_code=0 diff --git a/acceptance/bundle/debug/output.txt b/acceptance/bundle/debug/output.txt new file mode 100644 index 000000000..ed72b360e --- /dev/null +++ b/acceptance/bundle/debug/output.txt @@ -0,0 +1,7 @@ +Name: debug +Target: default +Workspace: + User: [USERNAME] + Path: /Workspace/Users/[USERNAME]/.bundle/debug/default + +Validation OK! diff --git a/acceptance/bundle/debug/script b/acceptance/bundle/debug/script new file mode 100644 index 000000000..1b4cfc8f0 --- /dev/null +++ b/acceptance/bundle/debug/script @@ -0,0 +1,4 @@ +$CLI bundle validate --debug 2> full.stderr.txt +grep -vw parallel full.stderr.txt > out.stderr.txt +grep -w parallel full.stderr.txt | sort_lines.py > out.stderr.parallel.txt +rm full.stderr.txt diff --git a/acceptance/bundle/debug/test.toml b/acceptance/bundle/debug/test.toml new file mode 100644 index 000000000..bb0fcb395 --- /dev/null +++ b/acceptance/bundle/debug/test.toml @@ -0,0 +1,18 @@ +LocalOnly = true + +[[Repls]] +# The keys are unsorted and also vary per OS +Old = 'Environment variables for Terraform: ([A-Z_ ,]+) ' +New = 'Environment variables for Terraform: ...redacted... ' + +[[Repls]] +Old = 'pid=[0-9]+' +New = 'pid=12345' + +[[Repls]] +Old = '\d\d:\d\d:\d\d' +New = '10:07:59' + +[[Repls]] +Old = '\\' +New = '/' diff --git a/acceptance/bundle/git-permerror/output.txt b/acceptance/bundle/git-permerror/output.txt index 03ab93442..730e8255b 100644 --- a/acceptance/bundle/git-permerror/output.txt +++ b/acceptance/bundle/git-permerror/output.txt @@ -3,6 +3,7 @@ >>> chmod 000 .git >>> [CLI] bundle validate +Warn: failed to read .git: unable to load repository specific gitconfig: open config: permission denied Error: unable to load repository specific gitconfig: open config: permission denied Name: git-permerror @@ -16,6 +17,7 @@ Found 1 error Exit code: 1 >>> [CLI] bundle validate -o json +Warn: failed to read .git: unable to load repository specific gitconfig: open config: permission denied Error: unable to load repository specific gitconfig: open config: permission denied @@ -25,6 +27,7 @@ Exit code: 1 } >>> withdir subdir/a/b [CLI] bundle validate -o json +Warn: failed to read .git: unable to load repository specific gitconfig: open config: permission denied Error: unable to load repository specific gitconfig: open config: permission denied @@ -39,11 +42,15 @@ Exit code: 1 >>> chmod 000 .git/HEAD >>> [CLI] bundle validate -o json +Warn: failed to load current branch: open HEAD: permission denied +Warn: failed to load latest commit: open HEAD: permission denied { "bundle_root_path": "." } >>> withdir subdir/a/b [CLI] bundle validate -o json +Warn: failed to load current branch: open HEAD: permission denied +Warn: failed to load latest commit: open HEAD: permission denied { "bundle_root_path": "." } @@ -54,6 +61,7 @@ Exit code: 1 >>> chmod 000 .git/config >>> [CLI] bundle validate -o json +Warn: failed to read .git: unable to load repository specific gitconfig: open config: permission denied Error: unable to load repository specific gitconfig: open config: permission denied @@ -63,6 +71,7 @@ Exit code: 1 } >>> withdir subdir/a/b [CLI] bundle validate -o json +Warn: failed to read .git: unable to load repository specific gitconfig: open config: permission denied Error: unable to load repository specific gitconfig: open config: permission denied diff --git a/acceptance/bundle/git-permerror/test.toml b/acceptance/bundle/git-permerror/test.toml index 3f96e551c..15305cff1 100644 --- a/acceptance/bundle/git-permerror/test.toml +++ b/acceptance/bundle/git-permerror/test.toml @@ -1,4 +1,4 @@ -Badness = "Warning logs not shown; inferred flag is set to true incorrect; bundle_root_path is not correct" +Badness = "inferred flag is set to true incorrect; bundle_root_path is not correct; Warn and Error talk about the same; Warn goes to stderr, Error goes to stdout (for backward compat); Warning about permissions repeated twice" [GOOS] # This test relies on chmod which does not work on Windows diff --git a/bundle/artifacts/upload.go b/bundle/artifacts/upload.go index c69939e8c..d4625d85d 100644 --- a/bundle/artifacts/upload.go +++ b/bundle/artifacts/upload.go @@ -29,7 +29,7 @@ func (m *cleanUp) Apply(ctx context.Context, b *bundle.Bundle) diag.Diagnostics // We intentionally ignore the error because it is not critical to the deployment err := client.Delete(ctx, ".", filer.DeleteRecursively) if err != nil { - log.Errorf(ctx, "failed to delete %s: %v", uploadPath, err) + log.Debugf(ctx, "failed to delete %s: %v", uploadPath, err) } err = client.Mkdir(ctx, ".") diff --git a/bundle/mutator.go b/bundle/mutator.go index 6c9968aac..16ef79ee7 100644 --- a/bundle/mutator.go +++ b/bundle/mutator.go @@ -42,7 +42,7 @@ func Apply(ctx context.Context, b *Bundle, m Mutator) diag.Diagnostics { // such that they are not logged multiple times. // If this is done, we can omit this block. if err := diags.Error(); err != nil { - log.Errorf(ctx, "Error: %s", err) + log.Debugf(ctx, "Error: %s", err) } return diags diff --git a/bundle/mutator_read_only.go b/bundle/mutator_read_only.go index ee4e36e0f..700a90d8d 100644 --- a/bundle/mutator_read_only.go +++ b/bundle/mutator_read_only.go @@ -22,7 +22,7 @@ func ApplyReadOnly(ctx context.Context, rb ReadOnlyBundle, m ReadOnlyMutator) di log.Debugf(ctx, "ApplyReadOnly") diags := m.Apply(ctx, rb) if err := diags.Error(); err != nil { - log.Errorf(ctx, "Error: %s", err) + log.Debugf(ctx, "Error: %s", err) } return diags diff --git a/cmd/root/root.go b/cmd/root/root.go index 3b37d0176..d7adf47f4 100644 --- a/cmd/root/root.go +++ b/cmd/root/root.go @@ -114,10 +114,15 @@ func Execute(ctx context.Context, cmd *cobra.Command) error { if err == nil { logger.Info("completed execution", slog.String("exit_code", "0")) - } else { - logger.Error("failed execution", + } else if errors.Is(err, ErrAlreadyPrinted) { + logger.Debug("failed execution", slog.String("exit_code", "1"), - slog.String("error", err.Error())) + ) + } else { + logger.Info("failed execution", + slog.String("exit_code", "1"), + slog.String("error", err.Error()), + ) } } diff --git a/libs/flags/log_level_flag.go b/libs/flags/log_level_flag.go index 836d84b70..82e2abc4c 100644 --- a/libs/flags/log_level_flag.go +++ b/libs/flags/log_level_flag.go @@ -25,7 +25,7 @@ type LogLevelFlag struct { func NewLogLevelFlag() LogLevelFlag { return LogLevelFlag{ - l: log.LevelDisabled, + l: log.LevelWarn, } } diff --git a/libs/flags/log_level_flag_test.go b/libs/flags/log_level_flag_test.go index 11a50bc45..c81f90d18 100644 --- a/libs/flags/log_level_flag_test.go +++ b/libs/flags/log_level_flag_test.go @@ -10,8 +10,8 @@ import ( func TestLogLevelFlagDefault(t *testing.T) { f := NewLogLevelFlag() - assert.Equal(t, log.LevelDisabled, f.Level()) - assert.Equal(t, "disabled", f.String()) + assert.Equal(t, log.LevelWarn, f.Level()) + assert.Equal(t, "warn", f.String()) } func TestLogLevelFlagSetValid(t *testing.T) { diff --git a/libs/log/handler/friendly.go b/libs/log/handler/friendly.go index 33b88a9e2..5c60eb13d 100644 --- a/libs/log/handler/friendly.go +++ b/libs/log/handler/friendly.go @@ -53,11 +53,11 @@ func NewFriendlyHandler(out io.Writer, opts *Options) slog.Handler { // Cache (colorized) level strings. // The colors to use for each level are configured in `colors.go`. - h.levelTrace = h.sprintf(ttyColorLevelTrace, "%5s", "TRACE") - h.levelDebug = h.sprintf(ttyColorLevelDebug, "%5s", "DEBUG") - h.levelInfo = h.sprintf(ttyColorLevelInfo, "%5s", "INFO") - h.levelWarn = h.sprintf(ttyColorLevelWarn, "%5s", "WARN") - h.levelError = h.sprintf(ttyColorLevelError, "%5s", "ERROR") + h.levelTrace = h.sprintf(ttyColorLevelTrace, "%s", "Trace:") + h.levelDebug = h.sprintf(ttyColorLevelDebug, "%s", "Debug:") + h.levelInfo = h.sprintf(ttyColorLevelInfo, "%s", "Info:") + h.levelWarn = h.sprintf(ttyColorLevelWarn, "%s", "Warn:") + h.levelError = h.sprintf(ttyColorLevelError, "%s", "Error:") return h } @@ -185,33 +185,41 @@ func (s *handleState) appendAttr(a slog.Attr) { // Handle implements slog.Handler. func (h *friendlyHandler) Handle(ctx context.Context, r slog.Record) error { state := h.handleState() - state.append(h.sprintf(ttyColorTime, "%02d:%02d:%02d ", r.Time.Hour(), r.Time.Minute(), r.Time.Second())) + + if h.opts.Level.Level() <= slog.LevelDebug { + state.append(h.sprintf(ttyColorTime, "%02d:%02d:%02d ", r.Time.Hour(), r.Time.Minute(), r.Time.Second())) + } + state.appendf("%s ", h.coloredLevel(r)) state.append(h.sprint(ttyColorMessage, r.Message)) - // Handle state from WithGroup and WithAttrs. - goas := h.goas - if r.NumAttrs() == 0 { - // If the record has no Attrs, remove groups at the end of the list; they are empty. - for len(goas) > 0 && goas[len(goas)-1].group != "" { - goas = goas[:len(goas)-1] - } - } - for _, goa := range goas { - if goa.group != "" { - state.openGroup(goa.group) - } else { - for _, a := range goa.attrs { - state.appendAttr(a) + if h.opts.Level.Level() <= slog.LevelDebug { + + // Handle state from WithGroup and WithAttrs. + goas := h.goas + if r.NumAttrs() == 0 { + // If the record has no Attrs, remove groups at the end of the list; they are empty. + for len(goas) > 0 && goas[len(goas)-1].group != "" { + goas = goas[:len(goas)-1] + } + } + for _, goa := range goas { + if goa.group != "" { + state.openGroup(goa.group) + } else { + for _, a := range goa.attrs { + state.appendAttr(a) + } } } - } - // Add attributes from the record. - r.Attrs(func(a slog.Attr) bool { - state.appendAttr(a) - return true - }) + // Add attributes from the record. + r.Attrs(func(a slog.Attr) bool { + state.appendAttr(a) + return true + }) + + } // Add newline. state.append("\n")