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.

Sign up for GitHub

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

Jump to bottom

[CT-232] Setting enabled to False in schema config does not move model to disabled #3992

Closed
gshank opened this issue Oct 2, 2021 · 5 comments · Fixed by #5868
Closed

[CT-232] Setting enabled to False in schema config does not move model to disabled #3992

gshank opened this issue Oct 2, 2021 · 5 comments · Fixed by #5868
Assignees
@emmyoop
Labels
bug Something isn't working jira
Milestone
v1.3

Comments

@gshank
Copy link
Contributor

gshank commented Oct 2, 2021

In the model node, NodeConfig.enabled equals False, but because the node isn't moved into the disabled dictionary, it doesn't have the correct error messages. Instead of the node is disabled messages, nodes referring to the disabled node cause an error "Model ... depends on a node named ... which was not found".
@gshank
Copy link
Contributor Author

gshank commented Oct 3, 2021

In addition, I don't think we ever remove models from 'disabled', which didn't matter that much without partial parsing, but probably should be fixed.

And a model that starts out 'disabled' can now be subsequently enabled via patch config, so we need to apply patches to disabled nodes and put them in the right place.

I'm actually wondering why we have a separate place for 'disabled' models and if it's necessary. It would be simpler to just change the config in the nodes and leave them where they are, skipping them for some purposes. I suspect some of that at least is already in place or the errors in this would be showing up.

@jtcohen6
Copy link
Contributor

jtcohen6 commented Oct 4, 2021

Leaving them in nodes with enabled: False makes intuitive sense, if we're not doing the right things in the disabled dict. It would be a significant (likely breaking) change for people who depend on project metadata, both via manifest.json and via the graph.nodes context variable. We'd need to tell them to start filtering on enabled. I don't think that's an unreasonable change.

@jeremyyeo
Copy link
Contributor

jeremyyeo commented Jan 10, 2022 •
edited
Loading

Hey team, looks like the following scenario is related (dbt-core 1.0.1, dbt-snowflake 1.0.0).

A barebones project with 3 models:

-- my_model.sql
select 1 as user

-- my_model_2.sql
select * from {{ ref('my_model') }}

-- my_model_3.sql
select * from {{ ref('my_model_2') }}

A schema.yml like so:

version: 2
models:
  - name: my_model
  - name: my_model_2
    config:
      enabled: false
  - name: my_model_3
    config:
      enabled: false

And a command like dbt clean && dbt run results in an error:

08:52:29  Running with dbt=1.0.1
08:52:29  Partial parse save file not found. Starting full parse.
08:52:31  Encountered an error:
Compilation Error in model my_model_3 (models/my_model_3.sql)
  Model 'model.snowflake.my_model_3' (models/my_model_3.sql) depends on a node named 'my_model_2' which was not found
