Add progress logs for job runs by shreyas-goenka · Pull Request #276 · databricks/cli

shreyas-goenka · 2023-03-24T02:54:37Z

No description provided.

shreyas-goenka · 2023-03-24T14:42:21Z

Output for append mode

shreyas.goenka@THW32HFW6T job-output % bricks bundle run foo --log-level=disabled --progress-format=append
2023-03-24 15:25:04 [job-output] test-job by shreyas RUNNING https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19168439
2023-03-24 15:27:08 [job-output] test-job by shreyas TERMINATED SUCCESS https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19168439
Run URL: https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19168439
=======
Task my_notebook_task:
computed results from notebook.
=======
Task my_python_task:
[my_python_script] hello, world

shreyas-goenka · 2023-03-24T14:42:51Z

Output for json mode:

shreyas.goenka@THW32HFW6T job-output % bricks bundle run foo --log-level=disabled --progress-format=json
{
"timestamp": "2023-03-24T15:41:51.237878+01:00",
"job_id": 1077573342009637,
"run_id": 19169866,
"run_name": "[job-output] test-job by shreyas",
"state": {
"life_cycle_state": "RUNNING"
},
"run_page_url": "https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19169866"
}
{
"timestamp": "2023-03-24T15:42:08.324034+01:00",
"job_id": 1077573342009637,
"run_id": 19169866,
"run_name": "[job-output] test-job by shreyas",
"state": {
"life_cycle_state": "TERMINATED",
"result_state": "SUCCESS"
},
"run_page_url": "https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19169866"
}
Run URL: https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19169866
=======
Task my_notebook_task:
computed results from notebook.
=======
Task my_python_task:
[my_python_script] hello, world

shreyas-goenka · 2023-03-24T14:45:40Z

output mode Inplace (default on tty)

Screen.Recording.2023-03-24.at.3.44.27.PM.mov

shreyas-goenka · 2023-03-24T14:47:49Z

Default output on non tty console (debug console)

Starting: /Users/shreyas.goenka/go/bin/dlv dap --listen=127.0.0.1:51818 --log-dest=3 from /Users/shreyas.goenka/bricks
DAP server listening at: 127.0.0.1:51818
Type 'dlv help' for list of commands.
2023-03-24 15:47:02 [job-output] test-job by shreyas RUNNING https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19174858
2023-03-24 15:47:19 [job-output] test-job by shreyas TERMINATED SUCCESS https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19174858
Run URL: https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19174858
=======
Task my_notebook_task:
computed results from notebook.
=======
Task my_python_task:
[my_python_script] hello, world

shreyas-goenka · 2023-03-27T01:39:21Z

Added normal logging for all progress events:
output now:

shreyas.goenka@THW32HFW6T job-output % bricks bundle run foo
time=2023-03-27T03:38:25.759+02:00 level=INFO source=phase.go:30 msg="Phase: initialize" mutator=initialize
time=2023-03-27T03:38:26.946+02:00 level=INFO source=job.go:158 msg="Run available at https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722" resource=jobs.foo
time=2023-03-27T03:38:26.946+02:00 level=INFO source=job.go:161 msg="Run status: RUNNING" resource=jobs.foo
2023-03-27 03:38:26 [job-output] test-job by shreyas RUNNING https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722
time=2023-03-27T03:38:26.946+02:00 level=INFO source=job.go:193 msg="2023-03-27 03:38:26 [job-output] test-job by shreyas RUNNING https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722" resource=jobs.foo event_type=progress_event_job
time=2023-03-27T03:38:28.179+02:00 level=INFO source=job.go:193 msg="2023-03-27 03:38:28 [job-output] test-job by shreyas RUNNING https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722" resource=jobs.foo event_type=progress_event_job
time=2023-03-27T03:38:30.472+02:00 level=INFO source=job.go:193 msg="2023-03-27 03:38:30 [job-output] test-job by shreyas RUNNING https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722" resource=jobs.foo event_type=progress_event_job
time=2023-03-27T03:38:34.108+02:00 level=INFO source=job.go:193 msg="2023-03-27 03:38:34 [job-output] test-job by shreyas RUNNING https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722" resource=jobs.foo event_type=progress_event_job
time=2023-03-27T03:38:38.895+02:00 level=INFO source=job.go:161 msg="Run status: TERMINATED" resource=jobs.foo
2023-03-27 03:38:38 [job-output] test-job by shreyas TERMINATED SUCCESS https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722
time=2023-03-27T03:38:38.895+02:00 level=INFO source=job.go:193 msg="2023-03-27 03:38:38 [job-output] test-job by shreyas TERMINATED SUCCESS https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722" resource=jobs.foo event_type=progress_event_job
time=2023-03-27T03:38:38.895+02:00 level=INFO source=job.go:253 msg="Run has completed successfully!" resource=jobs.foo
Run URL: https://adb-309687753508875.15.azuredatabricks.net/?o=309687753508875#job/1077573342009637/run/19192722
=======
Task my_notebook_task:
computed results from notebook.
=======
Task my_python_task:
[my_python_script] hello, world

shreyas-goenka · 2023-03-27T01:40:31Z

I followed the guide here, but could not get autocomplete working properly on my system: https://github.com/spf13/cobra/blob/main/shell_completions.md#zsh-completions

shreyas-goenka · 2023-03-27T17:50:39Z

+ fmt.Fprintln(os.Stderr, event.String())
+
+	default:
+ // we panic because errors are not captured in some log sides like


@pietern do you think we should change the go SDK to capture these errors in the runner?

Which error specifically?
If the mode is passed on construction it should never be invalid.

shreyas-goenka · 2023-03-27T18:02:03Z

Added autocomplete

shreyas.goenka@THW32HFW6T bricks % bricks bundle run foo --progress-format json
append inplace json

pietern · 2023-03-28T10:07:30Z

+ fmt.Fprintln(os.Stderr, event.String())
+
+	default:
+ // we panic because errors are not captured in some log sides like


Which error specifically?
If the mode is passed on construction it should never be invalid.

pietern · 2023-03-28T10:10:12Z


-var logFile = flags.NewLogFileFlag()
 var logLevel = flags.NewLogLevelFlag()
+var logFile = flags.NewLogFileFlag()


Please revert to keep order consistent.

Done. What do you mean by order consistency here?

pietern · 2023-03-28T10:12:59Z

+ progressLogger.Log(event)
+
+ // log progress events in using the default logger
+ log.Infof(ctx, event.String())


In a follow up this could be done in the progress logger itself.

I intentionally kept it outside incase we would like to log more information than what's being printed on stderr. For example we can decide to print the entire json blob even if the print mode is append just so more information is logged.
However, I think the right call is to simply just print the string even if the progress logger is printing json. We can decide to print more information if it seems useful later. It goes against making the log-file a dumping ground for everything, but I would rather avoid unnecessary clutter in our logs. WDYT?

shreyas-goenka · 2023-03-28T23:41:28Z

If the mode is passed on construction it should never be invalid.

Not necessarily, since "default" is not a valid mode of operation in this function. We resolve the "default" mode to one of "in place" or "append" in an upstream function initializeProgressLogger. This is a hedge against the possibility of Log being called with "default" mode (mostly for us during development)

An alternative is to have a different type without a "default", but IMO is fine and I don't expect this to trigger for customers

shreyas-goenka · 2023-03-28T23:46:20Z

Are you sure? The job details should be available immediately after starting the job.

You are right. I was mistaken about this. Works fine here without the need for any fake events

## Changes The progress logger now only supports `append` (default) and `json` modes. The `json` mode is not used anywhere and is up for removal next. ## Why In-place mode was added in #276 (March 2023) to update job progress on the same line using ANSI escape codes. The intent was to (eventually) show a rich UI with job status and task status but this didn't materialize. It was only ever implemented for job run status events, where the number of states to cycle through is minimal. The feature was effectively disabled after commit 54e16d5 (#2213, Feb 2025) changed the default log level from `disabled` to `warn`. In-place mode required `(log.level == "disabled" OR log.file != "stderr") AND stderr.IsTerminal()`. With the new default, this is only met when `log.file != "stderr"` (uncommon). Additionally, only `JobProgressEvent` supported in-place updates while other events fell back to append mode. Before (when forcing in-place mode): ``` Run URL: ... 2025-10-23 16:45:01 "Test Progress Logger" TERMINATED SUCCESS ``` After: ``` Run URL: ... 2025-10-23 16:46:28 "Test Progress Logger" RUNNING 2025-10-23 16:47:09 "Test Progress Logger" TERMINATED SUCCESS ``` Related: the escape codes that were used are not VT100 compliant and don't work in Ghostty. ## Tests Tests pass. Manually confirmed `bundle run` works as expected.

## Changes The progress logger now only supports `append` mode. ## Why JSON mode was added in #276 (March 2023). The intent was to make progress events machine readable but this didn't materialize (we didn't end up using it in the VS Code extension). This functionality would print events to stderr if the user specified `--progress-format json`, or set the an equivalent environment variable. Because the flag is hidden, and there are no online references to the functionality, I believe it is safe to remove. If users take a dependency on JSON output, it should be enabled via the existing `--output json` flag and be written to stdout. After this change is merged, the remaining functionality can be moved into the core `cmdio` types, and the "progress logger" can be removed. Once there is a single type for all I/O, we have a better shot at improving it. Related change: #3811. ## Tests Tests pass.

## Changes The progress logger now only supports `append` (default) and `json` modes. The `json` mode is not used anywhere and is up for removal next. ## Why In-place mode was added in #276 (March 2023) to update job progress on the same line using ANSI escape codes. The intent was to (eventually) show a rich UI with job status and task status but this didn't materialize. It was only ever implemented for job run status events, where the number of states to cycle through is minimal. The feature was effectively disabled after commit df2e58c (#2213, Feb 2025) changed the default log level from `disabled` to `warn`. In-place mode required `(log.level == "disabled" OR log.file != "stderr") AND stderr.IsTerminal()`. With the new default, this is only met when `log.file != "stderr"` (uncommon). Additionally, only `JobProgressEvent` supported in-place updates while other events fell back to append mode. Before (when forcing in-place mode): ``` Run URL: ... 2025-10-23 16:45:01 "Test Progress Logger" TERMINATED SUCCESS ``` After: ``` Run URL: ... 2025-10-23 16:46:28 "Test Progress Logger" RUNNING 2025-10-23 16:47:09 "Test Progress Logger" TERMINATED SUCCESS ``` Related: the escape codes that were used are not VT100 compliant and don't work in Ghostty. ## Tests Tests pass. Manually confirmed `bundle run` works as expected.

## Changes The progress logger now only supports `append` mode. ## Why JSON mode was added in #276 (March 2023). The intent was to make progress events machine readable but this didn't materialize (we didn't end up using it in the VS Code extension). This functionality would print events to stderr if the user specified `--progress-format json`, or set the an equivalent environment variable. Because the flag is hidden, and there are no online references to the functionality, I believe it is safe to remove. If users take a dependency on JSON output, it should be enabled via the existing `--output json` flag and be written to stdout. After this change is merged, the remaining functionality can be moved into the core `cmdio` types, and the "progress logger" can be removed. Once there is a single type for all I/O, we have a better shot at improving it. Related change: #3811. ## Tests Tests pass.

shreyas-goenka added 3 commits March 24, 2023 03:53

init
0f01db8

first version
83340b3

modularize callbacks
f6c838e

shreyas-goenka changed the title ~~First version for jobs progress logging~~Progress logs for jobsMar 24, 2023

shreyas-goenka changed the title ~~Progress logs for jobs~~Add progress logs for jobsMar 24, 2023

