Tomme/dbt-athena

Error running model with external_location when table already exists

Closed this issue · 4 comments

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):

�[0m14:38:54.901965 [debug] [Thread-1 (]: Began running node model.lake.portfolio_account
�[0m14:38:54.901965 [info ] [Thread-1 (]: 1 of 1 START table model lake_dev.portfolio_account ............................ [RUN]
�[0m14:38:54.901965 [debug] [Thread-1 (]: Acquiring new athena connection "model.lake.portfolio_account"
�[0m14:38:54.901965 [debug] [Thread-1 (]: Began compiling node model.lake.portfolio_account
�[0m14:38:54.917542 [debug] [Thread-1 (]: Compiling model.lake.portfolio_account
�[0m14:38:54.917542 [debug] [Thread-1 (]: Writing injected SQL for node "model.lake.portfolio_account"
�[0m14:38:54.917542 [debug] [Thread-1 (]: finished collecting timing info
�[0m14:38:54.917542 [debug] [Thread-1 (]: Began executing node model.lake.portfolio_account
�[0m14:38:54.982451 [debug] [Thread-1 (]: Opening a new connection, currently in state init
�[0m14:38:55.492034 [debug] [Thread-1 (]: Athena adapter: Error running SQL: macro drop_relation
�[0m14:38:55.507660 [debug] [Thread-1 (]: finished collecting timing info
�[0m14:38:55.507660 [debug] [Thread-1 (]: On model.lake.portfolio_account: Close
�[0m14:38:55.507660 [debug] [Thread-1 (]: Runtime Error in model portfolio_account (models\portfolio_account.sql)
  local variable 'table' referenced before assignment
�[0m14: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>]}
�[0m14:38:55.507660 [error] [Thread-1 (]: 1 of 1 ERROR creating table model lake_dev.portfolio_account ................... [�[31mERROR�[0m in 0.61s]
�[0m14:38:55.507660 [debug] [Thread-1 (]: Finished running node model.lake.portfolio_account

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.

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

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. [�[31mERROR�[0m in 0.79s]
21:30:59.663327 [debug] [Thread-1 ]: Finished running node model.dbt_printi.alpha_product_category

Appreciate any help. Thanks.

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