v0.19.1 test severity='warn' ignored

[SteveDMurphy]

Describe the bug

A failing test with the severity set to warn in the config block is treated as an error. Additionally the same model selection syntax in v0.19.1 is missing a test that is executed in v0.19.0

Steps To Reproduce

While validating there would be no issues with bumping from 0.19.0 to 0.19.1 this issue surfaced where a test with severity set to warn will instead return a hard failure.

Expected behavior

Warning in test... is expected instead of Failure in test...

Screenshots and log output

v0.19.0

Running with dbt=0.19.0
Found 330 models, 2503 tests, 196 snapshots, 0 analyses, 419 macros, 0 operations, 0 seed files, 221 sources, 0 exposures

17:56:05 | Concurrency: 4 threads (target='dev')
17:56:05 | 
17:56:05 | 1 of 3 START test duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [RUN]
17:56:05 | 2 of 3 START test logins_without_orgs_factUserLogins_UserLoginUserKey [RUN]
17:56:05 | 3 of 3 START test snapshot_changed_LogUserLoginsSnapshot_............ [RUN]
17:56:07 | 1 of 3 WARN 108811 duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [WARN 108811 in 2.26s]
17:56:07 | 3 of 3 ERROR snapshot_changed_LogUserLoginsSnapshot_................. [ERROR in 2.40s]
17:57:15 | 2 of 3 PASS logins_without_orgs_factUserLogins_UserLoginUserKey...... [PASS in 70.08s]
17:57:15 | 
17:57:15 | Finished running 3 tests in 79.87s.

v0.19.1

Running with dbt=0.19.1
Found 330 models, 2503 tests, 196 snapshots, 0 analyses, 419 macros, 0 operations, 0 seed files, 221 sources, 0 exposures

18:04:58 | Concurrency: 4 threads (target='dev')
18:04:58 | 
18:04:58 | 1 of 2 START test duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [RUN]
18:04:58 | 2 of 2 START test snapshot_changed_LogUserLoginsSnapshot_............ [RUN]
18:05:00 | 2 of 2 ERROR snapshot_changed_LogUserLoginsSnapshot_................. [ERROR in 1.92s]
18:05:00 | 1 of 2 WARN 108811 duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [WARN 108811 in 1.98s]
18:05:00 | 
18:05:00 | Finished running 2 tests in 7.41s.

System information

Which database are you using dbt with?

• postgres
• redshift
• bigquery
• snowflake
• other (specify: ____________)

The output of dbt --version:

Running with dbt=0.19.0

Running with dbt=0.19.1

The operating system you're using: OSX / dbt via Docker (3.8-slim)

The output of python --version: Python 3.8.7

Additional context

Other testing seemed to show that the severity being set to warn in the yml is not respected on out of the box tests as well

[jtcohen6]

Thanks for the quick report @SteveDMurphy! If possible, could you share:

• Whether these are data tests or custom schema tests
• How you're configuring severity for these tests
• The selection criteria you're using to select the tests above (since you're only running 2-3 out of 2503 tests in your project)

From looking at the log output you've shared above, it seems like:

• duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId is returning WARN 108811 in both
• snapshot_changed_LogUserLoginsSnapshot_ is returning ERROR in both
• logins_without_orgs_factUserLogins_UserLoginUserKey is selected and returns PASS in v0.19.0, but it is not selected in v0.19.1

So I can't tell if this is an issue with severity, or with test selection.

Other testing seemed to show that the severity being set to warn in the yml is not respected on out of the box tests as well

Could you say a bit more about this, too, or share an example?

[SteveDMurphy]

Thanks for the quick response @jtcohen6 !

• These are custom schema tests
• Set in the config block of the custom schema test
• dbt test -m LogUserLoginsSnapshot

🤦 I was moving too fast before having to split for a bit, my apologies! I'll repost the logs below:

Running with dbt=0.19.0
Found 330 models, 2503 tests, 196 snapshots, 0 analyses, 419 macros, 0 operations, 0 seed files, 221 sources, 0 exposures

00:23:15 | Concurrency: 4 threads (target='dev')
00:23:15 | 
00:23:15 | 1 of 3 START test duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [RUN]
00:23:15 | 2 of 3 START test logins_without_orgs_factUserLogins_UserLoginUserKey [RUN]
00:23:15 | 3 of 3 START test snapshot_changed_LogUserLoginsSnapshot_............ [RUN]
00:23:18 | 3 of 3 PASS snapshot_changed_LogUserLoginsSnapshot_.................. [PASS in 2.34s]
00:25:00 | 2 of 3 PASS logins_without_orgs_factUserLogins_UserLoginUserKey...... [PASS in 104.29s]
00:25:54 | 1 of 3 WARN 108811 duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [WARN 108811 in 159.03s]
00:25:54 | 
00:25:54 | Finished running 3 tests in 168.42s.

Running with dbt=0.19.1
Found 330 models, 2503 tests, 196 snapshots, 0 analyses, 419 macros, 0 operations, 0 seed files, 221 sources, 0 exposures

00:09:51 | Concurrency: 4 threads (target='dev')
00:09:51 | 
00:09:51 | 1 of 2 START test duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [RUN]
00:09:51 | 2 of 2 START test snapshot_changed_LogUserLoginsSnapshot_............ [RUN]
00:09:58 | 2 of 2 PASS snapshot_changed_LogUserLoginsSnapshot_.................. [PASS in 6.50s]
00:13:22 | 1 of 2 FAIL 108811 duplicate_snapshot_rows_LogUserLoginsSnapshot_LogId [FAIL 108811 in 210.69s]
00:13:22 | 
00:13:22 | Finished running 2 tests in 216.80s.

