[CT-3185] Hundreds of: Skipping due to fail_fast #8774
Labels
enhancement
New feature or request
Impact: Orch
paper_cut
A small change that impacts lots of users in their day-to-day
Comments
github-actions
bot
changed the title
graciegoheen
added
enhancement
|
Thanks for opening @nevdelap Oof! Yeah, showing that message 900+ times is not ideal. I was able to reproduce this.
19:53:19 Concurrency: 8 threads (target='dev')
19:53:19
19:53:19 1 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__call_center ........... [RUN]
19:53:19 2 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__catalog_returns ....... [RUN]
19:53:19 3 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__catalog_sales ......... [RUN]
19:53:19 4 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__customer .............. [RUN]
19:53:19 5 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__customer_address ...... [RUN]
19:53:19 6 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__customer_demographics . [RUN]
19:53:19 7 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__date_dim .............. [RUN]
19:53:19 8 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__household_demographics [RUN]
19:53:20 4 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__customer ......... [SUCCESS 1 in 1.40s]
19:53:20 9 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__income_band ........... [RUN]
19:53:21 1 of 81 ERROR creating sql view model DBT_GGOHEEN.stg_tpcds_core__call_center .. [ERROR in 1.57s]
19:53:21 10 of 81 START sql view model DBT_GGOHEEN.stg_tpcds_core__item ................. [RUN]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__item ................... [CANCEL]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__catalog_returns ........ [CANCEL]
19:53:21 6 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__customer_demographics [SUCCESS 1 in 2.42s]
19:53:21 7 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__date_dim ......... [SUCCESS 1 in 2.42s]
19:53:21 5 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__customer_address . [SUCCESS 1 in 2.43s]
19:53:21 3 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__catalog_sales .... [SUCCESS 1 in 2.39s]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__income_band ............ [CANCEL]
19:53:21 8 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__household_demographics [SUCCESS 1 in 2.37s]
19:53:21 2 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__catalog_returns .. [SUCCESS 1 in 2.46s]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__customer_address ....... [CANCEL]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__customer_demographics .. [CANCEL]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__date_dim ............... [CANCEL]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__catalog_sales .......... [CANCEL]
19:53:21 CANCEL query model.mega_corp_big_co_inc.stg_tpcds_core__household_demographics . [CANCEL]
19:53:22 9 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__income_band ...... [SUCCESS 1 in 1.15s]
19:53:22 10 of 81 OK created sql view model DBT_GGOHEEN.stg_tpcds_core__item ............ [SUCCESS 1 in 1.23s]
19:53:22
19:53:22 Database Error in model stg_tpcds_core__call_center (models/staging/tpcds_core/stg_tpcds_core__call_center.sql)
19:53:22 001003 (42000): SQL compilation error:
19:53:22 syntax error line 16 at position 8 unexpected 'cc_call_center_sk'.
19:53:22 syntax error line 17 at position 29 unexpected 'call_center_id'.
19:53:22 syntax error line 18 at position 29 unexpected 'rec_start_date'.
19:53:22 syntax error line 19 at position 27 unexpected 'rec_end_date'.
19:53:22 syntax error line 20 at position 29 unexpected 'closed_date_sk'.
19:53:22 syntax error line 21 at position 27 unexpected 'open_date_sk'.
19:53:22 syntax error line 22 at position 19 unexpected 'name'.
19:53:22 syntax error line 23 at position 20 unexpected 'class'.
19:53:22 syntax error line 24 at position 24 unexpected 'employees'.
19:53:22 syntax error line 25 at position 20 unexpected 'sq_ft'.
19:53:22 syntax error line 26 at position 20 unexpected 'hours'.
19:53:22 syntax error line 27 at position 22 unexpected 'manager'.
19:53:22 syntax error line 28 at position 21 unexpected 'mkt_id'.
19:53:22 syntax error line 29 at position 24 unexpected 'mkt_class'.
19:53:22 syntax error line 30 at position 23 unexpected 'mkt_desc'.
19:53:22 syntax error line 31 at position 29 unexpected 'market_manager'.
19:53:22 syntax error line 32 at position 23 unexpected 'division'.
19:53:22 syntax error line 33 at position 28 unexpected 'division_name'.
19:53:22 syntax error line 34 at position 22 unexpected 'company'.
19:53:22 syntax error line 35 at position 27 unexpected 'company_name'.
19:53:22 syntax error line 36 at position 28 unexpected 'street_number'.
19:53:22 syntax error line 37 at position 26 unexpected 'street_name'.
19:53:22 syntax error line 38 at position 26 unexpected 'street_type'.
19:53:22 syntax error line 39 at position 27 unexpected 'suite_number'.
19:53:22 syntax error line 40 at position 19 unexpected 'city'.
19:53:22 syntax error line 41 at position 21 unexpected 'county'.
19:53:22 syntax error line 42 at position 20 unexpected 'state'.
19:53:22 syntax error line 43 at position 18 unexpected 'zip'.
19:53:22 syntax error line 44 at position 22 unexpected 'country'.
19:53:22 syntax error line 45 at position 25 unexpected 'gmt_offset'.
19:53:22 syntax error line 46 at position 29 unexpected 'tax_percentage'.
19:53:22 syntax error line 52 at position 0 unexpected 'select'.
19:53:22 compiled Code at target/run/mega_corp_big_co_inc/models/staging/tpcds_core/stg_tpcds_core__call_center.sql
19:53:22
19:53:22 Finished running 19 view models, 54 tests, 8 table models in 0 hours 0 minutes and 14.09 seconds (14.09s).
19:53:22
19:53:22 Completed with 80 errors and 0 warnings:
19:53:22
19:53:22 Database Error in model stg_tpcds_core__call_center (models/staging/tpcds_core/stg_tpcds_core__call_center.sql)
19:53:22 001003 (42000): SQL compilation error:
19:53:22 syntax error line 16 at position 8 unexpected 'cc_call_center_sk'.
19:53:22 syntax error line 17 at position 29 unexpected 'call_center_id'.
19:53:22 syntax error line 18 at position 29 unexpected 'rec_start_date'.
19:53:22 syntax error line 19 at position 27 unexpected 'rec_end_date'.
19:53:22 syntax error line 20 at position 29 unexpected 'closed_date_sk'.
19:53:22 syntax error line 21 at position 27 unexpected 'open_date_sk'.
19:53:22 syntax error line 22 at position 19 unexpected 'name'.
19:53:22 syntax error line 23 at position 20 unexpected 'class'.
19:53:22 syntax error line 24 at position 24 unexpected 'employees'.
19:53:22 syntax error line 25 at position 20 unexpected 'sq_ft'.
19:53:22 syntax error line 26 at position 20 unexpected 'hours'.
19:53:22 syntax error line 27 at position 22 unexpected 'manager'.
19:53:22 syntax error line 28 at position 21 unexpected 'mkt_id'.
19:53:22 syntax error line 29 at position 24 unexpected 'mkt_class'.
19:53:22 syntax error line 30 at position 23 unexpected 'mkt_desc'.
19:53:22 syntax error line 31 at position 29 unexpected 'market_manager'.
19:53:22 syntax error line 32 at position 23 unexpected 'division'.
19:53:22 syntax error line 33 at position 28 unexpected 'division_name'.
19:53:22 syntax error line 34 at position 22 unexpected 'company'.
19:53:22 syntax error line 35 at position 27 unexpected 'company_name'.
19:53:22 syntax error line 36 at position 28 unexpected 'street_number'.
19:53:22 syntax error line 37 at position 26 unexpected 'street_name'.
19:53:22 syntax error line 38 at position 26 unexpected 'street_type'.
19:53:22 syntax error line 39 at position 27 unexpected 'suite_number'.
19:53:22 syntax error line 40 at position 19 unexpected 'city'.
19:53:22 syntax error line 41 at position 21 unexpected 'county'.
19:53:22 syntax error line 42 at position 20 unexpected 'state'.
19:53:22 syntax error line 43 at position 18 unexpected 'zip'.
19:53:22 syntax error line 44 at position 22 unexpected 'country'.
19:53:22 syntax error line 45 at position 25 unexpected 'gmt_offset'.
19:53:22 syntax error line 46 at position 29 unexpected 'tax_percentage'.
19:53:22 syntax error line 52 at position 0 unexpected 'select'.
19:53:22 compiled Code at target/run/mega_corp_big_co_inc/models/staging/tpcds_core/stg_tpcds_core__call_center.sql
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Skipping due to fail_fast
19:53:22
19:53:22 Done. PASS=1 WARN=0 ERROR=1 SKIP=79 TOTAL=81
I think either we'd want to:
Since we already show which models are "CANCEL"ed in the logs, I think option 2 would be a better user experience. I'm not sure what the technical implications would be of doing this, but I'll queue this up for our team to take a look at |
graciegoheen
added
paper_cut
dbeatty10
changed the title
|
I suggest having a single message, that specifies the number of models being skipped "Skipping ### models due to fail_fast" |
|
@graciegoheen @dbeatty10 is there any plan to address this? |
|
Honestly, I would be fine with simply moving this message to DEBUG level verbosity. If I've specified fail-fast, the only thing I want to see after the first failure is what failed and why. In the current behaviour, I can't even see the error message because my terminal history is full of "Skipping due to fail_fast", which is pretty ironic. |
scottgigante
added a commit
to scottgigante/dbt-core
that referenced
this issue
Jan 13, 2024
5 tasks
|
Interestingly:
Ideally, we would have the same behavior |
|
This is a lot more annoying since I raised it eight months ago because my projects are bigger and so spew out more useless skipping messages. Even just not outputting the blanks between the skipping messages would be an improvement of sorts. When I specify This 3500 lines might be annoying in an issue comment... (like it is annoying in the terminal) |
|
@nevdelap I have a PR that would fix this, but since I wrote it in January I now have less time to work on it, so haven't had a chance to respond to the review it finally got in April. If you have a chance, would you be able to send me a PR to resolve the comments on #9371 ? Then I think we'll be able to finally fix this. |
|
Ah, sweet. I've pulled it out and it looks good and sorting the merge conflict is straight forward. I'll have to set up to reproduce and have a look at the contributing guidelines and where to add the tests. Thanks @scottgigante. |
|
I've got a draft PR up #10244 which has your fix @scottgigante merged into the latest origin/main, I've tested it locally. Now I'm ready to look at filling in the remaining bits as suggested by @QMalcolm. |
|
Thank you @scottgigante for the original work here, thank you @nevdelap for continuing it. I'm available for questions or to pair. I've already commented on #10244, but for people following along here, we really want to get this across the line (and soon). @nevdelap I'm happy to answer questions and/or pair. Also let me know if you don't have much time to work on this, I'm happy to get it across the line myself in the next few days 🙂 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Is this a new bug in dbt-core?
I searched open and closed issues for "Skipping due to fail_fast".
Current Behavior
I can get as many as hundreds of these. 900 in the run I've just done, because something near the beginning of the dag failed - because I'm setting up clones of databases with different permissions to test something.
This wasn't always the case, I feel like it started fairly recently. Weeks ago, not months ago. We moved from 1.5.2 to 1.6.1 on the 13th of September. I checked the behaviour is the same in 1.6.1 and 1.6.5.
Expected Behavior
Since it is not saying what it is skipping, and all of those are the same, it should just say something once. Not sure what. Maybe "Skipping ### models due to fail_fast", ### being the number of models skipped.
Steps To Reproduce
dbt run --fail-fastRelevant log output
No response
Environment
Which database adapter are you using with dbt?
snowflake
Additional Context
No response
The text was updated successfully, but these errors were encountered: