[CT-2179] [Bug] Failing on-run-start does not stop dbt run

[fradeleo]

Is this a new bug in dbt-core?

• I believe this is a new bug in dbt-core
• I have searched the existing issues, and I could not find an existing issue for this bug

Current Behavior

Hi,

I recently upgraded to dbt core 1.4.3 (from 1.3.0) and dbt bigquery 1.4.1 and I've started noticing that failing on-run-start checks do not stop dbt from running models. Everything was working as expected before the upgrade.

Macro and logs attached below.

Expected Behavior

This setup worked before (dbt 1.3.0). If a single row was returned by the query in the on-run-start check, an error would be raised and dbt run would not start at all.

Steps To Reproduce

In macros folder, create an export_table_check.sql file with the following content (change table name and column name based on your own table in bigq).

{% macro export_table_check() %}

    {% set table = '12_exported_records' %}

    {% set query %}
        SELECT column_name
        FROM {{ref(table)}}
        LIMIT 1
    {% endset %}

    {%- if flags.WHICH in ('run', 'build') -%}
        {% set results = run_query(query) %}
        {% if execute %}
            {%- if results.rows -%}
                {{ exceptions.raise_compiler_error("ON_RUN_START_CHECK_NOT_PASSED: Data already exported. DBT Run aborted.") }}
            {% else -%}
                {{ log("No data found in " ~ table ~ " for current day and runtime region. Proceeding...", true) }}
            {%- endif -%}
        {%- endif -%}
    {%- endif -%}
{% endmacro %}

In dbt_project:

on-run-start: 
- "{{ export_table_check() }}"

Relevant log output

dbt run --models core                    
13:11:35  Running with dbt=1.4.3
13:11:35  Found 34 models, 89 tests, 0 snapshots, 0 analyses, 352 macros, 2 operations, 2 seed files, 32 sources, 0 exposures, 0 metrics
13:11:35  
13:11:37  
13:11:37  Running 2 on-run-start hooks
13:11:38  Database error while running on-run-start
13:11:38  Concurrency: 8 threads (target='dev')
13:11:38  
13:11:38  1 of 6 START sql table model prioritization.customers .......................... [RUN]
13:11:38  2 of 6 START sql table model prioritization.program_specification_exploded ..... [RUN]
13:11:43  2 of 6 OK created sql table model prioritization.program_specification_exploded  [CREATE TABLE (4.9k rows, 64.8 KB processed) in 4.20s]
13:11:43  3 of 6 START sql incremental model prioritization.history ...................... [RUN]
13:12:05  3 of 6 OK created sql incremental model prioritization.history ................. [SCRIPT (23.4 GB processed) in 22.36s]
13:12:10  1 of 6 OK created sql table model prioritization.customers ..................... [CREATE TABLE (39.0m rows, 123.4 GB processed) in 31.93s]
13:12:10  4 of 6 START sql table model prioritization.pre_checks ......................... [RUN]
13:12:53  4 of 6 OK created sql table model prioritization.pre_checks .................... [CREATE TABLE (4.7m rows, 67.5 GB processed) in 43.08s]
13:12:53  5 of 6 START sql table model prioritization.all_checks ......................... [RUN]
13:13:43  5 of 6 OK created sql table model prioritization.all_checks .................... [CREATE TABLE (4.7m rows, 20.6 GB processed) in 49.71s]
13:13:43  6 of 6 START sql table model prioritization.final_target ....................... [RUN]
13:13:47  Running in dry run mode, will skip exporting file
13:13:47  6 of 6 OK created sql table model prioritization.final_target .................. [CREATE TABLE (338.4k rows, 493.0 MB processed) in 3.65s]
13:13:47  
13:13:47  Finished running 5 table models, 1 incremental model in 0 hours 2 minutes and 11.73 seconds (131.73s).
13:13:47  
13:13:47  Completed with 1 error and 0 warnings:
13:13:47  
13:13:47  on-run-start failed, error:
13:13:47   ON_RUN_START_CHECK_NOT_PASSED: Data already exported. DBT Run aborted.

Environment

- OS: Ubuntu 20.04 LTS
- Python: 3.9.0
- dbt: 1.4.3

Which database adapter are you using with dbt?

bigquery

Additional Context

No response

[jtcohen6]

@fradeleo You're right. I'm not sure which change we made in v1.4 would be responsible for this change, but I can confirm that it changed from v1.3 to v1.4:

# dbt_project.yml
on-run-start:
  - "select error"

-- models/my_model.sql
select 1 as id

Using v1.4.3, dbt keeps going:

