Snapshot - macro 'dbt_macro__create_schema' takes not more than 1 argument(s)

[rlshuhart]

Hi trying out snapshots on SQL Server 2017 and I'm running into an odd issues that I can't make out what is going on. Apologies if this is stackoverflow territory, but this seems simple enough that there might be a bug. I have a fresh virtual environment with the packages listed below at the end.

Using this table as my test (models\test.sql)

SELECT 1 as id
,'Dallas' as city

and then trying this snapshot (snapshots\test.sql}

{% snapshot test_snap %}

{{
config(
unique_key='id',
strategy='check',
check_cols='all'
)
}}

SELECT * from {{ ref('test') }}

{% endsnapshot %}

I get this error:

15:09:06  Running with dbt=1.0.1
15:09:06  Found 1 model, 0 tests, 1 snapshot, 0 analyses, 187 macros, 0 operations, 0 seed files, 20 sources, 0 exposures, 0 metrics
15:09:06
15:09:07  Concurrency: 1 threads (target='dev')
15:09:07
15:09:07  1 of 1 START snapshot MyDatabaseStage.snapshot.test_snap...................... [RUN]
15:09:08  1 of 1 ERROR snapshotting MyDatabaseStage.snapshot.test_snap.................. [ERROR in 0.34s]
15:09:08
15:09:08  Finished running 1 snapshot in 1.11s.
15:09:08
15:09:08  Completed with 1 error and 0 warnings:
15:09:08
15:09:08  Compilation Error in macro create_schema (macros\adapters\schema.sql)
15:09:08    macro 'dbt_macro__create_schema' takes not more than 1 argument(s)
15:09:08
15:09:08    > in macro materialization_snapshot_default (macros\materializations\snapshots\snapshot.sql)
15:09:08    > called by macro create_schema (macros\adapters\schema.sql)
15:09:08
15:09:08  Done. PASS=0 WARN=0 ERROR=1 SKIP=0 TOTAL=1
15:09:08  Error sending message, disabling tracking

full log:

