Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[CT-2049] Fire an event at the end of every command #6878

Closed
Tracked by #7162
, #6356
...
jtcohen6 opened this issue Feb 6, 2023 · 4 comments · Fixed by #7180
Closed
Tracked by #7162
, #6356
...

[CT-2049] Fire an event at the end of every command #6878

jtcohen6 opened this issue Feb 6, 2023 · 4 comments · Fixed by #7180
Assignees
@QMalcolm
Labels
logging python_api Issues related to dbtRunner Python entry point

Comments

@jtcohen6
Copy link
Contributor

jtcohen6 commented Feb 6, 2023

On the feature/click-cli branch, each command explicitly returns a tuple of success: bool, results: Any. (The structure of results differs based on the command.)

We should additionally fire an event that can be used programmatically to determine:

  • when the command completed
  • if the command succeeded

Ideally, this event would be fired always, even in cases where the command was interrupted (^C) or cancelled itself (e.g. --fail-fast).
@jtcohen6 jtcohen6 added python_api Issues related to dbtRunner Python entry point Team:Execution logging labels Feb 6, 2023
@github-actions github-actions bot changed the title Fire an event at the end of every command [CT-2049] Fire an event at the end of every command Feb 6, 2023
@gshank
Copy link
Contributor

gshank commented Feb 6, 2023

Super agree with this. I suggest that we might want to have a CommandCompleted event that contains the data common to all commands, such as timing and success, and refer to an additional event that would contain more of the specific Result dump. We could do a "oneof" of all of the various Result objects, but the way they work in python protobufs is kind of kludgey and slow. We could even include the name of the Result event in the CommandCompleted event, if that would help.

@jtcohen6
Copy link
Contributor Author

jtcohen6 commented Feb 10, 2023 •
edited
Loading

Discussed during BLG: This event shouldn't include the full result that would be returned from the command if invoked programmatically, à la:

results, success = dbt.invoke(['<command>'])

Rationale:

  • those results can be different types (depending on the command), as Gerda mentioned above
  • node-level results are already fired as events as soon as the node is finished
  • we should already have events that "summarize" a graph-running command (how many nodes, how many succeeded, etc)

This event's data only needs to include:

  • which command
  • whether it succeeded (boolean)
  • timestamp when it finished
  • how long it took

(Plus standard metadata of course - invocation_id etc - which should already be present in the event's info dict, no specific plumbing needed)

@jtcohen6 jtcohen6 mentioned this issue Feb 13, 2023
Closed
23 tasks
@emmyoop
Copy link
Member

emmyoop commented Feb 13, 2023 •
edited
Loading

Will need to connect with the Execution Team for where we should fire this event. Possibly here?

@iknox-fa
Copy link
Contributor

Per BLG -- 2/13/23 we'd probably want to do this in the preflight decorator as a generator. If the language team picks this ticket up feel free to ask for a pair from the Execution team, we'd be happy to show how/where that lives.

@jtcohen6 jtcohen6 mentioned this issue Mar 13, 2023
Closed
@leahwicz leahwicz assigned leahwicz and QMalcolm and unassigned leahwicz Mar 15, 2023
QMalcolm added a commit that referenced this issue Mar 16, 2023
@QMalcolm
add protobuf message/class for new CommandCompleted event
f79b13b 
For [CT-2049](#6878) we
concluded that we wanted a new event type, [CommandCompleted](#6878 (comment))
with [four (4) values](#6878 (comment)):
which command was run, whether the command succeeded, the timestamp
that the command finished, and how long the command took. This commit
adds the new event proto defition, the auto generated proto_types, and
the instantiatable even type.
QMalcolm added a commit that referenced this issue Mar 16, 2023
@QMalcolm
begin emitting CommandCompleted event in the preflight decorator
86b2f84 
The [preflight decorator](https://github.com/dbt-labs/dbt-core/blob/4186f99b742b47e0e95aca4f604cc09e5c67a449/core/dbt/cli/requires.py#L19)
runs at the start of every CLI invocation. Thus is a perfect candidate
for emitting the CommandCompleted event. This is noted in the [dicussion
on CT-2049](#6878 (comment)).
@QMalcolm QMalcolm mentioned this issue Mar 16, 2023
Merged
6 tasks
QMalcolm added a commit that referenced this issue Mar 16, 2023
@QMalcolm
add protobuf message/class for new CommandCompleted event
ae93100 
For [CT-2049](#6878) we
concluded that we wanted a new event type, [CommandCompleted](#6878 (comment))
with [four (4) values](#6878 (comment)):
which command was run, whether the command succeeded, the timestamp
that the command finished, and how long the command took. This commit
adds the new event proto defition, the auto generated proto_types, and
the instantiatable even type.
QMalcolm added a commit that referenced this issue Mar 16, 2023
@QMalcolm
begin emitting CommandCompleted event in the preflight decorator
7303278 
The [preflight decorator](https://github.com/dbt-labs/dbt-core/blob/4186f99b742b47e0e95aca4f604cc09e5c67a449/core/dbt/cli/requires.py#L19)
runs at the start of every CLI invocation. Thus is a perfect candidate
for emitting the CommandCompleted event. This is noted in the [dicussion
on CT-2049](#6878 (comment)).
QMalcolm added a commit that referenced this issue Mar 22, 2023
@QMalcolm
CT-2049: Add CommandCompleted event (#7180)
9a7305d 
* add protobuf message/class for new CommandCompleted event

For [CT-2049](#6878) we
concluded that we wanted a new event type, [CommandCompleted](#6878 (comment))
with [four (4) values](#6878 (comment)):
which command was run, whether the command succeeded, the timestamp
that the command finished, and how long the command took. This commit
adds the new event proto defition, the auto generated proto_types, and
the instantiatable even type.

* begin emitting CommandCompleted event in the preflight decorator

The [preflight decorator](https://github.com/dbt-labs/dbt-core/blob/4186f99b742b47e0e95aca4f604cc09e5c67a449/core/dbt/cli/requires.py#L19)
runs at the start of every CLI invocation. Thus is a perfect candidate
for emitting the CommandCompleted event. This is noted in the [dicussion
on CT-2049](#6878 (comment)).

* add CommandCompleted event to event unit tests

* Add: changelog entry

* fire CommandCompleted event reguardless of upstream exceptions

Previously, if `--fail-fast` was specified and an issue was run into
or an unhandled issue became an exception, the CommandCompleted event
would not get fired because at this point in the stack we'd be in
exception thrown handling mode. If an exception does reach this point,
we want to still fire the event and also continue to propogate the
exception. Hence the bare `raise` exists to reraise the caught exception

* Update CommandCompleted event to be a `Debug` level event

We don't actually "always" need this event to be logged. Thus we've
updated it to `Debug` level. [Discussion Context](#7180 (comment))
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@QMalcolm QMalcolm

Labels
logging python_api Issues related to dbtRunner Python entry point
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

CT-2049: Add CommandCompleted event dbt-labs/dbt-core
6 participants
@gshank @emmyoop @QMalcolm @jtcohen6 @leahwicz @iknox-fa