shreyas-goenka changed the title ~~Add progress logs for jobs~~Add progress logs for job runsMar 24, 2023

shreyas-goenka added 3 commits March 24, 2023 15:08

use os.stderr to get fd
3901ede

Added some todos
7f889b9

-
0853630

shreyas-goenka added 4 commits March 24, 2023 16:18

added json tags
985cb2b

Added progress format tests
3eae50b

added string test
63c1617

Added runtime check for log level and log file for inplace
c7f0dc4

log progress events at log-file
0a53ffe

shreyas-goenka requested a review from pietern March 27, 2023 01:44

remove todo
8da4ad1

pietern reviewed Mar 27, 2023
View reviewed changes

Comment threadlibs/flags/progress_format.go Outdated
Comment threadlibs/flags/progress_format_test.go Outdated
Comment threadbundle/run/job.go Outdated
Comment threadbundle/run/job_progress.go Outdated
Comment threadbundle/run/options.go Outdated

shreyas-goenka requested a review from mgyucht March 27, 2023 10:06

shreyas-goenka added 2 commits March 27, 2023 19:31

implemented interface
2de0b67

remove flag
7c24766

shreyas-goenka commented Mar 27, 2023
View reviewed changes

added env var
a622d28

added autocompletE
1d2f984

shreyas-goenka added 4 commits March 27, 2023 20:04

fake test to see actions
268e663

fix failing test
d70f901

change event name
83e2d11

added writer function
03e367b

shreyas-goenka commented Mar 27, 2023
View reviewed changes

Comment threadbundle/run/job.go

remove todo
c50834b

shreyas-goenka requested a review from pietern March 27, 2023 18:42

Added support for first event logging
0c2aaaa

pietern reviewed Mar 28, 2023
View reviewed changes

addressed comments
1969ee5

shreyas-goenka requested a review from pietern March 29, 2023 10:10

pietern approved these changes Mar 29, 2023
View reviewed changes

shreyas-goenka merged commit 8fd3dcc into mainMar 29, 2023

shreyas-goenka deleted the job-progress branch March 29, 2023 12:58

This was referenced Oct 23, 2025
Remove unused in-place progress logging mode #3811
Merged
Remove unused JSON progress logging mode #3812
Merged

denik pushed a commit that referenced this pull request May 20, 2026
Add progress logs for job runs (#276)
cd23bea

Uh oh!

Conversation

shreyas-goenka commented Mar 24, 2023• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

shreyas-goenka commented Mar 24, 2023• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

shreyas-goenka commented Mar 24, 2023

Uh oh!

shreyas-goenka commented Mar 24, 2023• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

shreyas-goenka commented Mar 24, 2023

Uh oh!

shreyas-goenka commented Mar 27, 2023

Uh oh!

shreyas-goenka commented Mar 27, 2023

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

shreyas-goenkaMar 27, 2023

Choose a reason for hiding this comment

Uh oh!

pieternMar 28, 2023

Choose a reason for hiding this comment

Uh oh!

shreyas-goenka commented Mar 27, 2023• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

pieternMar 28, 2023

Choose a reason for hiding this comment

Uh oh!

Uh oh!

pieternMar 28, 2023

Choose a reason for hiding this comment

Uh oh!

shreyas-goenkaMar 28, 2023

Choose a reason for hiding this comment

Uh oh!

Uh oh!

pieternMar 28, 2023

Choose a reason for hiding this comment

Uh oh!

shreyas-goenkaMar 28, 2023

Choose a reason for hiding this comment

Uh oh!

Uh oh!

shreyas-goenka commented Mar 28, 2023

Uh oh!

shreyas-goenka commented Mar 28, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

shreyas-goenka commented Mar 24, 2023•
edited
Loading

shreyas-goenka commented Mar 24, 2023•
edited
Loading

shreyas-goenka commented Mar 24, 2023•
edited
Loading

shreyas-goenka commented Mar 27, 2023•
edited
Loading