dbt --debug run output 
============================== 2022-01-10 08:46:35.985690 | c4027fbc-f97c-417b-8cf0-e16731f8ddb8 ==============================
08:46:35.985690 [info ] [MainThread]: Running with dbt=1.0.1
08:46:35.986544 [debug] [MainThread]: running dbt with arguments Namespace(record_timing_info=None, debug=True, log_format=None, write_json=None, use_colors=None, printer_width=None, warn_error=None, version_check=None, partial_parse=None, single_threaded=False, use_experimental_parser=None, static_parser=None, profiles_dir='/Users/jeremy/.dbt', send_anonymous_usage_stats=None, fail_fast=None, event_buffer_size=None, project_dir=None, profile=None, target=None, vars='{}', log_cache_events=False, threads=None, select=None, exclude=None, selector_name=None, state=None, defer=None, full_refresh=False, cls=<class 'dbt.task.run.RunTask'>, which='run', rpc_method='run')
08:46:35.987141 [debug] [MainThread]: Tracking: tracking
08:46:35.987723 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10635f5b0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10635fc10>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10635f0d0>]}
08:46:36.000082 [info ] [MainThread]: Partial parse save file not found. Starting full parse.
08:46:36.000497 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'partial_parser', 'label': 'c4027fbc-f97c-417b-8cf0-e16731f8ddb8', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10636d640>]}
08:46:36.015002 [debug] [MainThread]: Parsing macros/catalog.sql
08:46:36.017655 [debug] [MainThread]: Parsing macros/adapters.sql
08:46:36.058269 [debug] [MainThread]: Parsing macros/materializations/merge.sql
08:46:36.062741 [debug] [MainThread]: Parsing macros/materializations/seed.sql
08:46:36.069441 [debug] [MainThread]: Parsing macros/materializations/view.sql
08:46:36.071095 [debug] [MainThread]: Parsing macros/materializations/table.sql
08:46:36.075599 [debug] [MainThread]: Parsing macros/materializations/incremental.sql
08:46:36.085426 [debug] [MainThread]: Parsing macros/materializations/snapshot.sql
08:46:36.087289 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
08:46:36.091718 [debug] [MainThread]: Parsing macros/materializations/configs.sql
08:46:36.094383 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
08:46:36.096214 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
08:46:36.116359 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
08:46:36.128888 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
08:46:36.143242 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
08:46:36.148474 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
08:46:36.150505 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
08:46:36.153317 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
08:46:36.159243 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
08:46:36.172132 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
08:46:36.174747 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
08:46:36.187790 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
08:46:36.206183 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
08:46:36.215541 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
08:46:36.218844 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
08:46:36.228731 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
08:46:36.230666 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
08:46:36.235058 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
08:46:36.238623 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
08:46:36.248192 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
08:46:36.273813 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
08:46:36.276328 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
08:46:36.281504 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
08:46:36.284431 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
08:46:36.285868 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
08:46:36.286897 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
08:46:36.288488 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
08:46:36.291751 [debug] [MainThread]: Parsing macros/etc/statement.sql
08:46:36.301228 [debug] [MainThread]: Parsing macros/etc/datetime.sql
08:46:36.313597 [debug] [MainThread]: Parsing macros/adapters/schema.sql
08:46:36.317205 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
08:46:36.320872 [debug] [MainThread]: Parsing macros/adapters/relation.sql
08:46:36.333704 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
08:46:36.337709 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
08:46:36.343671 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
08:46:36.355085 [debug] [MainThread]: Parsing macros/adapters/columns.sql
08:46:36.368738 [debug] [MainThread]: Parsing tests/generic/builtin.sql
08:46:36.579632 [debug] [MainThread]: 1699: static parser successfully parsed my_model.sql
08:46:36.590715 [debug] [MainThread]: 1699: static parser successfully parsed my_model_2.sql
08:46:36.592952 [debug] [MainThread]: 1699: static parser successfully parsed my_model_3.sql
08:46:36.613269 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x1066449a0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x106632190>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x106632430>]}
08:46:36.614500 [debug] [MainThread]: Flushing usage events
08:46:37.792302 [error] [MainThread]: Encountered an error:
Compilation Error in model my_model_3 (models/my_model_3.sql)
  Model 'model.snowflake.my_model_3' (models/my_model_3.sql) depends on a node named 'my_model_2' which was not found