$ dbt run
13:43:58  Running with dbt=1.4.3
13:43:58  Unable to do partial parsing because of a version mismatch
13:43:59  Found 1 model, 0 tests, 0 snapshots, 0 analyses, 290 macros, 1 operation, 1 seed file, 0 sources, 0 exposures, 0 metrics
13:43:59
13:43:59
13:43:59  Running 1 on-run-start hook
13:43:59  1 of 1 START hook: test.on-run-start.0 ......................................... [RUN]
13:43:59  Database error while running on-run-start
13:43:59  Concurrency: 5 threads (target='dev')
13:43:59
13:43:59  1 of 1 START sql view model dbt_jcohen.my_good_model ........................... [RUN]
13:43:59  1 of 1 OK created sql view model dbt_jcohen.my_good_model ...................... [CREATE VIEW in 0.11s]
13:43:59
13:43:59  Finished running 1 view model in 0 hours 0 minutes and 0.29 seconds (0.29s).
13:43:59
13:43:59  Completed with 1 error and 0 warnings:
13:43:59
13:43:59  on-run-start failed, error:
13:43:59   column "error" does not exist
13:43:59  LINE 2: select error
13:43:59                 ^
13:43:59
13:43:59  Done. PASS=1 WARN=0 ERROR=1 SKIP=0 TOTAL=2

Whereas, with v1.3.2, it stops after the initial hook error:

$ dbt run
13:44:20  Running with dbt=1.3.2
13:44:20  Found 1 model, 0 tests, 0 snapshots, 0 analyses, 290 macros, 1 operation, 1 seed file, 0 sources, 0 exposures, 0 metrics
13:44:20
13:44:21
13:44:21  Running 1 on-run-start hook
13:44:21  1 of 1 START hook: test.on-run-start.0 ......................................... [RUN]
13:44:21  Database error while running on-run-start
13:44:21  Encountered an error:
Database Error
  column "error" does not exist
  LINE 2: select error
                 ^

If I had to guess, we may no longer be checking for a specific type of exception after running hooks...?

[jtcohen6]

Ah, it looks like this was due to an intentional change that we made:

• [CT-1003] run_results.json not generated when on-run-end fails #5625
• properly track hook running #6059

This way, a failing on-run-end hook doesn't preempt dbt from writing run_results.json.

We don't explicitly document here that on-run-start hooks can be used as a "verification check" to skip the rest of execution, but it does feel like a reasonable & intuitive use of them. Let's see if we can manage to have it both ways:

• Write results if an on-run-end hook fails
• Skip running any selected nodes if an on-run-start hook fails

[jtcohen6]

Naive solution: Add a conditional here to raise or node_results.append depending on whether hook_type is RunHookType.Start or RunHookType.End. Or, add an explicit argument to safe_run_hooks, e.g. should_raise.

In either case, we'd be introducing a genuine divergence between the behavior of on-run-start and on-run-end hooks. It might be the right thing to do, and we should clearly document it if so.

[jtcohen6]

From chatting with @dbeatty10 @MichelleArk @emmyoop

What feels bad:

• Genuinely different behavior for each individual hook, based on whether it's on-run-start versus on-run-end

What feels better to me:

• Treating hooks as participants in the DAG. Hooks are meaningfully ordered (linked lists). A failure in one hook should prevent the subsequent hooks from running. A failure in ANY on-run-start hook should prevent the selected DAG nodes from running.

on-run-start-1 --> on-run-start-2 --> [selection from DAG] --> on-run-end-1 --> on-run-end-2

@fradeleo I think that would account for your use case — curious to hear if that makes sense to you conceptually?

[fradeleo]

From chatting with @dbeatty10 @MichelleArk @emmyoop

What feels bad:

• Genuinely different behavior for each individual hook, based on whether it's on-run-start versus on-run-end

What feels better to me:

• Treating hooks as participants in the DAG. Hooks are meaningfully ordered (linked lists). A failure in one hook should prevent the subsequent hooks from running. A failure in ANY on-run-start hook should prevent the selected DAG nodes from running.

on-run-start-1 --> on-run-start-2 --> [selection from DAG] --> on-run-end-1 --> on-run-end-2

@fradeleo I think that would account for your use case — curious to hear if that makes sense to you conceptually?

@jtcohen6 it would and it does make a lot of sense to me :)

[jtcohen6]

Doing this "right" will be a larger lift than just a simple fix for a simple regression, so I've opened it up as a new feature request:

• [CT-2427] [Feature] [Investigate] Gracefully handle failures in on-run-* hooks, and skip subsequent hooks/nodes #7387

In the meantime, there are workarounds to achieve this sort of behavior in a multi-step dbt deployment.