invocation_id not the same through the whole dbt run.

[FebbyK]

Describe the bug

Running: dbt run --m tag:x

48models are run, with a pre-hook and post hook which logs the start and end of each model, and a on-run-start and on-run-end hook which logs the start and end of the run.

After about 35models are run, the error message: Error sending message, disabling tracking is displayed, but the run keeps on going.

After the run dbt has inserted all model starts, ends and the start of the run with the same Invocation_id, but the on-run-end hook insert, which tells that the run was completed has a different invocation_id.

This only happens if I run a dbt which loads many models, not if I run dbt run --m speficic model.

This does happen when I run dbt locally, but not if I run the same dbt project from our server we use to schedule dbt runs.

Steps To Reproduce

In as much detail as possible, please provide steps to reproduce the issue. Sample data that triggers the issue, example model code, etc is all very helpful here.

-- Dont know

Expected behavior

A clear and concise description of what you expected to happen.

The run to have the same invocation_id

Screenshots and log output

20:54:46 | Running 4 on-run-start hooks
20:54:46 | 1 of 4 START hook: dbt_edw.on-run-start.0............................ [RUN]
20:54:46 | 1 of 4 OK hook: dbt_edw.on-run-start.0............................... [SUCCESS 1 in 0.26s]
20:54:46 | 2 of 4 START hook: dbt_edw.on-run-start.1............................ [RUN]
20:54:46 | 2 of 4 OK hook: dbt_edw.on-run-start.1............................... [SUCCESS 1 in 0.29s]
20:54:46 | 3 of 4 START hook: dbt_edw.on-run-start.2............................ [RUN]
20:54:47 | 3 of 4 OK hook: dbt_edw.on-run-start.2............................... [SUCCESS 1 in 0.30s]
20:54:47 | 4 of 4 START hook: dbt_edw.on-run-start.3............................ [RUN]
20:54:48 | 4 of 4 OK hook: dbt_edw.on-run-start.3............................... [SUCCESS 1 in 1.23s]

20:55:19 | 30 of 48 OK created table model ...... [SUCCESS 1 in 16.19s]
20:55:21 | 2 of 48 OK created table model ...... [SUCCESS 1 in 33.55s]
20:55:22 | 31 of 48 OK created table model ...... [SUCCESS 1 in 17.75s]
20:55:22 | 11 of 48 OK created table model ...... [SUCCESS 1 in 34.22s]
20:55:22 | 8 of 48 OK created table model ...... [SUCCESS 1 in 34.44s]
Error sending message, disabling tracking
20:55:23 | 3 of 48 OK created table model ...... [SUCCESS 1 in 35.18s]
20:55:23 | 34 of 48 OK created table model ...... [SUCCESS 1 in 16.67s]
20:55:24 | 44 of 48 OK created table model ...... [SUCCESS 1 in 8.51s]
20:55:25 | 4 of 48 OK created table model ...... [SUCCESS 1 in 36.99s]

21:00:31 | Running 2 on-run-end hooks
21:00:31 | 1 of 2 START hook: dbt_edw.on-run-end.0.............................. [RUN]
21:00:34 | 1 of 2 OK hook: dbt_edw.on-run-end.0................................. [SUCCESS 1 in 2.89s]
21:00:34 | 2 of 2 START hook: dbt_edw.on-run-end.1.............................. [RUN]
21:00:37 | 2 of 2 OK hook: dbt_edw.on-run-end.1................................. [SUCCESS 1 in 3.11s]

System information

Which database are you using dbt with?

• snowflake

The output of dbt --version:

0.16.0

The operating system you're using:
Windows 10

The output of python --version:
3.8.2

Additional context

Add any other context about the problem here.

[drewbanin]

Thanks for the report @FebbyK - this is definitely a bug, and we'll get it fixed in the next release of dbt!