08:46:37.794155 [debug] [MainThread]: Traceback (most recent call last):
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/main.py", line 127, in main
    results, succeeded = handle_and_check(args)
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/main.py", line 192, in handle_and_check
    task, res = run_from_args(parsed)
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/main.py", line 246, in run_from_args
    results = task.run()
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/task/runnable.py", line 454, in run
    self._runtime_initialize()
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/task/runnable.py", line 156, in _runtime_initialize
    super()._runtime_initialize()
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/task/runnable.py", line 94, in _runtime_initialize
    self.load_manifest()
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/task/runnable.py", line 81, in load_manifest
    self.manifest = ManifestLoader.get_full_manifest(self.config)
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/parser/manifest.py", line 200, in get_full_manifest
    manifest = loader.load()
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/parser/manifest.py", line 374, in load
    self.process_refs(self.root_project.project_name)
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/parser/manifest.py", line 803, in process_refs
    _process_refs_for_node(self.manifest, current_project, node)
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/parser/manifest.py", line 1163, in _process_refs_for_node
    invalid_ref_fail_unless_test(
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/parser/manifest.py", line 901, in invalid_ref_fail_unless_test
    ref_target_not_found(
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/exceptions.py", line 620, in ref_target_not_found
    raise_compiler_error(msg, model)
  File "/Users/jeremy/src/dbt-sandcastles/venv_dbt_1.0.1/lib/python3.9/site-packages/dbt/exceptions.py", line 454, in raise_compiler_error
    raise CompilationException(msg, node)
dbt.exceptions.CompilationException: Compilation Error in model my_model_3 (models/my_model_3.sql)
  Model 'model.snowflake.my_model_3' (models/my_model_3.sql) depends on a node named 'my_model_2' which was not found

Disabling models via these other methods do not result in the same error:

  • dbt_project.yml:
...
models:
  project:
    my_model_2:
      +enabled: false
    my_model_3:
      +enabled: false
09:05:57  Running with dbt=1.0.1
09:05:57  Partial parse save file not found. Starting full parse.
09:05:58  Found 1 model, 0 tests, 0 snapshots, 0 analyses, 179 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics
09:05:58  
09:06:07  Concurrency: 1 threads (target='dev')
09:06:07  
09:06:07  1 of 1 START table model dbt_jyeo.my_model...................................... [RUN]
09:06:10  1 of 1 OK created table model dbt_jyeo.my_model................................. [SUCCESS 1 in 3.39s]
09:06:10  
09:06:10  Finished running 1 table model in 12.57s.
09:06:10  
09:06:10  Completed successfully
09:06:10  
09:06:10  Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
dbt --debug run output 
============================== 2022-01-10 09:07:15.906013 | ee7f69fa-770a-4f4c-86b7-e80fdb7e57cb ==============================
09:07:15.906013 [info ] [MainThread]: Running with dbt=1.0.1
09:07:15.906982 [debug] [MainThread]: running dbt with arguments Namespace(record_timing_info=None, debug=True, log_format=None, write_json=None, use_colors=None, printer_width=None, warn_error=None, version_check=None, partial_parse=None, single_threaded=False, use_experimental_parser=None, static_parser=None, profiles_dir='/Users/jeremy/.dbt', send_anonymous_usage_stats=None, fail_fast=None, event_buffer_size=None, project_dir=None, profile=None, target=None, vars='{}', log_cache_events=False, threads=None, select=None, exclude=None, selector_name=None, state=None, defer=None, full_refresh=False, cls=<class 'dbt.task.run.RunTask'>, which='run', rpc_method='run')
09:07:15.907481 [debug] [MainThread]: Tracking: tracking
09:07:15.908052 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10d88b7f0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10d88b670>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10d88b130>]}
09:07:15.920696 [info ] [MainThread]: Partial parse save file not found. Starting full parse.
09:07:15.921082 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'partial_parser', 'label': 'ee7f69fa-770a-4f4c-86b7-e80fdb7e57cb', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10d898970>]}
09:07:15.935567 [debug] [MainThread]: Parsing macros/catalog.sql
09:07:15.938210 [debug] [MainThread]: Parsing macros/adapters.sql
09:07:15.978738 [debug] [MainThread]: Parsing macros/materializations/merge.sql
09:07:15.982742 [debug] [MainThread]: Parsing macros/materializations/seed.sql
09:07:15.989422 [debug] [MainThread]: Parsing macros/materializations/view.sql
09:07:15.991242 [debug] [MainThread]: Parsing macros/materializations/table.sql
09:07:15.994805 [debug] [MainThread]: Parsing macros/materializations/incremental.sql
09:07:16.004285 [debug] [MainThread]: Parsing macros/materializations/snapshot.sql
09:07:16.005601 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
09:07:16.010257 [debug] [MainThread]: Parsing macros/materializations/configs.sql
09:07:16.013130 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
09:07:16.015202 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
09:07:16.033623 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
09:07:16.046121 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
09:07:16.058869 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
09:07:16.063728 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
09:07:16.065708 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
09:07:16.067717 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
09:07:16.072490 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
09:07:16.084324 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
09:07:16.086071 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
09:07:16.096681 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
09:07:16.112051 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
09:07:16.119512 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
09:07:16.122339 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
09:07:16.129265 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
09:07:16.130927 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
09:07:16.133866 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
09:07:16.136395 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
09:07:16.142943 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
09:07:16.160026 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
09:07:16.161741 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
09:07:16.164516 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
09:07:16.166345 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
09:07:16.167394 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
09:07:16.168119 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
09:07:16.169023 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
09:07:16.170562 [debug] [MainThread]: Parsing macros/etc/statement.sql
09:07:16.175269 [debug] [MainThread]: Parsing macros/etc/datetime.sql
09:07:16.184485 [debug] [MainThread]: Parsing macros/adapters/schema.sql
09:07:16.186924 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
09:07:16.189799 [debug] [MainThread]: Parsing macros/adapters/relation.sql
09:07:16.199713 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
09:07:16.202886 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
09:07:16.208162 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
09:07:16.215887 [debug] [MainThread]: Parsing macros/adapters/columns.sql
09:07:16.227055 [debug] [MainThread]: Parsing tests/generic/builtin.sql
09:07:16.436383 [debug] [MainThread]: 1699: static parser successfully parsed my_model.sql
09:07:16.448883 [debug] [MainThread]: 1699: static parser successfully parsed my_model_2.sql
09:07:16.451398 [debug] [MainThread]: 1603: static parser failed on my_model_3.sql
09:07:16.454904 [debug] [MainThread]: 1602: parser fallback to jinja rendering on my_model_3.sql
09:07:16.485117 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'load_project', 'label': 'ee7f69fa-770a-4f4c-86b7-e80fdb7e57cb', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10db91ee0>]}
09:07:16.490365 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'resource_counts', 'label': 'ee7f69fa-770a-4f4c-86b7-e80fdb7e57cb', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10db91fa0>]}
09:07:16.490954 [info ] [MainThread]: Found 1 model, 0 tests, 0 snapshots, 0 analyses, 179 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics
09:07:16.492398 [info ] [MainThread]: 
09:07:16.493017 [debug] [MainThread]: Acquiring new snowflake connection "master"
09:07:16.493950 [debug] [ThreadPool]: Acquiring new snowflake connection "list_development"
09:07:16.508027 [debug] [ThreadPool]: Using snowflake connection "list_development"
09:07:16.508443 [debug] [ThreadPool]: On list_development: /* {"app": "dbt", "dbt_version": "1.0.1", "profile_name": "snowflake", "target_name": "dev", "connection_name": "list_development"} */

    show terse schemas in database development
    limit 10000
09:07:16.508765 [debug] [ThreadPool]: Opening a new connection, currently in state init
09:07:18.910128 [debug] [ThreadPool]: SQL status: SUCCESS 28 in 2.4 seconds
09:07:18.916047 [debug] [ThreadPool]: On list_development: Close
09:07:19.606366 [debug] [ThreadPool]: Acquiring new snowflake connection "list_development_dbt_jyeo"
09:07:19.621842 [debug] [ThreadPool]: Using snowflake connection "list_development_dbt_jyeo"
09:07:19.622507 [debug] [ThreadPool]: On list_development_dbt_jyeo: /* {"app": "dbt", "dbt_version": "1.0.1", "profile_name": "snowflake", "target_name": "dev", "connection_name": "list_development_dbt_jyeo"} */

    show terse objects in development.dbt_jyeo
09:07:19.623012 [debug] [ThreadPool]: Opening a new connection, currently in state closed
09:07:21.705613 [debug] [ThreadPool]: SQL status: SUCCESS 3 in 2.08 seconds
09:07:21.709829 [debug] [ThreadPool]: On list_development_dbt_jyeo: Close
09:07:22.374266 [info ] [MainThread]: Concurrency: 1 threads (target='dev')
09:07:22.375269 [info ] [MainThread]: 
09:07:22.381115 [debug] [Thread-1  ]: Began running node model.snowflake.my_model
09:07:22.382043 [info ] [Thread-1  ]: 1 of 1 START table model dbt_jyeo.my_model...................................... [RUN]
09:07:22.383033 [debug] [Thread-1  ]: Acquiring new snowflake connection "model.snowflake.my_model"
09:07:22.383671 [debug] [Thread-1  ]: Began compiling node model.snowflake.my_model
09:07:22.384262 [debug] [Thread-1  ]: Compiling model.snowflake.my_model
09:07:22.387419 [debug] [Thread-1  ]: Writing injected SQL for node "model.snowflake.my_model"
09:07:22.388982 [debug] [Thread-1  ]: finished collecting timing info
09:07:22.389593 [debug] [Thread-1  ]: Began executing node model.snowflake.my_model
09:07:22.421557 [debug] [Thread-1  ]: Writing runtime SQL for node "model.snowflake.my_model"
09:07:22.422714 [debug] [Thread-1  ]: Using snowflake connection "model.snowflake.my_model"
09:07:22.423018 [debug] [Thread-1  ]: On model.snowflake.my_model: /* {"app": "dbt", "dbt_version": "1.0.1", "profile_name": "snowflake", "target_name": "dev", "node_id": "model.snowflake.my_model"} */


      create or replace transient table development.dbt_jyeo.my_model  as
      (select 1 as user
      );
