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.

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

Weird error messages on 0.14.2 && Snowflake #1807

Closed
clrcrl opened this issue Oct 4, 2019 · 5 comments · Fixed by #1839
Closed

Weird error messages on 0.14.2 && Snowflake #1807

clrcrl opened this issue Oct 4, 2019 · 5 comments · Fixed by #1839
Labels
bug Something isn't working

Comments

@clrcrl
Copy link
Contributor

clrcrl commented Oct 4, 2019

Describe the bug

I keep getting weird error messages when I dbt compile or dbt docs generate. dbt is right -- these objects don't exist, but it isn't handling the errors well.

$ dbt compile
Running with dbt=0.14.2
Found 106 models, 71 tests, 1 snapshot, 0 analyses, 275 macros, 1 operation, 6 seed files, 23 sources

16:17:21 | Concurrency: 8 threads (target='dev')
16:17:21 |
Unhandled error while executing model.fishtown_internal_analytics.stg_dbt_invocation_env_contexts
connection never acquired for thread (52969, 123145499398144), have []
Unhandled error while executing model.fishtown_internal_analytics.stg_snowplow_web_page_contexts
connection never acquired for thread (52969, 123145504653312), have []
Unhandled error while executing model.fishtown_internal_analytics.stg_dbt_invocation_contexts
connection never acquired for thread (52969, 123145473122304), have []
Unhandled error while executing model.fishtown_internal_analytics.stg_dbt_platform_contexts
connection never acquired for thread (52969, 123145467867136), have []
Unhandled error while executing model.fishtown_internal_analytics.stg_dbt_run_model_contexts
connection never acquired for thread (52969, 123145483632640), have []
Unhandled error while executing model.fishtown_internal_analytics.stg_snowplow_events
'AttributeError' object has no attribute 'msg'
Encountered an error:
Runtime Error
  Database Error in model fct_opportunities (models/marts/sales/fct_opportunities.sql)
    002003 (42S02): 018f53e1-03a9-fa7b-0000-0e69039ebcee: SQL compilation error:
    Object 'ANALYTICS.DBT_CLAIRE.STG_CLOSE_CUSTOM_FIELDS' does not exist.

System information

Which database are you using dbt with?

  • snowflake

The output of dbt debug:

Running with dbt=0.14.2
dbt version: 0.14.2
python version: 3.7.4
python path: /usr/local/Cellar/dbt@0.14.2/0.14.2_3/libexec/bin/python3.7
os info: Darwin-18.7.0-x86_64-i386-64bit
Using profiles.yml file at /Users/claire/.dbt/profiles.yml

Configuration:
  profiles.yml file [OK found and valid]
  dbt_project.yml file [OK found and valid]
  profile: garage-snowflake [OK found]
  target: dev [OK found]

Required dependencies:
 - git [OK found]

Additional context

Logs sent via Slack (too long for here)

@clrcrl clrcrl added bug Something isn't working triage labels Oct 4, 2019
@clrcrl
Copy link
Contributor Author

clrcrl commented Oct 4, 2019

When I dbt --single-threaded compile it hits the error more gracefully:

$ ../dbt/env/bin/dbt --single-threaded compile
Running with dbt=0.15.0-a1
Found 106 models, 71 tests, 1 snapshot, 0 analyses, 275 macros, 1 operation, 6 seed files, 23 sources

16:33:48 | Concurrency: 8 threads (target='dev')
16:33:48 |
Encountered an error:
Runtime Error
  Database Error in model fct_opportunities (models/marts/sales/fct_opportunities.sql)
    002003 (42S02): SQL compilation error:
    Object 'ANALYTICS.DBT_CLAIRE.STG_CLOSE_CUSTOM_FIELDS' does not exist.
16:35:06 ~/fishtown/internal-analytics (master *)

Looks like when dbt hits the error with multiple threads, it tries to roll back the transaction that hasn't actually been opened (?).

Also happens on 0.15.0-a1, will send through debug logs on Slack now

@clrcrl
Copy link
Contributor Author

clrcrl commented Oct 4, 2019

So it seems like the steps to reproduce are:

  1. Have a statement that tries to query a relation that doesn't exit
  2. dbt compile with multiple threads

Expected results:

  1. Object does not exist error handled gracefully, like this:
Encountered an error:
Runtime Error
  Database Error in model fct_opportunities (models/marts/sales/fct_opportunities.sql)
    002003 (42S02): SQL compilation error:
    Object 'ANALYTICS.DBT_CLAIRE.STG_CLOSE_CUSTOM_FIELDS' does not exist.
  1. Other open threads are rolled back gracefully.

Actual results:

  1. Other threads are rolled back, even though a connection hasn't yet been acquired for them, causing weird error messages (see above)

@beckjake
Copy link
Contributor

beckjake commented Oct 4, 2019

Ok, so!

  1. In 0.15.x, the AttributeError about .msg is fixed. We could probably squeeze it in to 0.14.3 if we really really wanted to but I don't think that's worthwhile.
  2. This comes to us courtesy of snowflake. I have no darn idea what it means, but we shouldn't see it anymore due to the fix for 1 properly swallowing the exception:
  File "/usr/local/Cellar/dbt@0.14.2/0.14.2_3/libexec/lib/python3.7/site-packages/snowflake/connector/connection.py", line 1102, in _validate_client_session_keep_alive_heartbeat_frequency
    real_max = int(self.rest.master_validity_in_seconds / 4)
AttributeError: 'NoneType' object has no attribute 'master_validity_in_seconds'
  1. From examining the stack trace, I think this stuff RuntimeError: connection never acquired for thread (52969, 123145499398144), have [] is caused by us detecting a failure in thread A, and when the error bubbles up, canceling the open connections in B. The only reasonable fix for this is to have some sort of "I am being canceled" global state value, flip the flag on cancellation, and suppress anything like this when we see that flag is True.

@beckjake
Copy link
Contributor

beckjake commented Oct 7, 2019

Also: I think we should try to fix this for 0.15.0, if we can. It's really terrible output, and the people most likely to hit it are beginners and people who are in the middle of developing new dbt models/macros that do interesting things, and all that cruft really makes it hard to debug.

@drewbanin drewbanin added this to the Louisa May Alcott milestone Oct 7, 2019
@drewbanin drewbanin removed the triage label Oct 7, 2019
@drewbanin
Copy link
Contributor

just added this one to the LMA milestone

beckjake added a commit that referenced this issue Oct 17, 2019
…bad-errors

Handle a number of bad failure-path behaviors (#1807)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants