From 5aa3bdade4c140d7f4b6306ebb218de77f8d517e 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 ++ libs/flags/log_level_flag_test.go | 4 +- libs/log/handler/friendly.go | 55 ++++++------ 9 files changed, 149 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/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")