Tomme / dbt-athena

The athena adapter plugin for dbt (https://getdbt.com)
Apache License 2.0
142 stars 79 forks source link

Error running model with external_location when table already exists #118

Closed rmbrich closed 2 years ago

rmbrich commented 2 years ago

I'm experiencing a strange error when running a model with materialized='table' and external_location. It only happens when the table already exists in Athena. I thought #73 would fix it but it doesn't appear to.

portfolio_account.sql:

{{ config(
   materialized = 'table',
   external_location = 's3://<my bucket>/test/' + target.name + '/portfolio_account/',
   partitioned_by = ['_company_id'],
   format = 'orc',
   write_compression = 'zlib'
) }}
...

dbt run --models portfolio_account (relevant dbt.log snippet):

14:38:54.901965 [debug] [Thread-1 (]: Began running node model.lake.portfolio_account
14:38:54.901965 [info ] [Thread-1 (]: 1 of 1 START table model lake_dev.portfolio_account ............................ [RUN]
14:38:54.901965 [debug] [Thread-1 (]: Acquiring new athena connection "model.lake.portfolio_account"
14:38:54.901965 [debug] [Thread-1 (]: Began compiling node model.lake.portfolio_account
14:38:54.917542 [debug] [Thread-1 (]: Compiling model.lake.portfolio_account
14:38:54.917542 [debug] [Thread-1 (]: Writing injected SQL for node "model.lake.portfolio_account"
14:38:54.917542 [debug] [Thread-1 (]: finished collecting timing info
14:38:54.917542 [debug] [Thread-1 (]: Began executing node model.lake.portfolio_account
14:38:54.982451 [debug] [Thread-1 (]: Opening a new connection, currently in state init
14:38:55.492034 [debug] [Thread-1 (]: Athena adapter: Error running SQL: macro drop_relation
14:38:55.507660 [debug] [Thread-1 (]: finished collecting timing info
14:38:55.507660 [debug] [Thread-1 (]: On model.lake.portfolio_account: Close
14:38:55.507660 [debug] [Thread-1 (]: Runtime Error in model portfolio_account (models\portfolio_account.sql)
  local variable 'table' referenced before assignment
14:38:55.507660 [debug] [Thread-1 (]: Sending event: {'category': 'dbt', 'action': 'run_model', 'label': 'fedef137-2292-43ea-9d8f-27a910d27f59', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000027BE7F09F60>]}
14:38:55.507660 [error] [Thread-1 (]: 1 of 1 ERROR creating table model lake_dev.portfolio_account ................... [ERROR in 0.61s]
14:38:55.507660 [debug] [Thread-1 (]: Finished running node model.lake.portfolio_account
owenprough-sift commented 2 years ago

When I updated to a version of dbt-athena with #73 included, I had saw this behavior as well. Full-refreshing my tables once after update seemed the resolve the issue going forward (I have not had this issue since), but I have no idea what was causing the problem.

rmbrich commented 2 years ago

Even after full refreshing once, this is still happening for me.

melquic commented 2 years ago

Same error here

dbt-athena Version: 1.0.1 Location: /usr/local/lib/python3.9/dist-packages

19:50:14 Runtime Error in model alpha_product_category (models/silver/alpha_product_category.sql) 19:50:14 local variable 'table' referenced before assignment

DBT logs:

21:30:58.863264 [debug] [Thread-1 ]: Began running node model.dbt_printi.alpha_product_category 21:30:58.865017 [info ] [Thread-1 ]: 1 of 1 START table model bi_datalake_dev_silver.alpha_product_category.......... [RUN] 21:30:58.868244 [debug] [Thread-1 ]: Acquiring new athena connection "model.dbt_printi.alpha_product_category" 21:30:58.871360 [debug] [Thread-1 ]: Began compiling node model.dbt_printi.alpha_product_category 21:30:58.872429 [debug] [Thread-1 ]: Compiling model.dbt_printi.alpha_product_category 21:30:58.885684 [debug] [Thread-1 ]: Writing injected SQL for node "model.dbt_printi.alpha_product_category" 21:30:58.893848 [debug] [Thread-1 ]: finished collecting timing info 21:30:58.895043 [debug] [Thread-1 ]: Began executing node model.dbt_printi.alpha_product_category 21:30:58.911181 [debug] [Thread-1 ]: Opening a new connection, currently in state closed 21:30:59.640458 [debug] [Thread-1 ]: Athena adapter: Error running SQL: macro drop_relation 21:30:59.645847 [debug] [Thread-1 ]: finished collecting timing info 21:30:59.650678 [debug] [Thread-1 ]: On model.dbt_printi.alpha_product_category: Close 21:30:59.654288 [debug] [Thread-1 ]: Runtime Error in model alpha_product_category (models/silver/alpha_product_category.sql) local variable 'table' referenced before assignment 21:30:59.657052 [debug] [Thread-1 ]: Sending event: {'category': 'dbt', 'action': 'run_model', 'label': '91a10d40-84e3-4a33-a7f3-cc6e2a3f5a83', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0xffff8a63d400>]} 21:30:59.660499 [error] [Thread-1 ]: 1 of 1 ERROR creating table model bi_datalake_dev_silver.alpha_product_category. [ERROR in 0.79s] 21:30:59.663327 [debug] [Thread-1 ]: Finished running node model.dbt_printi.alpha_product_category

Appreciate any help. Thanks.

rmbrich commented 2 years ago

Closing this for now, it will be fixed by #124 or #125