============================== 2022-02-17 15:18:24.201713 | 2bf48697-56da-42e9-8bff-806d6d3a24b5 ==============================
15:18:24.201713 [info ] [MainThread]: Running with dbt=1.0.1
15:18:24.202713 [debug] [MainThread]: running dbt with arguments Namespace(record_timing_info=None, debug=None, 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='C:\\Users\\rshuhart001\\.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, cls=<class 'dbt.task.snapshot.SnapshotTask'>, which='snapshot', rpc_method='snapshot')
15:18:24.202713 [debug] [MainThread]: Tracking: tracking
15:18:24.203213 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D632C4F0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D632C550>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D632C5B0>]}
15:18:24.264257 [debug] [MainThread]: Partial parsing enabled: 0 files deleted, 0 files added, 0 files changed.
15:18:24.264757 [debug] [MainThread]: Partial parsing enabled, no changes found, skipping parsing
15:18:24.271712 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'load_project', 'label': '2bf48697-56da-42e9-8bff-806d6d3a24b5', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D644AF10>]}
15:18:24.278716 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'resource_counts', 'label': '2bf48697-56da-42e9-8bff-806d6d3a24b5', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D638BBB0>]}
15:18:24.278716 [info ] [MainThread]: Found 1 model, 0 tests, 1 snapshot, 0 analyses, 187 macros, 0 operations, 0 seed files, 20 sources, 0 exposures, 0 metrics
15:18:24.281213 [info ] [MainThread]: 
15:18:24.281713 [debug] [MainThread]: Acquiring new sqlserver connection "master"
15:18:24.283215 [debug] [ThreadPool]: Acquiring new sqlserver connection "list_MyDatabaseStage"
15:18:24.292714 [debug] [ThreadPool]: Opening a new connection, currently in state init
15:18:25.024568 [debug] [ThreadPool]: On list_MyDatabaseStage: Close
15:18:25.025568 [debug] [ThreadPool]: Acquiring new sqlserver connection "list_MyDatabaseStage_snapshot"
15:18:25.030571 [debug] [ThreadPool]: Opening a new connection, currently in state init
15:18:25.120571 [debug] [ThreadPool]: On list_MyDatabaseStage_snapshot: ROLLBACK
15:18:25.121071 [debug] [ThreadPool]: On list_MyDatabaseStage_snapshot: Close
15:18:25.121571 [debug] [ThreadPool]: Acquiring new sqlserver connection "list_MyDatabase_dbt_ryan"
15:18:25.123071 [debug] [ThreadPool]: Opening a new connection, currently in state closed
15:18:25.193070 [debug] [ThreadPool]: On list_MyDatabase_dbt_ryan: ROLLBACK
15:18:25.193569 [debug] [ThreadPool]: On list_MyDatabase_dbt_ryan: Close
15:18:25.194573 [debug] [MainThread]: On master: COMMIT
15:18:25.194573 [info ] [MainThread]: Concurrency: 1 threads (target='dev')
15:18:25.195071 [info ] [MainThread]: 
15:18:25.205577 [debug] [Thread-1  ]: Began running node snapshot.MyDatabase.test_snap
15:18:25.206071 [info ] [Thread-1  ]: 1 of 1 START snapshot MyDatabaseStage.snapshot.test_snap...................... [RUN]
15:18:25.207590 [debug] [Thread-1  ]: Acquiring new sqlserver connection "snapshot.MyDatabase.test_snap"
15:18:25.207590 [debug] [Thread-1  ]: Began compiling node snapshot.MyDatabase.test_snap
15:18:25.208104 [debug] [Thread-1  ]: Compiling snapshot.MyDatabase.test_snap
15:18:25.210603 [debug] [Thread-1  ]: finished collecting timing info
15:18:25.211106 [debug] [Thread-1  ]: Began executing node snapshot.MyDatabase.test_snap
15:18:25.238569 [debug] [Thread-1  ]: Opening a new connection, currently in state init
15:18:25.646573 [debug] [Thread-1  ]: finished collecting timing info
15:18:25.646573 [debug] [Thread-1  ]: On snapshot.MyDatabase.test_snap: Close
15:18:25.647073 [debug] [Thread-1  ]: Compilation Error in macro create_schema (macros\adapters\schema.sql)
  macro 'dbt_macro__create_schema' takes not more than 1 argument(s)
  
  > in macro materialization_snapshot_default (macros\materializations\snapshots\snapshot.sql)
  > called by macro create_schema (macros\adapters\schema.sql)
