From f429c5d7939867fd09859f38b3a547f25403e1f8 Mon Sep 17 00:00:00 2001 From: Denis Bilenko Date: Fri, 24 Jan 2025 19:45:05 +0100 Subject: [PATCH] tweak log output - remove time - remove attrs unless level is debug - replace $DEV_VERSION - add acceptance test for --debug --- acceptance/bundle/debug/databricks.yml | 2 + .../bundle/debug/out.stderr.parallel.txt | 12 +++ acceptance/bundle/debug/out.stderr.txt | 86 +++++++++++++++++++ acceptance/bundle/debug/out.stdout.txt | 7 ++ acceptance/bundle/debug/output.txt | 0 acceptance/bundle/debug/script | 3 + acceptance/bundle/debug/test.toml | 8 ++ acceptance/bundle/git-permerror/output.txt | 9 ++ .../bundle/templates/dbt-sql/output.txt | 1 + .../templates/default-python/output.txt | 1 + .../bundle/templates/default-sql/output.txt | 1 + libs/flags/log_level_flag_test.go | 4 +- libs/log/handler/friendly.go | 55 ++++++------ 13 files changed, 161 insertions(+), 28 deletions(-) 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/out.stdout.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/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..87530b84c --- /dev/null +++ b/acceptance/bundle/debug/out.stderr.parallel.txt @@ -0,0 +1,12 @@ +< } pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync sdk=true +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:SingleNodeCluster +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:artifact_paths +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:job_cluster_key_defined +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=fast_validate(readonly) mutator (read-only)=parallel mutator (read-only)=validate:job_task_cluster_spec +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:folder_permissions +Debug: ApplyReadOnly pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:validate_sync_patterns +Debug: Path has type directory (ID: 1001) pid=00000 mutator=validate mutator (read-only)=parallel mutator (read-only)=validate:files_to_sync diff --git a/acceptance/bundle/debug/out.stderr.txt b/acceptance/bundle/debug/out.stderr.txt new file mode 100644 index 000000000..d128e599e --- /dev/null +++ b/acceptance/bundle/debug/out.stderr.txt @@ -0,0 +1,86 @@ +Info: start pid=00000 version=$DEV_VERSION args="$CLI, bundle, validate, --debug" +Debug: Found bundle root at $TMPDIR (file $TMPDIR/databricks.yml) pid=00000 +Debug: Apply pid=00000 mutator=load +Info: Phase: load pid=00000 mutator=load +Debug: Apply pid=00000 mutator=load mutator=seq +Debug: Apply pid=00000 mutator=load mutator=seq mutator=EntryPoint +Debug: Apply pid=00000 mutator=load mutator=seq mutator=scripts.preinit +Debug: No script defined for preinit, skipping pid=00000 mutator=load mutator=seq mutator=scripts.preinit +Debug: Apply pid=00000 mutator=load mutator=seq mutator=ProcessRootIncludes +Debug: Apply pid=00000 mutator=load mutator=seq mutator=ProcessRootIncludes mutator=seq +Debug: Apply pid=00000 mutator=load mutator=seq mutator=VerifyCliVersion +Debug: Apply pid=00000 mutator=load mutator=seq mutator=EnvironmentsToTargets +Debug: Apply pid=00000 mutator=load mutator=seq mutator=ComputeIdToClusterId +Debug: Apply pid=00000 mutator=load mutator=seq mutator=InitializeVariables +Debug: Apply pid=00000 mutator=load mutator=seq mutator=DefineDefaultTarget(default) +Debug: Apply pid=00000 mutator=load mutator=seq mutator=PythonMutator(load) +Debug: Apply pid=00000 mutator=load mutator=seq mutator=validate:unique_resource_keys +Debug: Apply pid=00000 mutator=load mutator=seq mutator=SelectDefaultTarget +Debug: Apply pid=00000 mutator=load mutator=seq mutator=SelectDefaultTarget mutator=SelectTarget(default) +Debug: Apply pid=00000 mutator= +Debug: Apply pid=00000 mutator=initialize +Info: Phase: initialize pid=00000 mutator=initialize +Debug: Apply pid=00000 mutator=initialize mutator=seq +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=validate:AllResourcesHaveValues +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=RewriteSyncPaths +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=SyncDefaultPath +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=SyncInferRoot +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=InitializeWorkspaceClient +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=PopulateCurrentUser +Debug: GET /api/2.0/preview/scim/v2/Me +< HTTP/1.1 200 OK +< { +< "userName": "$USERNAME" +< } pid=00000 mutator=initialize mutator=seq mutator=PopulateCurrentUser sdk=true +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=LoadGitDetails +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ApplySourceLinkedDeploymentPreset +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=DefineDefaultWorkspaceRoot +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ExpandWorkspaceRoot +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=DefaultWorkspacePaths +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=PrependWorkspacePrefix +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=RewriteWorkspacePrefix +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=SetVariables +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=PythonMutator(init) +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=PythonMutator(load_resources) +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=PythonMutator(apply_mutators) +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ResolveVariableReferences +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ResolveResourceReferences +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ResolveVariableReferences +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=MergeJobClusters +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=MergeJobParameters +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=MergeJobTasks +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=MergePipelineClusters +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=MergeApps +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=CaptureSchemaDependency +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=CheckPermissions +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=SetRunAs +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=OverrideCompute +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ConfigureDashboardDefaults +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ConfigureVolumeDefaults +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ProcessTargetMode +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ApplyPresets +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=DefaultQueueing +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ExpandPipelineGlobPaths +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ConfigureWSFS +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=TranslatePaths +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=PythonWrapperWarning +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=apps.Validate +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ValidateSharedRootPermissions +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=ApplyBundlePermissions +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=FilterCurrentUserFromPermissions +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=metadata.AnnotateJobs +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=metadata.AnnotatePipelines +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=terraform.Initialize +Debug: Using Terraform from DATABRICKS_TF_EXEC_PATH at $TMPHOME pid=00000 mutator=initialize mutator=seq mutator=terraform.Initialize +Debug: DATABRICKS_TF_CLI_CONFIG_FILE is not defined pid=00000 mutator=initialize mutator=seq mutator=terraform.Initialize +Debug: Environment variables for Terraform: ...redacted... pid=00000 mutator=initialize mutator=seq mutator=terraform.Initialize +Debug: Apply pid=00000 mutator=initialize mutator=seq mutator=scripts.postinit +Debug: No script defined for postinit, skipping pid=00000 mutator=initialize mutator=seq mutator=scripts.postinit +Debug: Apply pid=00000 mutator=validate +Debug: GET /api/2.0/workspace/get-status?path=/Workspace/Users/$USERNAME/.bundle/debug/default/files +< HTTP/1.1 200 OK +< { +< "object_id": 1001, +< "object_type": "DIRECTORY", +< "resource_id": "1001" +Info: completed execution pid=00000 exit_code=0 diff --git a/acceptance/bundle/debug/out.stdout.txt b/acceptance/bundle/debug/out.stdout.txt new file mode 100644 index 000000000..df4765946 --- /dev/null +++ b/acceptance/bundle/debug/out.stdout.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/output.txt b/acceptance/bundle/debug/output.txt new file mode 100644 index 000000000..e69de29bb diff --git a/acceptance/bundle/debug/script b/acceptance/bundle/debug/script new file mode 100644 index 000000000..b0e5f4503 --- /dev/null +++ b/acceptance/bundle/debug/script @@ -0,0 +1,3 @@ +$CLI bundle validate --debug > out.stdout.txt 2> full.stderr.txt +grep -vw parallel full.stderr.txt > out.stderr.txt +grep -w parallel full.stderr.txt | sort > out.stderr.parallel.txt diff --git a/acceptance/bundle/debug/test.toml b/acceptance/bundle/debug/test.toml new file mode 100644 index 000000000..401f48494 --- /dev/null +++ b/acceptance/bundle/debug/test.toml @@ -0,0 +1,8 @@ +[[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=00000' diff --git a/acceptance/bundle/git-permerror/output.txt b/acceptance/bundle/git-permerror/output.txt index 60e77ca0e..af4847f4e 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/templates/dbt-sql/output.txt b/acceptance/bundle/templates/dbt-sql/output.txt index 972c7e152..a04047faa 100644 --- a/acceptance/bundle/templates/dbt-sql/output.txt +++ b/acceptance/bundle/templates/dbt-sql/output.txt @@ -22,6 +22,7 @@ Workspace: Validation OK! >>> $CLI bundle validate -t prod +Warn: target with 'mode: production' should specify an explicit 'targets.prod.git' configuration Name: my_dbt_sql Target: prod Workspace: diff --git a/acceptance/bundle/templates/default-python/output.txt b/acceptance/bundle/templates/default-python/output.txt index 5493ac2cf..8c925e568 100644 --- a/acceptance/bundle/templates/default-python/output.txt +++ b/acceptance/bundle/templates/default-python/output.txt @@ -20,6 +20,7 @@ Workspace: Validation OK! >>> $CLI bundle validate -t prod +Warn: target with 'mode: production' should specify an explicit 'targets.prod.git' configuration Name: my_default_python Target: prod Workspace: diff --git a/acceptance/bundle/templates/default-sql/output.txt b/acceptance/bundle/templates/default-sql/output.txt index fe0139093..d07e90c69 100644 --- a/acceptance/bundle/templates/default-sql/output.txt +++ b/acceptance/bundle/templates/default-sql/output.txt @@ -22,6 +22,7 @@ Workspace: Validation OK! >>> $CLI bundle validate -t prod +Warn: target with 'mode: production' should specify an explicit 'targets.prod.git' configuration Name: my_default_sql Target: prod Workspace: 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..8bd8c6e5b 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,36 @@ 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())) 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")