Also here is the test in question that Warns on 0.19.0 and Errors on 0.19.1:

{% macro test_duplicate_snapshot_rows(model, unique_key='UniqueKey') %}
  {{
      config(
          severity='warn'
      )
  }}
    with duplicate_active_recs as (
        select {{ unique_key }}
        from {{model}}
        where dbt_valid_to is null
        group by {{ unique_key }}
        having count(*) > 1
    )
    select count(*) from duplicate_active_recs

{% endmacro %}

For the third bullet, that was something random I noticed just based on the snapshot I chose to test with today. It is a data test (if that makes a difference) but thought it might be worth mentioning.

In regard to:

Other testing seemed to show that the severity being set to warn in the yml is not respected on out of the box tests as well

I also tested a separate model that I knew to have a failing relationship but was set to warn and mistakenly thought it was a relationship test with the severity set in the schema.yml, however it's also a custom data test set in the config block. It also correctly returns the warn on 0.19.0 but an error on 0.19.1.

Based on my mistake, I went back and specified the severity in the schema.yml like the below for LogUserLoginsSnapshot and it correctly returned the warn instead of the error as shown above:

 - name: LogUserLoginsSnapshot
    tests:
      - duplicate_snapshot_rows:
          unique_key: LogId
          severity: warn # adding this here correctly fires the warn instead of error
      - snapshot_changed

Thanks again for the help! Let me know if I can add anything else. Pumped to unleash the new power of 0.19.1, huge increase in dev quality of life on those compile times 🙌

[jtcohen6]

@SteveDMurphy Thanks for the detailed report back, this is hugely helpful!

Regression

There's a regression from v0.19.0 to v0.19.1 around setting "default" severity within a custom schema test macro. I don't actually think we've documented that this is possible—rather, we document [config() for setting data test severity](https://docs.getdbt.com/reference/data-test-configs—but it's a reasonable thing to want to do, and it makes sense that it previously worked.

We'll investigate this to see if there's an obvious way we can switch back to the previous behavior. In any case, we're planning lots of (good) changes for custom tests in v0.20.0. The ability to configure "default" severity within a generic test wasn't previously on my mind, but it definitely feels possible with the new constructs we're developing, so thanks for raising!

In the meantime, as you say, the right approach is to configure severity within the .yml test definition:

tests
  - duplicate_snapshot_rows:
      severity: warn

Question

I'm still not sure why your first (v0.19.0) invocation includes three tests and your second (v0.19.1) only includes two. The missing test is logins_without_orgs_factUserLogins_UserLoginUserKey; given that your selection logic is -m LogUserLoginsSnapshot, by that test's name/unique_id, it's not clear why it should have been included, since it doesn't seem to depend on LogUserLoginsSnapshot. (If I had to guess, it looks like a custom test, logins_without_orgs, defined on the column UserLoginUserKey of the model factUserLogins.) Do you have a sense of why that would have been included in the first test invocation?

[SteveDMurphy]

Thanks for the detailed explanation @jtcohen6 ! That all makes sense to me, I think we can go ahead and update severity in the .yml to manage that properly for now - it would definitely be nice to have in the future to keep it DRY for those situations but I understand if it's an edge case 👍

For the missing invocation of logins_without_orgs_factUserLogins_UserLoginUserKey - this is a custom data (regression) test used to validate that we were correct in applying a default/unknown surrogate key. The test is applied to the model in the schema.yml as well, but consists of joining/validating to a few models as well as the snapshot. Based on what you mentioned earlier, it might be related to how or where we apply things in the models? If I remember correctly, when we got started (on v0.14.0) we either needed or assumed we needed to apply custom tests in the .yml as well - so there might be a common theme behind what we are seeing?

Thanks again!

[jtcohen6]

Appreciate your understanding + flexibility!

Just to clarify: Is logins_without_orgs_factUserLogins_UserLoginUserKey a custom "schema" test, defined in macros/ + models/*.yml, or custom "data" test, defined (as a query / SQL file) in test/?

What's the relationship between logins_without_orgs_factUserLogins_UserLoginUserKey and LogUserLoginsSnapshot?

[SteveDMurphy]

custom schema test, my bad on the terminology! 😅 we have moved solely towards that setup (defined in macros/ + models/*.yml)

LogUserLoginsSnapshot is ref'd directly in a cte as part of the test (along with another snapshot and a few models) but the test is only defined underneath the fact model in the .yml. I'm not sure if that's exactly what you were looking for but let me know if you were looking for something different

[jtcohen6]

No worries on the terminology—I know it's confusing and, in fact, would like to change it in v0.20.0 to be a bit more intuitive :)

Got it, ok. That sounds like it's a very similar issue to the one over in #3229 (I'm actually surprised you didn't run into that same compilation error), and closely related to parsing config/severity out of the test definition.

Really appreciate the clarification, thank you!

[jtcohen6]

Resolved by #3272

@SteveDMurphy Thanks again for your help getting to the bottom of this one!

[jtcohen6]

@SteveDMurphy We're including a fix for this in v0.19.2, for which we just cut a release candidate. Any chance you could test locally and confirm that it fixes the issue you described above?

pip install dbt==0.19.2rc1
# or
brew install dbt@0.19.2-rc1