15:18:25.647573 [debug] [Thread-1  ]: Sending event: {'category': 'dbt', 'action': 'run_model', 'label': '2bf48697-56da-42e9-8bff-806d6d3a24b5', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D65047F0>]}
15:18:25.647573 [error] [Thread-1  ]: 1 of 1 ERROR snapshotting MyDatabaseStage.snapshot.test_snap.................. [�[31mERROR�[0m in 0.44s]
15:18:25.649069 [debug] [Thread-1  ]: Finished running node snapshot.MyDatabase.test_snap
15:18:25.650071 [debug] [MainThread]: Acquiring new sqlserver connection "master"
15:18:25.650571 [debug] [MainThread]: On master: COMMIT
15:18:25.651129 [info ] [MainThread]: 
15:18:25.651606 [info ] [MainThread]: Finished running 1 snapshot in 1.37s.
15:18:25.652071 [debug] [MainThread]: Connection 'master' was properly closed.
15:18:25.652071 [debug] [MainThread]: Connection 'list_MyDatabaseStage' was properly closed.
15:18:25.652603 [debug] [MainThread]: Connection 'list_MyDatabase_dbt_ryan' was properly closed.
15:18:25.652603 [debug] [MainThread]: Connection 'snapshot.MyDatabase.test_snap' was properly closed.
15:18:25.662095 [info ] [MainThread]: 
15:18:25.662607 [info ] [MainThread]: �[31mCompleted with 1 error and 0 warnings:�[0m
15:18:25.663573 [info ] [MainThread]: 
15:18:25.664071 [error] [MainThread]: �[33mCompilation Error in macro create_schema (macros\adapters\schema.sql)�[0m
15:18:25.665099 [error] [MainThread]:   macro 'dbt_macro__create_schema' takes not more than 1 argument(s)
15:18:25.665569 [error] [MainThread]:   
15:18:25.665569 [error] [MainThread]:   > in macro materialization_snapshot_default (macros\materializations\snapshots\snapshot.sql)
15:18:25.666069 [error] [MainThread]:   > called by macro create_schema (macros\adapters\schema.sql)
15:18:25.666572 [info ] [MainThread]: 
15:18:25.667571 [info ] [MainThread]: Done. PASS=0 WARN=0 ERROR=1 SKIP=0 TOTAL=1
15:18:25.671571 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D64139A0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D6466DF0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000002D7D6504490>]}
15:18:25.964571 [warn ] [MainThread]: Error sending message, disabling tracking

pip freeze:

agate==1.6.3
attrs==21.4.0
azure-core==1.22.1
azure-identity==1.7.1
Babel==2.9.1
certifi==2021.10.8
cffi==1.15.0
charset-normalizer==2.0.12
click==8.0.3
colorama==0.4.4
cryptography==36.0.1
dbt-core==1.0.1
dbt-extractor==0.4.0
dbt-sqlserver==1.0.0
decorator==5.1.1
future==0.18.2
hologram==0.0.14
idna==3.3
importlib-metadata==4.11.1
isodate==0.6.1
Jinja2==2.11.3
json-rpc==1.13.0
jsonschema==3.1.1
leather==0.3.4
Logbook==1.5.3
MarkupSafe==2.0.1
mashumaro==2.9
minimal-snowplow-tracker==0.0.2
msal==1.17.0
msal-extensions==0.3.1
msgpack==1.0.3
networkx==2.6.3
packaging==21.3
parsedatetime==2.4
portalocker==2.3.2
pycparser==2.21
PyJWT==2.3.0
pyodbc==4.0.32
pyparsing==3.0.7
pyrsistent==0.18.1
python-dateutil==2.8.2
python-slugify==6.0.1
pytimeparse==1.1.8
pytz==2021.3
pywin32==303
PyYAML==6.0
requests==2.27.1
six==1.16.0
sqlparse==0.4.2
text-unidecode==1.3
typing-extensions==3.10.0.2
urllib3==1.26.8
Werkzeug==2.0.3
wincertstore==0.2
zipp==3.7.0

[rlshuhart]

I found a work-around. If I delete the certain lines below from what I think comes from the dependency install of dbt-core, I am able to run snapshot successfully. Perhaps this is a dbt-core issue?

https://github.com/dbt-labs/dbt-core/blob/3ad61d5d810aab8bf7bf7bc38f62d02348839c80/core/dbt/include/global_project/macros/materializations/snapshots/snapshot.sql#L9-L11

[mikaelene]

Hi! It looks more like configuration or authorisation problem. Can you run any model?

The failing part is when dbt tries to create the schema that does not exist. Do you have any special chars in the schema name?

[rlshuhart]

Hi @mikaelene,

I have two snapshot and both run into the 'dbt_macro__create_schema' issue above. I can run a model-paths model successfully without error.

To expand a little more on the above work-around, when I go into the python environment then Lib/site-packages/dbt/include/global_project/macros/materializations/snapshots/snapshots.sql and delete lines 9-11, the adapter.check_schema_exists section, then the snapshot compile and execute without issue.

[mikaelene]

Hi,

Did you specify target_schema somewhere?

/Mikael

[mikaelene]

https://docs.getdbt.com/docs/building-a-dbt-project/snapshots#snapshot-configurations

[rlshuhart]

I had target_schema specified in the dbt_project.yml. Using the work-around I mentioned above, the snapshots did land in the schema specified on the dbt_project.yml. I just tried adding the target_schema specification into the config of the snapshot model and resulted in the same error.

[rlshuhart]

Hi @mikaelene, Indeed this appears to be a dbt-core issue. @jtcohen6 has researched that above lines in dbt-core are unnecessary and will be removed via dbt-labs/dbt-core#4993