09:07:22.423312 [debug] [Thread-1  ]: Opening a new connection, currently in state closed
09:07:25.045715 [debug] [Thread-1  ]: SQL status: SUCCESS 1 in 2.62 seconds
09:07:25.067344 [debug] [Thread-1  ]: finished collecting timing info
09:07:25.067956 [debug] [Thread-1  ]: On model.snowflake.my_model: Close
09:07:25.705237 [debug] [Thread-1  ]: Sending event: {'category': 'dbt', 'action': 'run_model', 'label': 'ee7f69fa-770a-4f4c-86b7-e80fdb7e57cb', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10e56fbb0>]}
09:07:25.706663 [info ] [Thread-1  ]: 1 of 1 OK created table model dbt_jyeo.my_model................................. [SUCCESS 1 in 3.32s]
09:07:25.707648 [debug] [Thread-1  ]: Finished running node model.snowflake.my_model
09:07:25.710507 [debug] [MainThread]: Acquiring new snowflake connection "master"
09:07:25.711566 [info ] [MainThread]: 
09:07:25.712212 [info ] [MainThread]: Finished running 1 table model in 9.22s.
09:07:25.712802 [debug] [MainThread]: Connection 'master' was properly closed.
09:07:25.713408 [debug] [MainThread]: Connection 'model.snowflake.my_model' was properly closed.
09:07:25.724105 [info ] [MainThread]: 
09:07:25.724616 [info ] [MainThread]: Completed successfully
09:07:25.725127 [info ] [MainThread]: 
09:07:25.725536 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
09:07:25.726047 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10dbb1dc0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10db911f0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10e588d30>]}
09:07:25.727219 [debug] [MainThread]: Flushing usage events
  • In the model's config block:
-- my_model.sql
select 1 as user

-- my_model_2.sql
{{ config(enabled=false) }}
select * from {{ ref('my_model') }}

-- my_model_3.sql
{{ config(enabled=false) }}
select * from {{ ref('my_model_2') }}
08:56:56  Running with dbt=1.0.1
08:56:56  Partial parse save file not found. Starting full parse.
08:56:57  Found 1 model, 0 tests, 0 snapshots, 0 analyses, 179 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics
08:56:57  
08:57:02  Concurrency: 1 threads (target='dev')
08:57:02  
08:57:02  1 of 1 START table model dbt_jyeo.my_model...................................... [RUN]
08:57:06  1 of 1 OK created table model dbt_jyeo.my_model................................. [SUCCESS 1 in 4.07s]
08:57:06  
08:57:06  Finished running 1 table model in 9.75s.
08:57:06  
08:57:06  Completed successfully
08:57:06  
08:57:06  Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
dbt --debug run output 
============================== 2022-01-10 09:00:08.694488 | 6fb52f7a-b8e0-4a9c-afdd-9a6955f333c8 ==============================
09:00:08.694488 [info ] [MainThread]: Running with dbt=1.0.1
09:00:08.695442 [debug] [MainThread]: running dbt with arguments Namespace(record_timing_info=None, debug=True, log_format=None, write_json=None, use_colors=None, printer_width=None, warn_error=None, version_check=None, partial_parse=None, single_threaded=False, use_experimental_parser=None, static_parser=None, profiles_dir='/Users/jeremy/.dbt', send_anonymous_usage_stats=None, fail_fast=None, event_buffer_size=None, project_dir=None, profile=None, target=None, vars='{}', log_cache_events=False, threads=None, select=None, exclude=None, selector_name=None, state=None, defer=None, full_refresh=False, cls=<class 'dbt.task.run.RunTask'>, which='run', rpc_method='run')
09:00:08.696034 [debug] [MainThread]: Tracking: tracking
09:00:08.696535 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x11284a7f0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x11284a670>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x11284a130>]}
09:00:08.711178 [info ] [MainThread]: Partial parse save file not found. Starting full parse.
09:00:08.711593 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'partial_parser', 'label': '6fb52f7a-b8e0-4a9c-afdd-9a6955f333c8', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x112857970>]}
09:00:08.727760 [debug] [MainThread]: Parsing macros/catalog.sql
09:00:08.730836 [debug] [MainThread]: Parsing macros/adapters.sql
09:00:08.771753 [debug] [MainThread]: Parsing macros/materializations/merge.sql
09:00:08.775709 [debug] [MainThread]: Parsing macros/materializations/seed.sql
09:00:08.780845 [debug] [MainThread]: Parsing macros/materializations/view.sql
09:00:08.782241 [debug] [MainThread]: Parsing macros/materializations/table.sql
09:00:08.785582 [debug] [MainThread]: Parsing macros/materializations/incremental.sql
09:00:08.794303 [debug] [MainThread]: Parsing macros/materializations/snapshot.sql
09:00:08.795571 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
09:00:08.800717 [debug] [MainThread]: Parsing macros/materializations/configs.sql
09:00:08.803368 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
09:00:08.806392 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
09:00:08.825667 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
09:00:08.837769 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
09:00:08.850442 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
09:00:08.855572 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
09:00:08.857625 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
09:00:08.859603 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
09:00:08.864352 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
09:00:08.876112 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
09:00:08.877797 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
09:00:08.888606 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
09:00:08.903316 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
09:00:08.911117 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
09:00:08.914193 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
09:00:08.921052 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
09:00:08.922423 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
09:00:08.925146 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
09:00:08.927510 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
09:00:08.933343 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
09:00:08.949547 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
09:00:08.951148 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
09:00:08.953576 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
09:00:08.955220 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
09:00:08.956154 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
09:00:08.956774 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
09:00:08.957598 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
09:00:08.959224 [debug] [MainThread]: Parsing macros/etc/statement.sql
09:00:08.963595 [debug] [MainThread]: Parsing macros/etc/datetime.sql
09:00:08.972037 [debug] [MainThread]: Parsing macros/adapters/schema.sql
09:00:08.974379 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
09:00:08.977001 [debug] [MainThread]: Parsing macros/adapters/relation.sql
09:00:08.985746 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
09:00:08.988570 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
09:00:08.992754 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
09:00:08.999505 [debug] [MainThread]: Parsing macros/adapters/columns.sql
09:00:09.010205 [debug] [MainThread]: Parsing tests/generic/builtin.sql
09:00:09.215466 [debug] [MainThread]: 1699: static parser successfully parsed my_model.sql
09:00:09.226345 [debug] [MainThread]: 1603: static parser failed on my_model_2.sql
09:00:09.230598 [debug] [MainThread]: 1602: parser fallback to jinja rendering on my_model_2.sql
09:00:09.232724 [debug] [MainThread]: 1603: static parser failed on my_model_3.sql
09:00:09.238179 [debug] [MainThread]: 1602: parser fallback to jinja rendering on my_model_3.sql
09:00:09.272336 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'load_project', 'label': '6fb52f7a-b8e0-4a9c-afdd-9a6955f333c8', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x112b0bf70>]}
09:00:09.277866 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'resource_counts', 'label': '6fb52f7a-b8e0-4a9c-afdd-9a6955f333c8', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x112b0beb0>]}
09:00:09.278593 [info ] [MainThread]: Found 1 model, 0 tests, 0 snapshots, 0 analyses, 179 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics
09:00:09.279787 [info ] [MainThread]: 
09:00:09.280282 [debug] [MainThread]: Acquiring new snowflake connection "master"
09:00:09.281130 [debug] [ThreadPool]: Acquiring new snowflake connection "list_development"
09:00:09.295471 [debug] [ThreadPool]: Using snowflake connection "list_development"
09:00:09.295873 [debug] [ThreadPool]: On list_development: /* {"app": "dbt", "dbt_version": "1.0.1", "profile_name": "snowflake", "target_name": "dev", "connection_name": "list_development"} */

    show terse schemas in database development
    limit 10000
09:00:09.296151 [debug] [ThreadPool]: Opening a new connection, currently in state init
09:00:11.548609 [debug] [ThreadPool]: SQL status: SUCCESS 28 in 2.25 seconds
09:00:11.553247 [debug] [ThreadPool]: On list_development: Close
09:00:12.284957 [debug] [ThreadPool]: Acquiring new snowflake connection "list_development_dbt_jyeo"
09:00:12.299039 [debug] [ThreadPool]: Using snowflake connection "list_development_dbt_jyeo"
09:00:12.299641 [debug] [ThreadPool]: On list_development_dbt_jyeo: /* {"app": "dbt", "dbt_version": "1.0.1", "profile_name": "snowflake", "target_name": "dev", "connection_name": "list_development_dbt_jyeo"} */

    show terse objects in development.dbt_jyeo
09:00:12.300139 [debug] [ThreadPool]: Opening a new connection, currently in state closed
09:00:14.176853 [debug] [ThreadPool]: SQL status: SUCCESS 3 in 1.88 seconds
09:00:14.180866 [debug] [ThreadPool]: On list_development_dbt_jyeo: Close
09:00:14.834195 [info ] [MainThread]: Concurrency: 1 threads (target='dev')
09:00:14.835160 [info ] [MainThread]: 
09:00:14.840734 [debug] [Thread-1  ]: Began running node model.snowflake.my_model
09:00:14.841693 [info ] [Thread-1  ]: 1 of 1 START table model dbt_jyeo.my_model...................................... [RUN]
09:00:14.842690 [debug] [Thread-1  ]: Acquiring new snowflake connection "model.snowflake.my_model"
09:00:14.843307 [debug] [Thread-1  ]: Began compiling node model.snowflake.my_model
09:00:14.843852 [debug] [Thread-1  ]: Compiling model.snowflake.my_model
09:00:14.846553 [debug] [Thread-1  ]: Writing injected SQL for node "model.snowflake.my_model"
09:00:14.847909 [debug] [Thread-1  ]: finished collecting timing info
09:00:14.848482 [debug] [Thread-1  ]: Began executing node model.snowflake.my_model
09:00:14.881159 [debug] [Thread-1  ]: Writing runtime SQL for node "model.snowflake.my_model"
09:00:14.882302 [debug] [Thread-1  ]: Using snowflake connection "model.snowflake.my_model"
09:00:14.882629 [debug] [Thread-1  ]: On model.snowflake.my_model: /* {"app": "dbt", "dbt_version": "1.0.1", "profile_name": "snowflake", "target_name": "dev", "node_id": "model.snowflake.my_model"} */


      create or replace transient table development.dbt_jyeo.my_model  as
      (select 1 as user
      );
09:00:14.883050 [debug] [Thread-1  ]: Opening a new connection, currently in state closed
09:00:17.363953 [debug] [Thread-1  ]: SQL status: SUCCESS 1 in 2.48 seconds
09:00:17.385282 [debug] [Thread-1  ]: finished collecting timing info
09:00:17.385849 [debug] [Thread-1  ]: On model.snowflake.my_model: Close
09:00:18.082891 [debug] [Thread-1  ]: Sending event: {'category': 'dbt', 'action': 'run_model', 'label': '6fb52f7a-b8e0-4a9c-afdd-9a6955f333c8', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x11294f670>]}
09:00:18.084297 [info ] [Thread-1  ]: 1 of 1 OK created table model dbt_jyeo.my_model................................. [SUCCESS 1 in 3.24s]
09:00:18.085289 [debug] [Thread-1  ]: Finished running node model.snowflake.my_model
09:00:18.088066 [debug] [MainThread]: Acquiring new snowflake connection "master"
09:00:18.089076 [info ] [MainThread]: 
09:00:18.089709 [info ] [MainThread]: Finished running 1 table model in 8.81s.
09:00:18.090307 [debug] [MainThread]: Connection 'master' was properly closed.
09:00:18.090848 [debug] [MainThread]: Connection 'model.snowflake.my_model' was properly closed.
09:00:18.098615 [info ] [MainThread]: 
09:00:18.099229 [info ] [MainThread]: Completed successfully
09:00:18.099810 [info ] [MainThread]: 
09:00:18.100218 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
09:00:18.100724 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x112963af0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x112904790>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x11296ef40>]}
09:00:18.101901 [debug] [MainThread]: Flushing usage events

The static parser is "successful" on all 3 models when using the property file disabling but there are some "failed" ones when using project file ("static parser failed on my_model_3.sql" but "static parser successfully parsed my_model_2.sql") / config block disabling ("static parser failed on my_model_3.sql" and ""static parser failed on my_model_2.sql"). Not too sure why the inconsistency between those 2 methods that worked.

@jtcohen6
Copy link
Contributor

@gshank Would you be able to take a look at the reproduction case @jeremyyeo laid out, when you get a chance? Since more folks have upgraded to v0.21+, we should expect to see more users trying enabled: False in yaml file config, and being surprised when it doesn't work.

@gshank gshank self-assigned this Feb 15, 2022
@gshank gshank added the jira label Feb 15, 2022
@github-actions github-actions bot changed the title Setting enabled to False in schema config does not move model to disabled [CT-232] Setting enabled to False in schema config does not move model to disabled Feb 15, 2022
@emmyoop emmyoop mentioned this issue May 12, 2022
Closed
1 task
@azhard
Copy link
Contributor

azhard commented May 27, 2022

Any update on this issue? My team is trying to move all our configs into the YAML files but are blocked by this bug.

@leahwicz leahwicz added the bug Something isn't working label Jun 14, 2022
@emmyoop emmyoop self-assigned this Sep 8, 2022
This was referenced Sep 16, 2022
Closed
Merged
@jtcohen6 jtcohen6 added this to the v1.3 milestone Sep 21, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@emmyoop emmyoop

Labels
bug Something isn't working jira
Projects
None yet
Milestone
v1.3
Development

Successfully merging a pull request may close this issue.

Disabled Models in schema files dbt-labs/dbt-core
6 participants
@gshank @azhard @emmyoop @jeremyyeo @jtcohen6 @leahwicz