append query

gistfile1.txt

============================= test session starts ==============================
platform linux -- Python 3.8.10, pytest-7.3.0, pluggy-1.0.0
rootdir: /home/vkolanu/dbt_impala/dbt-impala
configfile: pytest.ini
plugins: dotenv-0.5.2
collected 1 item

tests/functional/adapter/test_basic.py::TestIncrementalWithSinglePartitionKeyImpala::test_incremental 
=== Test project_root: /tmp/pytest-of-vkolanu/pytest-363/project0
20:05:07.837850 [info ] [MainThread]: Partial parse save file not found. Starting full parse.
20:05:08.167659 [debug] [MainThread]: Acquiring new impala connection "_test"
20:05:08.168217 [debug] [MainThread]: Acquiring new impala connection "_test"
20:05:08.168842 [debug] [MainThread]: Creating schema "_ReferenceKey(database=None, schema='test16830579085311601108_test_basic', identifier=None)"
20:05:08.176461 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:08.176990 [debug] [MainThread]: Using impala connection "_test"
20:05:08.177519 [debug] [MainThread]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:05:08.178288 [debug] [MainThread]: On _test: create schema if not exists test16830579085311601108_test_basic
  
20:05:08.178825 [debug] [MainThread]: Opening a new connection, currently in state init
20:05:08.179357 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:08.179959 [debug] [Thread-1  ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:05:08.180560 [debug] [Thread-1  ]: Tracker adapter: Disabling usage tracking due to error.
20:05:08.926463 [debug] [MainThread]: Impala adapter: IMPALA VERSION ImpalaConnectionManager.impala_version
20:05:08.929678 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:08.932752 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:09.767185 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:09.770200 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': 'create schema if not exists test16830579085311601108_test_basic\n  ', 'elapsed_time': '1.59', 'status': 'OK', 'profile_name': 'test'}
20:05:09.773166 [debug] [MainThread]: SQL status: OK in 1.59 seconds
20:05:09.778837 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:05:09.781997 [debug] [MainThread]: On _test: ROLLBACK
20:05:09.785037 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:09.788021 [debug] [MainThread]: On _test: Close
20:05:10.015869 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:10.019068 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}


Invoking dbt with ['seed']
20:05:10.057428 [debug] [MainThread]: Connection '_test' was properly closed.


============================== 2023-05-02 20:05:10.071616 | 45d39209-e952-42d1-8f1f-86b1dae76657 ==============================
20:05:10.071622 [info ] [MainThread]: Running with dbt=1.3.3
20:05:10.072456 [debug] [MainThread]: running dbt with arguments {'debug': True, 'write_json': True, 'use_colors': True, 'printer_width': 80, 'version_check': True, 'partial_parse': True, 'static_parser': True, 'profiles_dir': '/tmp/pytest-of-vkolanu/pytest-363/profile0', 'send_anonymous_usage_stats': False, 'event_buffer_size': 100000, 'quiet': False, 'no_print': False, 'cache_selected_only': False, 'show': False, 'which': 'seed', 'rpc_method': 'seed', 'indirect_selection': 'eager'}
20:05:10.073228 [debug] [MainThread]: Tracking: do not track
20:05:10.083172 [info ] [MainThread]: Partial parse save file not found. Starting full parse.
20:05:10.094184 [debug] [MainThread]: Parsing macros/adapters.sql
20:05:10.153826 [debug] [MainThread]: Parsing macros/catalog.sql
20:05:10.154639 [debug] [MainThread]: Parsing macros/incremental.sql
20:05:10.166208 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:05:10.168806 [debug] [MainThread]: Parsing macros/seed.sql
20:05:10.172171 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:05:10.177419 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:10.178241 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:10.179062 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:10.179935 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:10.181399 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:10.183017 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:10.183866 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:10.184798 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:10.185699 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:10.186803 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:10.199429 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:05:10.200190 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:10.201052 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:10.202007 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:10.202853 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:10.203701 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:05:10.205856 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:05:10.207335 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:05:10.208873 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:05:10.212460 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:05:10.214463 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:05:10.221510 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:05:10.231727 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:05:10.233595 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:05:10.238899 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:05:10.249081 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:05:10.251890 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:05:10.254349 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:10.255592 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:05:10.256954 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:05:10.258310 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:05:10.259637 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:10.260944 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:10.262144 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:05:10.263347 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:10.265384 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:10.267093 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:10.268322 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:10.269703 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:10.270917 [debug] [MainThread]: Parsing macros/utils/except.sql
20:05:10.271960 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:05:10.277237 [debug] [MainThread]: Parsing macros/utils/length.sql
20:05:10.278360 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:05:10.279406 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:10.281309 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:10.282620 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:10.283754 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:10.285094 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:10.286578 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:10.287774 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:05:10.289023 [debug] [MainThread]: Parsing macros/utils/right.sql
20:05:10.290255 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:05:10.292314 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:05:10.295488 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:05:10.300788 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:05:10.306599 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:05:10.317698 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:05:10.324920 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:05:10.326394 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:05:10.336506 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:05:10.339160 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:05:10.341228 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:05:10.345282 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:05:10.346633 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:05:10.350751 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:05:10.353632 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:05:10.361802 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:05:10.373231 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:05:10.374809 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:05:10.383959 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:05:10.385662 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:05:10.389172 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:05:10.390824 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:05:10.395720 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:05:10.408028 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:05:10.412540 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:05:10.416501 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:05:10.422567 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:05:10.423512 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:05:10.424550 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:05:10.425946 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:05:10.427005 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:05:10.680184 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:05:10.692984 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:05:10.775254 [info ] [MainThread]: Found 1 model, 0 tests, 0 snapshots, 0 analyses, 317 macros, 0 operations, 2 seed files, 1 source, 0 exposures, 0 metrics
20:05:10.776468 [info ] [MainThread]: 
20:05:10.777233 [debug] [MainThread]: Acquiring new impala connection "master"
20:05:10.778278 [debug] [ThreadPool]: Acquiring new impala connection "list_schemas"
20:05:10.782636 [debug] [ThreadPool]: Using impala connection "list_schemas"
20:05:10.783191 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:05:10.783853 [debug] [Thread-2  ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:05:10.784487 [debug] [ThreadPool]: On list_schemas: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_schemas"} */
show databases
20:05:10.785079 [debug] [Thread-2  ]: Tracker adapter: Disabling usage tracking due to error.
20:05:10.785685 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:05:10.786337 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:10.914079 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:10.917129 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:11.156969 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:11.160111 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_schemas"} */\nshow databases', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:05:11.163181 [debug] [ThreadPool]: SQL status: OK in 0.37 seconds
20:05:11.509768 [debug] [ThreadPool]: On list_schemas: Close
20:05:11.746638 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:11.749952 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}
20:05:11.757455 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830579085311601108_test_basic"
20:05:11.789714 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:11.790997 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:11.792216 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:11.793442 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic
  
20:05:11.794431 [debug] [ThreadPool]: Opening a new connection, currently in state closed
20:05:11.795419 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:11.929454 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:11.932633 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:12.155614 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:12.158911 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:05:12.162257 [debug] [ThreadPool]: SQL status: OK in 0.36 seconds
20:05:12.395041 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: Close
20:05:12.642034 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:12.645357 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.25'}
20:05:12.650248 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:12.653416 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:05:12.654267 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:05:12.654873 [info ] [MainThread]: 
20:05:12.658011 [debug] [Thread-3  ]: Began running node seed.incremental_test_model.added
20:05:12.659004 [info ] [Thread-3  ]: 1 of 2 START seed file test16830579085311601108_test_basic.added ............... [RUN]
20:05:12.659892 [debug] [Thread-4  ]: Began running node seed.incremental_test_model.base
20:05:12.660659 [debug] [Thread-3  ]: Acquiring new impala connection "seed.incremental_test_model.added"
20:05:12.660977 [info ] [Thread-4  ]: 2 of 2 START seed file test16830579085311601108_test_basic.base ................ [RUN]
20:05:12.662397 [debug] [Thread-3  ]: Began compiling node seed.incremental_test_model.added
20:05:12.662716 [debug] [Thread-4  ]: Acquiring new impala connection "seed.incremental_test_model.base"
20:05:12.663676 [debug] [Thread-3  ]: finished collecting timing info
20:05:12.663941 [debug] [Thread-4  ]: Began compiling node seed.incremental_test_model.base
20:05:12.664822 [debug] [Thread-3  ]: Began executing node seed.incremental_test_model.added
20:05:12.665083 [debug] [Thread-4  ]: finished collecting timing info
20:05:12.676926 [debug] [Thread-4  ]: Began executing node seed.incremental_test_model.base
20:05:12.690830 [debug] [Thread-3  ]: Impala adapter: NotImplemented: add_begin_query
20:05:12.691355 [debug] [Thread-3  ]: Using impala connection "seed.incremental_test_model.added"
20:05:12.691881 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:12.692446 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "seed.incremental_test_model.added"} */\n\n    create table test16830579085311601108_test_basic.added (id integer,name string,some_date timestamp)\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'seed.incremental_test_model.added'}
20:05:12.692976 [debug] [Thread-3  ]: On seed.incremental_test_model.added: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "seed.incremental_test_model.added"} */

    create table test16830579085311601108_test_basic.added (id integer,name string,some_date timestamp)
  
20:05:12.693570 [debug] [Thread-3  ]: Opening a new connection, currently in state closed
20:05:12.695716 [debug] [Thread-3  ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:12.695983 [debug] [Thread-4  ]: Impala adapter: NotImplemented: add_begin_query
20:05:12.697247 [debug] [Thread-4  ]: Using impala connection "seed.incremental_test_model.base"
20:05:12.697866 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:12.698391 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "seed.incremental_test_model.base"} */\n\n    create table test16830579085311601108_test_basic.base (id integer,name string,some_date timestamp)\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'seed.incremental_test_model.base'}
20:05:12.698945 [debug] [Thread-4  ]: On seed.incremental_test_model.base: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "seed.incremental_test_model.base"} */

    create table test16830579085311601108_test_basic.base (id integer,name string,some_date timestamp)
  
20:05:12.699641 [debug] [Thread-4  ]: Opening a new connection, currently in state init
20:05:12.700237 [debug] [Thread-4  ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:12.833080 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:12.839146 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:12.842700 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:12.845310 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:13.579581 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:13.582979 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "seed.incremental_test_model.base"} */\n\n    create table test16830579085311601108_test_basic.base (id integer,name string,some_date timestamp)\n  ', 'elapsed_time': '0.88', 'status': 'OK', 'profile_name': 'test'}
20:05:13.586210 [debug] [Thread-4  ]: SQL status: OK in 0.88 seconds
20:05:13.650455 [debug] [Thread-4  ]: Using impala connection "seed.incremental_test_model.base"
20:05:13.651056 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:13.651623 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '\n          insert into test16830579085311601108_test_basic.base values\n          (cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as ti...', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'seed.incremental_test_model.base'}
20:05:13.652247 [debug] [Thread-4  ]: On seed.incremental_test_model.base: 
          insert into test16830579085311601108_test_basic.base values
          (cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as ti...
20:05:13.893948 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:13.897099 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "seed.incremental_test_model.added"} */\n\n    create table test16830579085311601108_test_basic.added (id integer,name string,some_date timestamp)\n  ', 'elapsed_time': '1.20', 'status': 'OK', 'profile_name': 'test'}
20:05:13.900202 [debug] [Thread-3  ]: SQL status: OK in 1.2 seconds
20:05:13.973915 [debug] [Thread-3  ]: Using impala connection "seed.incremental_test_model.added"
20:05:13.974467 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:13.974992 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '\n          insert into test16830579085311601108_test_basic.added values\n          (cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as t...', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'seed.incremental_test_model.added'}
20:05:13.975522 [debug] [Thread-3  ]: On seed.incremental_test_model.added: 
          insert into test16830579085311601108_test_basic.added values
          (cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as t...
20:05:14.521777 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.525130 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '\n          insert into test16830579085311601108_test_basic.base values\n          (cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as ti...', 'elapsed_time': '0.87', 'status': 'OK', 'profile_name': 'test'}
20:05:14.528267 [debug] [Thread-4  ]: SQL status: OK in 0.87 seconds
20:05:14.556131 [debug] [Thread-4  ]: Writing runtime SQL for node "seed.incremental_test_model.base"
20:05:14.559926 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.561517 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:14.586014 [debug] [Thread-4  ]: Impala adapter: NotImplemented: commit
20:05:14.586904 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.587589 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:14.588522 [debug] [Thread-4  ]: finished collecting timing info
20:05:14.589172 [debug] [Thread-4  ]: On seed.incremental_test_model.base: ROLLBACK
20:05:14.589774 [debug] [Thread-4  ]: Impala adapter: NotImplemented: rollback
20:05:14.590381 [debug] [Thread-4  ]: On seed.incremental_test_model.base: Close
20:05:14.764757 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.767776 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '\n          insert into test16830579085311601108_test_basic.added values\n          (cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as timestamp)),(cast(%s as integer),cast(%s as string),cast(%s as t...', 'elapsed_time': '0.79', 'status': 'OK', 'profile_name': 'test'}
20:05:14.768304 [debug] [Thread-3  ]: SQL status: OK in 0.79 seconds
20:05:14.769554 [debug] [Thread-3  ]: Writing runtime SQL for node "seed.incremental_test_model.added"
20:05:14.770695 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.771225 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:14.773467 [debug] [Thread-3  ]: Impala adapter: NotImplemented: commit
20:05:14.774119 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.774634 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:14.775215 [debug] [Thread-3  ]: finished collecting timing info
20:05:14.775750 [debug] [Thread-3  ]: On seed.incremental_test_model.added: ROLLBACK
20:05:14.776266 [debug] [Thread-3  ]: Impala adapter: NotImplemented: rollback
20:05:14.776791 [debug] [Thread-3  ]: On seed.incremental_test_model.added: Close
20:05:14.819428 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.822623 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:05:14.827080 [info ] [Thread-4  ]: 2 of 2 OK loaded seed file test16830579085311601108_test_basic.base ............ [INSERT 10 in 2.16s]
20:05:14.830755 [debug] [Thread-4  ]: Finished running node seed.incremental_test_model.base
20:05:14.995047 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:14.998073 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:05:15.002369 [info ] [Thread-3  ]: 1 of 2 OK loaded seed file test16830579085311601108_test_basic.added ........... [INSERT 20 in 2.34s]
20:05:15.005763 [debug] [Thread-3  ]: Finished running node seed.incremental_test_model.added
20:05:15.012345 [debug] [MainThread]: Acquiring new impala connection "master"
20:05:15.015726 [debug] [MainThread]: On master: ROLLBACK
20:05:15.018874 [debug] [MainThread]: Opening a new connection, currently in state init
20:05:15.021952 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:15.159358 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:15.162477 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.01'}
20:05:15.165496 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:15.168556 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:15.171564 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:05:15.174577 [debug] [MainThread]: On master: ROLLBACK
20:05:15.177508 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:15.180440 [debug] [MainThread]: On master: Close
20:05:15.301434 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:15.304754 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.13'}
20:05:15.309120 [info ] [MainThread]: 
20:05:15.312218 [info ] [MainThread]: Finished running 2 seeds in 0 hours 0 minutes and 4.53 seconds (4.53s).
20:05:15.315303 [debug] [MainThread]: Connection 'master' was properly closed.
20:05:15.318218 [debug] [MainThread]: Connection 'seed.incremental_test_model.added' was properly closed.
20:05:15.321216 [debug] [MainThread]: Connection 'seed.incremental_test_model.base' was properly closed.
20:05:15.340338 [info ] [MainThread]: 
20:05:15.341639 [info ] [MainThread]: Completed successfully
20:05:15.342931 [info ] [MainThread]: 
20:05:15.344080 [info ] [MainThread]: Done. PASS=2 WARN=0 ERROR=0 SKIP=0 TOTAL=2
20:05:15.345211 [debug] [MainThread]: Flushing usage events
20:05:15.345881 [debug] [MainThread]: Integration Test: test connection "__test" executing: select count(*) as num_rows from test16830579085311601108_test_basic.base
20:05:15.347291 [debug] [MainThread]: Acquiring new impala connection "_test"
20:05:15.348330 [debug] [MainThread]: Opening a new connection, currently in state init
20:05:15.349279 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:15.483338 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:15.486660 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:15.967389 [debug] [MainThread]: On _test: Close
20:05:16.209133 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:16.212264 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}
20:05:16.215045 [debug] [MainThread]: Integration Test: test connection "__test" executing: select count(*) as num_rows from test16830579085311601108_test_basic.added
20:05:16.219180 [debug] [MainThread]: Acquiring new impala connection "_test"
20:05:16.222819 [debug] [MainThread]: Opening a new connection, currently in state closed
20:05:16.225908 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:16.367042 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:16.370145 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.01'}
20:05:16.831274 [debug] [MainThread]: On _test: Close
20:05:17.055317 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:17.058400 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}


Invoking dbt with ['run', '--vars', 'seed_name: base']
20:05:17.095925 [debug] [MainThread]: Connection '_test' was properly closed.


============================== 2023-05-02 20:05:17.111628 | 45d39209-e952-42d1-8f1f-86b1dae76657 ==============================
20:05:17.111634 [info ] [MainThread]: Running with dbt=1.3.3
20:05:17.112456 [debug] [MainThread]: running dbt with arguments {'debug': True, 'write_json': True, 'use_colors': True, 'printer_width': 80, 'version_check': True, 'partial_parse': True, 'static_parser': True, 'profiles_dir': '/tmp/pytest-of-vkolanu/pytest-363/profile0', 'send_anonymous_usage_stats': False, 'event_buffer_size': 100000, 'quiet': False, 'no_print': False, 'cache_selected_only': False, 'vars': 'seed_name: base', 'which': 'run', 'rpc_method': 'run', 'indirect_selection': 'eager'}
20:05:17.113237 [debug] [MainThread]: Tracking: do not track
20:05:17.135686 [info ] [MainThread]: Unable to do partial parsing because config vars, config profile, or config target have changed
20:05:17.145478 [debug] [MainThread]: Parsing macros/adapters.sql
20:05:17.204969 [debug] [MainThread]: Parsing macros/catalog.sql
20:05:17.205778 [debug] [MainThread]: Parsing macros/incremental.sql
20:05:17.217137 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:05:17.219706 [debug] [MainThread]: Parsing macros/seed.sql
20:05:17.223089 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:05:17.228335 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:17.229166 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:17.229983 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:17.230854 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:17.232396 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:17.234030 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:17.234877 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:17.235789 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:17.236669 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:17.237764 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:17.249537 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:05:17.250288 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:17.251129 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:17.252075 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:17.252925 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:17.253781 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:05:17.255923 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:05:17.257399 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:05:17.258923 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:05:17.262459 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:05:17.264428 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:05:17.271290 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:05:17.281480 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:05:17.283283 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:05:17.288622 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:05:17.298410 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:05:17.301227 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:05:17.303551 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:17.304690 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:05:17.306010 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:05:17.307241 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:05:17.308362 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:17.309569 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:17.310749 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:05:17.311955 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:17.313968 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:17.315705 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:17.316923 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:17.318246 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:17.319466 [debug] [MainThread]: Parsing macros/utils/except.sql
20:05:17.320524 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:05:17.325717 [debug] [MainThread]: Parsing macros/utils/length.sql
20:05:17.326856 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:05:17.327912 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:17.329773 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:17.331107 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:17.332257 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:17.333706 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:17.335184 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:17.336380 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:05:17.337604 [debug] [MainThread]: Parsing macros/utils/right.sql
20:05:17.338828 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:05:17.340887 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:05:17.343973 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:05:17.349261 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:05:17.355052 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:05:17.366102 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:05:17.373248 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:05:17.374696 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:05:17.384802 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:05:17.387482 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:05:17.389527 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:05:17.393548 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:05:17.394874 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:05:17.398831 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:05:17.401674 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:05:17.409595 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:05:17.420608 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:05:17.422143 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:05:17.430791 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:05:17.432480 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:05:17.435928 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:05:17.437554 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:05:17.442421 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:05:17.454718 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:05:17.459177 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:05:17.463123 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:05:17.469098 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:05:17.470044 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:05:17.471057 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:05:17.472446 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:05:17.473482 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:05:17.710045 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:05:17.714869 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:05:17.757820 [info ] [MainThread]: Found 1 model, 0 tests, 0 snapshots, 0 analyses, 317 macros, 0 operations, 2 seed files, 1 source, 0 exposures, 0 metrics
20:05:17.758716 [info ] [MainThread]: 
20:05:17.759430 [debug] [MainThread]: Acquiring new impala connection "master"
20:05:17.760434 [debug] [ThreadPool]: Acquiring new impala connection "list_schemas"
20:05:17.762483 [debug] [ThreadPool]: Using impala connection "list_schemas"
20:05:17.763011 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:05:17.763656 [debug] [Thread-10 ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:05:17.764508 [debug] [Thread-10 ]: Tracker adapter: Disabling usage tracking due to error.
20:05:17.764834 [debug] [ThreadPool]: On list_schemas: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_schemas"} */
show databases
20:05:17.765430 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:05:17.765933 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:17.903661 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:17.907975 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:18.165618 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:18.168687 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_schemas"} */\nshow databases', 'elapsed_time': '0.40', 'status': 'OK', 'profile_name': 'test'}
20:05:18.171731 [debug] [ThreadPool]: SQL status: OK in 0.4 seconds
20:05:18.534616 [debug] [ThreadPool]: On list_schemas: Close
20:05:18.757781 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:18.760839 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:05:18.768208 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830579085311601108_test_basic"
20:05:18.781189 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:18.784220 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:18.787243 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:18.790240 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic
  
20:05:18.793170 [debug] [ThreadPool]: Opening a new connection, currently in state closed
20:05:18.796053 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:18.926441 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:18.929444 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.01'}
20:05:19.152271 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:19.154995 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:05:19.155524 [debug] [ThreadPool]: SQL status: OK in 0.36 seconds
20:05:19.525522 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:19.527132 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:19.528627 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "added"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:19.530138 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "added"
  
20:05:19.876126 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:19.879298 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "added"\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:19.882312 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:05:20.236362 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:20.239500 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:20.242518 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:20.245534 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.added
  
20:05:20.590171 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:20.590894 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.added\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:20.591581 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:05:20.932969 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:20.936032 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:20.939047 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "base"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:20.942140 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "base"
  
20:05:21.270581 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:21.273605 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "base"\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:05:21.276774 [debug] [ThreadPool]: SQL status: OK in 0.33 seconds
20:05:21.634662 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:21.637870 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:21.641096 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:21.644071 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.base
  
20:05:22.000018 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.003115 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.base\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:22.006285 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:05:22.369151 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.372520 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:22.376203 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.379341 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:22.382455 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: Close
20:05:22.605990 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.609054 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:05:22.613960 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:22.617277 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:05:22.621455 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:05:22.624949 [info ] [MainThread]: 
20:05:22.633054 [debug] [Thread-11 ]: Began running node model.incremental_test_model.incremental_test_model
20:05:22.636508 [info ] [Thread-11 ]: 1 of 1 START sql incremental model test16830579085311601108_test_basic.incremental_test_model  [RUN]
20:05:22.640604 [debug] [Thread-11 ]: Acquiring new impala connection "model.incremental_test_model.incremental_test_model"
20:05:22.644251 [debug] [Thread-11 ]: Began compiling node model.incremental_test_model.incremental_test_model
20:05:22.647451 [debug] [Thread-11 ]: Compiling model.incremental_test_model.incremental_test_model
20:05:22.662453 [debug] [Thread-11 ]: Writing injected SQL for node "model.incremental_test_model.incremental_test_model"
20:05:22.664761 [debug] [Thread-11 ]: finished collecting timing info
20:05:22.666331 [debug] [Thread-11 ]: Began executing node model.incremental_test_model.incremental_test_model
20:05:22.693508 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.694133 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:22.697817 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.698429 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:22.701457 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.702009 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:22.705427 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.705961 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_backup', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:22.710540 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.711079 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'incremental', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': 'append'}
20:05:22.721494 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.722030 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:22.737435 [debug] [Thread-11 ]: Writing runtime sql for node "model.incremental_test_model.incremental_test_model"
20:05:22.738146 [debug] [Thread-11 ]: Impala adapter: NotImplemented: add_begin_query
20:05:22.738699 [debug] [Thread-11 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:05:22.739233 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.739758 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      \n  \n    \n\n  create  table\n    test16830579085311601108_test_basic.incremental_test_model\n    \n      partitioned by (id_partition)\n    \n    \n    \n    \n    \n    \n     \n    \n    \n  as \n    \n select *, id as id_partition from test16830579085311601108_test_basic.base\n \n  ;\n  \n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'model.incremental_test_model.incremental_test_model'}
20:05:22.740277 [debug] [Thread-11 ]: On model.incremental_test_model.incremental_test_model: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */

      
  
    

  create  table
    test16830579085311601108_test_basic.incremental_test_model
    
      partitioned by (id_partition)
    
    
    
    
    
    
     
    
    
  as 
    
 select *, id as id_partition from test16830579085311601108_test_basic.base
 
  ;
  
  
20:05:22.740819 [debug] [Thread-11 ]: Opening a new connection, currently in state closed
20:05:22.741331 [debug] [Thread-11 ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:22.872616 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:22.873749 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:26.722180 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:26.725361 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      \n  \n    \n\n  create  table\n    test16830579085311601108_test_basic.incremental_test_model\n    \n      partitioned by (id_partition)\n    \n    \n    \n    \n    \n    \n     \n    \n    \n  as \n    \n select *, id as id_partition from test16830579085311601108_test_basic.base\n \n  ;\n  \n  ', 'elapsed_time': '3.98', 'status': 'OK', 'profile_name': 'test'}
20:05:26.728461 [debug] [Thread-11 ]: SQL status: OK in 3.98 seconds
20:05:26.743473 [debug] [Thread-11 ]: Impala adapter: NotImplemented: commit
20:05:26.747409 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:26.750393 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:26.752688 [debug] [Thread-11 ]: finished collecting timing info
20:05:26.754780 [debug] [Thread-11 ]: On model.incremental_test_model.incremental_test_model: ROLLBACK
20:05:26.756286 [debug] [Thread-11 ]: Impala adapter: NotImplemented: rollback
20:05:26.757800 [debug] [Thread-11 ]: On model.incremental_test_model.incremental_test_model: Close
20:05:26.992820 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:26.995729 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}
20:05:26.996651 [info ] [Thread-11 ]: 1 of 1 OK created sql incremental model test16830579085311601108_test_basic.incremental_test_model  [OK in 4.36s]
20:05:26.997275 [debug] [Thread-11 ]: Finished running node model.incremental_test_model.incremental_test_model
20:05:26.998666 [debug] [MainThread]: Acquiring new impala connection "master"
20:05:26.999261 [debug] [MainThread]: On master: ROLLBACK
20:05:26.999826 [debug] [MainThread]: Opening a new connection, currently in state init
20:05:27.000391 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:27.133955 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:27.137250 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:27.140234 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:27.143294 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:27.146391 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:05:27.149550 [debug] [MainThread]: On master: ROLLBACK
20:05:27.152512 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:27.155484 [debug] [MainThread]: On master: Close
20:05:27.277086 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:27.280131 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.13'}
20:05:27.284315 [info ] [MainThread]: 
20:05:27.287731 [info ] [MainThread]: Finished running 1 incremental model in 0 hours 0 minutes and 9.52 seconds (9.52s).
20:05:27.290856 [debug] [MainThread]: Connection 'master' was properly closed.
20:05:27.293700 [debug] [MainThread]: Connection 'model.incremental_test_model.incremental_test_model' was properly closed.
20:05:27.298951 [info ] [MainThread]: 
20:05:27.299512 [info ] [MainThread]: Completed successfully
20:05:27.300081 [info ] [MainThread]: 
20:05:27.300605 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
20:05:27.301179 [debug] [MainThread]: Flushing usage events
20:05:27.302040 [debug] [MainThread]: Acquiring new impala connection "_test"
20:05:27.306880 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:27.307412 [debug] [MainThread]: Using impala connection "_test"
20:05:27.307948 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:27.308477 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\n\n      describe extended test16830579085311601108_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:05:27.308996 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */

      describe extended test16830579085311601108_test_basic.base
  
20:05:27.309517 [debug] [MainThread]: Opening a new connection, currently in state init
20:05:27.310022 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:27.441412 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:27.444567 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:27.678764 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:27.681816 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\n\n      describe extended test16830579085311601108_test_basic.base\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:05:27.684832 [debug] [MainThread]: SQL status: OK in 0.37 seconds
20:05:28.053181 [debug] [MainThread]: Using impala connection "_test"
20:05:28.053764 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:28.054302 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\nwith diff_count as (\n    SELECT\n        1 as id,\n        COUNT(*) as num_missing FROM (\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.base EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.base)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.base\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.incremental_test_model\n), row_count_diff as (\n    select\n        1 as id,\n        table_a.num_rows - table_b.num_rows as difference\n    from table_a, table_b\n)\nselect\n    row_count_diff.difference as row_count_difference,\n    diff_count.num_missing as num_mismatched\nfrom row_count_diff\njoin diff_count using (id)', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:05:28.054826 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */
with diff_count as (
    SELECT
        1 as id,
        COUNT(*) as num_missing FROM (
            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.base EXCEPT
             SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model)
             UNION ALL
            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model EXCEPT
             SELECT id, name, some_date FROM test16830579085311601108_test_basic.base)
        ) as a
), table_a as (
    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.base
), table_b as (
    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.incremental_test_model
), row_count_diff as (
    select
        1 as id,
        table_a.num_rows - table_b.num_rows as difference
    from table_a, table_b
)
select
    row_count_diff.difference as row_count_difference,
    diff_count.num_missing as num_mismatched
from row_count_diff
join diff_count using (id)
20:05:28.730686 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:28.733876 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\nwith diff_count as (\n    SELECT\n        1 as id,\n        COUNT(*) as num_missing FROM (\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.base EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.base)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.base\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.incremental_test_model\n), row_count_diff as (\n    select\n        1 as id,\n        table_a.num_rows - table_b.num_rows as difference\n    from table_a, table_b\n)\nselect\n    row_count_diff.difference as row_count_difference,\n    diff_count.num_missing as num_mismatched\nfrom row_count_diff\njoin diff_count using (id)', 'elapsed_time': '0.67', 'status': 'OK', 'profile_name': 'test'}
20:05:28.736893 [debug] [MainThread]: SQL status: OK in 0.67 seconds
20:05:29.083105 [debug] [MainThread]: On _test: ROLLBACK
20:05:29.086219 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:29.089484 [debug] [MainThread]: On _test: Close
20:05:29.332715 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:29.335252 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.25'}


Invoking dbt with ['run', '--vars', 'seed_name: added']
20:05:29.343145 [debug] [MainThread]: Connection '_test' was properly closed.


============================== 2023-05-02 20:05:29.351098 | 45d39209-e952-42d1-8f1f-86b1dae76657 ==============================
20:05:29.351103 [info ] [MainThread]: Running with dbt=1.3.3
20:05:29.351653 [debug] [MainThread]: running dbt with arguments {'debug': True, 'write_json': True, 'use_colors': True, 'printer_width': 80, 'version_check': True, 'partial_parse': True, 'static_parser': True, 'profiles_dir': '/tmp/pytest-of-vkolanu/pytest-363/profile0', 'send_anonymous_usage_stats': False, 'event_buffer_size': 100000, 'quiet': False, 'no_print': False, 'cache_selected_only': False, 'vars': 'seed_name: added', 'which': 'run', 'rpc_method': 'run', 'indirect_selection': 'eager'}
20:05:29.352203 [debug] [MainThread]: Tracking: do not track
20:05:29.364686 [info ] [MainThread]: Unable to do partial parsing because config vars, config profile, or config target have changed
20:05:29.374410 [debug] [MainThread]: Parsing macros/adapters.sql
20:05:29.434385 [debug] [MainThread]: Parsing macros/catalog.sql
20:05:29.435184 [debug] [MainThread]: Parsing macros/incremental.sql
20:05:29.446635 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:05:29.449225 [debug] [MainThread]: Parsing macros/seed.sql
20:05:29.452622 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:05:29.457914 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:29.458742 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:29.459563 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:29.460426 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:29.461878 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:29.463517 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:29.464357 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:29.465278 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:29.466147 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:29.467263 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:29.479058 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:05:29.479811 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:29.480662 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:29.481654 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:29.482498 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:29.483348 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:05:29.485508 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:05:29.486971 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:05:29.488501 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:05:29.492069 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:05:29.494030 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:05:29.500956 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:05:29.511107 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:05:29.512932 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:05:29.518294 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:05:29.528051 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:05:29.530868 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:05:29.533202 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:29.534346 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:05:29.535651 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:05:29.536877 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:05:29.537989 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:29.539194 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:29.540385 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:05:29.541590 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:29.543606 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:29.545333 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:29.546541 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:29.547891 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:29.549135 [debug] [MainThread]: Parsing macros/utils/except.sql
20:05:29.550189 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:05:29.555450 [debug] [MainThread]: Parsing macros/utils/length.sql
20:05:29.556587 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:05:29.557639 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:29.559474 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:29.560796 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:29.561942 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:29.563235 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:29.564738 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:29.565942 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:05:29.567151 [debug] [MainThread]: Parsing macros/utils/right.sql
20:05:29.568383 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:05:29.570424 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:05:29.573473 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:05:29.578710 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:05:29.584518 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:05:29.595613 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:05:29.603021 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:05:29.604500 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:05:29.614613 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:05:29.617265 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:05:29.619282 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:05:29.623300 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:05:29.624636 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:05:29.628631 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:05:29.631414 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:05:29.639347 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:05:29.650518 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:05:29.652042 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:05:29.660807 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:05:29.662455 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:05:29.665907 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:05:29.667546 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:05:29.672349 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:05:29.684647 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:05:29.689069 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:05:29.692971 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:05:29.698881 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:05:29.699835 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:05:29.700905 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:05:29.702242 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:05:29.703263 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:05:29.939942 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:05:29.944836 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:05:30.013967 [info ] [MainThread]: Found 1 model, 0 tests, 0 snapshots, 0 analyses, 317 macros, 0 operations, 2 seed files, 1 source, 0 exposures, 0 metrics
20:05:30.014861 [info ] [MainThread]: 
20:05:30.015575 [debug] [MainThread]: Acquiring new impala connection "master"
20:05:30.016648 [debug] [ThreadPool]: Acquiring new impala connection "list_schemas"
20:05:30.018919 [debug] [ThreadPool]: Using impala connection "list_schemas"
20:05:30.019456 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:05:30.020132 [debug] [Thread-18 ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:05:30.020702 [debug] [ThreadPool]: On list_schemas: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_schemas"} */
show databases
20:05:30.021303 [debug] [Thread-18 ]: Tracker adapter: Disabling usage tracking due to error.
20:05:30.021875 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:05:30.022572 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:30.159632 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:30.161479 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:30.404539 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:30.407589 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_schemas"} */\nshow databases', 'elapsed_time': '0.38', 'status': 'OK', 'profile_name': 'test'}
20:05:30.410785 [debug] [ThreadPool]: SQL status: OK in 0.38 seconds
20:05:30.767984 [debug] [ThreadPool]: On list_schemas: Close
20:05:31.013899 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:31.016940 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.25'}
20:05:31.024144 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830579085311601108_test_basic"
20:05:31.037491 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:31.040587 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:31.043705 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:31.046706 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic
  
20:05:31.049927 [debug] [ThreadPool]: Opening a new connection, currently in state closed
20:05:31.052662 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:31.189045 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:31.192131 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:31.426016 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:31.429089 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic\n  ', 'elapsed_time': '0.38', 'status': 'OK', 'profile_name': 'test'}
20:05:31.432103 [debug] [ThreadPool]: SQL status: OK in 0.38 seconds
20:05:31.787198 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:31.790333 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:31.793328 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "added"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:31.796219 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "added"
  
20:05:32.165695 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:32.168781 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "added"\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:05:32.171742 [debug] [ThreadPool]: SQL status: OK in 0.37 seconds
20:05:32.510907 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:32.514134 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:32.517146 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:32.520062 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.added
  
20:05:32.859308 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:32.862347 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.added\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:32.865289 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:05:33.202236 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:33.205363 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:33.208329 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "base"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:33.211378 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "base"
  
20:05:33.554157 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:33.557305 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "base"\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:33.560385 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:05:33.905889 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:33.909019 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:33.912036 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:33.915133 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.base
  
20:05:34.268959 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:34.272036 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.base\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:34.275050 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:05:34.629494 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:34.632604 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:34.635650 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "incremental_test_model"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:34.638639 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "incremental_test_model"
  
20:05:34.995949 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:34.999112 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "incremental_test_model"\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:35.002258 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:05:35.347639 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:35.350885 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:35.353968 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:35.357238 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.incremental_test_model
  
20:05:35.721983 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:35.725119 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:05:35.728075 [debug] [ThreadPool]: SQL status: OK in 0.36 seconds
20:05:36.076476 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.079605 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.082793 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.085801 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.088903 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.091830 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.094952 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: Close
20:05:36.323016 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.326045 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:05:36.327444 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:36.327975 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:05:36.328702 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:05:36.329231 [info ] [MainThread]: 
20:05:36.330945 [debug] [Thread-19 ]: Began running node model.incremental_test_model.incremental_test_model
20:05:36.331591 [info ] [Thread-19 ]: 1 of 1 START sql incremental model test16830579085311601108_test_basic.incremental_test_model  [RUN]
20:05:36.332346 [debug] [Thread-19 ]: Acquiring new impala connection "model.incremental_test_model.incremental_test_model"
20:05:36.333043 [debug] [Thread-19 ]: Began compiling node model.incremental_test_model.incremental_test_model
20:05:36.333625 [debug] [Thread-19 ]: Compiling model.incremental_test_model.incremental_test_model
20:05:36.337075 [debug] [Thread-19 ]: Writing injected SQL for node "model.incremental_test_model.incremental_test_model"
20:05:36.337776 [debug] [Thread-19 ]: finished collecting timing info
20:05:36.338349 [debug] [Thread-19 ]: Began executing node model.incremental_test_model.incremental_test_model
20:05:36.340151 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.340714 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.341941 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.342509 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.343738 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.344285 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.345501 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.346056 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_backup', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.346870 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.347430 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'incremental', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': 'append'}
20:05:36.349638 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.350186 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:36.351400 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:05:36.351970 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.352541 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n    \n  \n    \n\n  create  table\n    test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n    \n      partitioned by (id_partition)\n    \n    \n    \n    \n    \n    \n     \n    \n    \n  as \n    \n select *, id as id_partition from test16830579085311601108_test_basic.added\n \n where id > (select max(id) from test16830579085311601108_test_basic.incremental_test_model)\n \n  ;\n  \n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'model.incremental_test_model.incremental_test_model'}
20:05:36.353104 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */

    
  
    

  create  table
    test16830579085311601108_test_basic.incremental_test_model__dbt_tmp
    
      partitioned by (id_partition)
    
    
    
    
    
    
     
    
    
  as 
    
 select *, id as id_partition from test16830579085311601108_test_basic.added
 
 where id > (select max(id) from test16830579085311601108_test_basic.incremental_test_model)
 
  ;
  
  
20:05:36.353674 [debug] [Thread-19 ]: Opening a new connection, currently in state closed
20:05:36.354231 [debug] [Thread-19 ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:36.490059 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:36.494084 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:42.533278 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:42.536430 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n    \n  \n    \n\n  create  table\n    test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n    \n      partitioned by (id_partition)\n    \n    \n    \n    \n    \n    \n     \n    \n    \n  as \n    \n select *, id as id_partition from test16830579085311601108_test_basic.added\n \n where id > (select max(id) from test16830579085311601108_test_basic.incremental_test_model)\n \n  ;\n  \n  ', 'elapsed_time': '6.18', 'status': 'OK', 'profile_name': 'test'}
20:05:42.539604 [debug] [Thread-19 ]: SQL status: OK in 6.18 seconds
20:05:42.900188 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:42.903595 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:42.906949 [debug] [Thread-19 ]: Impala adapter: NotImplemented: add_begin_query
20:05:42.909976 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:05:42.913101 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:42.916075 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'model.incremental_test_model.incremental_test_model'}
20:05:42.918739 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */

      describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp
  
20:05:43.251103 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:43.254243 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:05:43.257287 [debug] [Thread-19 ]: SQL status: OK in 0.33 seconds
20:05:43.634501 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:43.637565 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:43.640848 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:05:43.643972 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:43.647041 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'model.incremental_test_model.incremental_test_model'}
20:05:43.650076 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */

      describe extended test16830579085311601108_test_basic.incremental_test_model
  
20:05:43.993043 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:43.996152 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:43.999176 [debug] [Thread-19 ]: SQL status: OK in 0.34 seconds
20:05:44.597667 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:44.598197 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:44.598757 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:05:44.599287 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:44.599795 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'model.incremental_test_model.incremental_test_model'}
20:05:44.600295 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */

      describe extended test16830579085311601108_test_basic.incremental_test_model
  
20:05:44.983820 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:44.986979 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.38', 'status': 'OK', 'profile_name': 'test'}
20:05:44.989935 [debug] [Thread-19 ]: SQL status: OK in 0.38 seconds
20:05:45.384828 [debug] [Thread-19 ]: Writing runtime sql for node "model.incremental_test_model.incremental_test_model"
20:05:45.386156 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:05:45.387070 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:45.387933 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      \n        insert into test16830579085311601108_test_basic.incremental_test_model (id, name, some_date) partition(id_partition)\n        (\n            select id, name, some_date, id_partition\n            from test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n        )\n    \n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'model_name': 'model.incremental_test_model.incremental_test_model'}
20:05:45.388800 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */

      
        insert into test16830579085311601108_test_basic.incremental_test_model (id, name, some_date) partition(id_partition)
        (
            select id, name, some_date, id_partition
            from test16830579085311601108_test_basic.incremental_test_model__dbt_tmp
        )
    
  
20:05:46.980487 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:46.983638 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "node_id": "model.incremental_test_model.incremental_test_model"} */\n\n      \n        insert into test16830579085311601108_test_basic.incremental_test_model (id, name, some_date) partition(id_partition)\n        (\n            select id, name, some_date, id_partition\n            from test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n        )\n    \n  ', 'elapsed_time': '1.59', 'status': 'OK', 'profile_name': 'test'}
20:05:46.986686 [debug] [Thread-19 ]: SQL status: OK in 1.59 seconds
20:05:46.999233 [debug] [Thread-19 ]: Impala adapter: NotImplemented: commit
20:05:47.003130 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:47.006112 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:47.009415 [debug] [Thread-19 ]: finished collecting timing info
20:05:47.011955 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: ROLLBACK
20:05:47.014095 [debug] [Thread-19 ]: Impala adapter: NotImplemented: rollback
20:05:47.015903 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: Close
20:05:47.242053 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:47.244518 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:05:47.245442 [info ] [Thread-19 ]: 1 of 1 OK created sql incremental model test16830579085311601108_test_basic.incremental_test_model  [OK in 10.91s]
20:05:47.246072 [debug] [Thread-19 ]: Finished running node model.incremental_test_model.incremental_test_model
20:05:47.247323 [debug] [MainThread]: Acquiring new impala connection "master"
20:05:47.247863 [debug] [MainThread]: On master: ROLLBACK
20:05:47.248422 [debug] [MainThread]: Opening a new connection, currently in state init
20:05:47.248989 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:47.376711 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:47.379699 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:47.382675 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:47.385616 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:47.388527 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:05:47.391508 [debug] [MainThread]: On master: ROLLBACK
20:05:47.394429 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:47.397300 [debug] [MainThread]: On master: Close
20:05:47.505961 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:47.509059 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.11'}
20:05:47.513299 [info ] [MainThread]: 
20:05:47.516273 [info ] [MainThread]: Finished running 1 incremental model in 0 hours 0 minutes and 17.50 seconds (17.50s).
20:05:47.519342 [debug] [MainThread]: Connection 'master' was properly closed.
20:05:47.522328 [debug] [MainThread]: Connection 'model.incremental_test_model.incremental_test_model' was properly closed.
20:05:47.543693 [info ] [MainThread]: 
20:05:47.545341 [info ] [MainThread]: Completed successfully
20:05:47.546620 [info ] [MainThread]: 
20:05:47.547833 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
20:05:47.549168 [debug] [MainThread]: Flushing usage events
20:05:47.550902 [debug] [MainThread]: Acquiring new impala connection "_test"
20:05:47.555175 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:05:47.555755 [debug] [MainThread]: Using impala connection "_test"
20:05:47.556285 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:47.556810 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\n\n      describe extended test16830579085311601108_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:05:47.557322 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */

      describe extended test16830579085311601108_test_basic.added
  
20:05:47.557836 [debug] [MainThread]: Opening a new connection, currently in state init
20:05:47.558354 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:47.677782 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:47.678654 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:47.917985 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:47.921171 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\n\n      describe extended test16830579085311601108_test_basic.added\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:05:47.924136 [debug] [MainThread]: SQL status: OK in 0.36 seconds
20:05:48.302153 [debug] [MainThread]: Using impala connection "_test"
20:05:48.305345 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:48.308462 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\nwith diff_count as (\n    SELECT\n        1 as id,\n        COUNT(*) as num_missing FROM (\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.added EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.added)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.added\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.incremental_test_model\n), row_count_diff as (\n    select\n        1 as id,\n        table_a.num_rows - table_b.num_rows as difference\n    from table_a, table_b\n)\nselect\n    row_count_diff.difference as row_count_difference,\n    diff_count.num_missing as num_mismatched\nfrom row_count_diff\njoin diff_count using (id)', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:05:48.311661 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */
with diff_count as (
    SELECT
        1 as id,
        COUNT(*) as num_missing FROM (
            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.added EXCEPT
             SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model)
             UNION ALL
            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model EXCEPT
             SELECT id, name, some_date FROM test16830579085311601108_test_basic.added)
        ) as a
), table_a as (
    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.added
), table_b as (
    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.incremental_test_model
), row_count_diff as (
    select
        1 as id,
        table_a.num_rows - table_b.num_rows as difference
    from table_a, table_b
)
select
    row_count_diff.difference as row_count_difference,
    diff_count.num_missing as num_mismatched
from row_count_diff
join diff_count using (id)
20:05:49.145567 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:49.148411 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\nwith diff_count as (\n    SELECT\n        1 as id,\n        COUNT(*) as num_missing FROM (\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.added EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830579085311601108_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830579085311601108_test_basic.added)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.added\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830579085311601108_test_basic.incremental_test_model\n), row_count_diff as (\n    select\n        1 as id,\n        table_a.num_rows - table_b.num_rows as difference\n    from table_a, table_b\n)\nselect\n    row_count_diff.difference as row_count_difference,\n    diff_count.num_missing as num_mismatched\nfrom row_count_diff\njoin diff_count using (id)', 'elapsed_time': '0.83', 'status': 'OK', 'profile_name': 'test'}
20:05:49.148959 [debug] [MainThread]: SQL status: OK in 0.83 seconds
20:05:49.499938 [debug] [MainThread]: On _test: ROLLBACK
20:05:49.503043 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:05:49.506046 [debug] [MainThread]: On _test: Close
20:05:49.754974 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:49.758095 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.25'}


Invoking dbt with ['docs', 'generate']
20:05:49.792995 [debug] [MainThread]: Connection '_test' was properly closed.


============================== 2023-05-02 20:05:49.807605 | 45d39209-e952-42d1-8f1f-86b1dae76657 ==============================
20:05:49.807611 [info ] [MainThread]: Running with dbt=1.3.3
20:05:49.808423 [debug] [MainThread]: running dbt with arguments {'debug': True, 'write_json': True, 'use_colors': True, 'printer_width': 80, 'version_check': True, 'partial_parse': True, 'static_parser': True, 'profiles_dir': '/tmp/pytest-of-vkolanu/pytest-363/profile0', 'send_anonymous_usage_stats': False, 'event_buffer_size': 100000, 'quiet': False, 'no_print': False, 'cache_selected_only': False, 'compile': True, 'which': 'generate', 'rpc_method': 'docs.generate', 'indirect_selection': 'eager'}
20:05:49.809178 [debug] [MainThread]: Tracking: do not track
20:05:49.824381 [info ] [MainThread]: Unable to do partial parsing because config vars, config profile, or config target have changed
20:05:49.834108 [debug] [MainThread]: Parsing macros/adapters.sql
20:05:49.893192 [debug] [MainThread]: Parsing macros/catalog.sql
20:05:49.893985 [debug] [MainThread]: Parsing macros/incremental.sql
20:05:49.905376 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:05:49.907947 [debug] [MainThread]: Parsing macros/seed.sql
20:05:49.911281 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:05:49.916446 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:49.917284 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:49.918110 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:49.918977 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:49.920422 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:49.922048 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:49.922883 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:49.923782 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:49.924654 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:49.925749 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:49.937405 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:05:49.938199 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:49.939035 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:49.939951 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:49.940824 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:49.941651 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:05:49.943944 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:05:49.945423 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:05:49.946947 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:05:49.950512 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:05:49.952450 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:05:49.959276 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:05:49.969344 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:05:49.971108 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:05:49.976390 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:05:49.986033 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:05:49.988831 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:05:49.991079 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:05:49.992225 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:05:49.993564 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:05:49.994766 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:05:49.995852 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:05:49.997092 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:05:49.998253 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:05:49.999425 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:05:50.001413 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:05:50.003086 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:05:50.004272 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:05:50.005707 [debug] [MainThread]: Parsing macros/utils/position.sql
20:05:50.006907 [debug] [MainThread]: Parsing macros/utils/except.sql
20:05:50.007935 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:05:50.013157 [debug] [MainThread]: Parsing macros/utils/length.sql
20:05:50.014256 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:05:50.015280 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:05:50.017143 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:05:50.018473 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:05:50.019598 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:05:50.020920 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:05:50.022374 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:05:50.023553 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:05:50.024870 [debug] [MainThread]: Parsing macros/utils/right.sql
20:05:50.026069 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:05:50.028055 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:05:50.031103 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:05:50.036266 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:05:50.042057 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:05:50.053265 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:05:50.060382 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:05:50.061844 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:05:50.071912 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:05:50.074519 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:05:50.076510 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:05:50.080672 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:05:50.081974 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:05:50.085823 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:05:50.088618 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:05:50.096412 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:05:50.107266 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:05:50.108814 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:05:50.117424 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:05:50.119146 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:05:50.122557 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:05:50.124138 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:05:50.128883 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:05:50.140920 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:05:50.145426 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:05:50.149356 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:05:50.155366 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:05:50.156279 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:05:50.157357 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:05:50.158706 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:05:50.159727 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:05:50.393069 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:05:50.397705 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:05:50.439468 [info ] [MainThread]: Found 1 model, 0 tests, 0 snapshots, 0 analyses, 317 macros, 0 operations, 2 seed files, 1 source, 0 exposures, 0 metrics
20:05:50.440441 [info ] [MainThread]: 
20:05:50.441170 [debug] [MainThread]: Acquiring new impala connection "master"
20:05:50.442191 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830579085311601108_test_basic"
20:05:50.444720 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:50.445262 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:05:50.445956 [debug] [Thread-26 ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:05:50.447020 [debug] [Thread-26 ]: Tracker adapter: Disabling usage tracking due to error.
20:05:50.447306 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic
  
20:05:50.447887 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:05:50.448461 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:50.565462 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:50.565998 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:50.792178 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:50.795437 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:50.798609 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:05:51.146905 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:51.147456 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:51.147977 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "added"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:51.148497 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "added"
  
20:05:51.507094 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:51.510297 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "added"\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:05:51.513379 [debug] [ThreadPool]: SQL status: OK in 0.36 seconds
20:05:51.860509 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:51.863646 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:51.866645 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:51.869579 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.added
  
20:05:52.220305 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:52.224949 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.added\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:52.228171 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:05:52.594050 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:52.597519 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:52.600679 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "base"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:52.603755 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "base"
  
20:05:52.959806 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:52.962931 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "base"\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:52.965959 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:05:53.319114 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:53.322284 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:53.325321 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:53.328355 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.base
  
20:05:53.681899 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:53.685046 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.base\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:53.688056 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:05:54.041426 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:54.044570 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:54.047613 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "incremental_test_model"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:54.050564 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "incremental_test_model"
  
20:05:54.398525 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:54.401796 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "incremental_test_model"\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:54.404847 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:05:54.740966 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:54.744093 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:54.747073 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:54.750055 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.incremental_test_model
  
20:05:55.084176 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:55.087299 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:05:55.090659 [debug] [ThreadPool]: SQL status: OK in 0.33 seconds
20:05:55.478332 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:55.478902 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:55.479440 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "incremental_test_model__dbt_tmp"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:55.479974 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    show tables in test16830579085311601108_test_basic like "incremental_test_model__dbt_tmp"
  
20:05:55.814037 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:55.817137 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    show tables in test16830579085311601108_test_basic like "incremental_test_model__dbt_tmp"\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:05:55.820140 [debug] [ThreadPool]: SQL status: OK in 0.33 seconds
20:05:56.172056 [debug] [ThreadPool]: Using impala connection "list_None_test16830579085311601108_test_basic"
20:05:56.175212 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:56.178252 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830579085311601108_test_basic'}
20:05:56.181593 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */

    describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp
  
20:05:56.519011 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:56.522268 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830579085311601108_test_basic"} */\n\n    describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:05:56.525778 [debug] [ThreadPool]: SQL status: OK in 0.33 seconds
20:05:56.878215 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:56.881369 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:56.884494 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:56.887552 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:56.890659 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:56.893677 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:56.896723 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:56.899605 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:56.902045 [debug] [ThreadPool]: On list_None_test16830579085311601108_test_basic: Close
20:05:57.129138 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:57.132199 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:05:57.138221 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:05:57.141415 [info ] [MainThread]: 
20:05:57.150930 [debug] [Thread-27 ]: Began running node model.incremental_test_model.incremental_test_model
20:05:57.157059 [debug] [Thread-28 ]: Began running node seed.incremental_test_model.added
20:05:57.161568 [debug] [Thread-27 ]: Acquiring new impala connection "model.incremental_test_model.incremental_test_model"
20:05:57.165360 [debug] [Thread-29 ]: Began running node seed.incremental_test_model.base
20:05:57.170173 [debug] [Thread-28 ]: Acquiring new impala connection "seed.incremental_test_model.added"
20:05:57.173623 [debug] [Thread-27 ]: Began compiling node model.incremental_test_model.incremental_test_model
20:05:57.176911 [debug] [Thread-29 ]: Acquiring new impala connection "seed.incremental_test_model.base"
20:05:57.180476 [debug] [Thread-28 ]: Began compiling node seed.incremental_test_model.added
20:05:57.183821 [debug] [Thread-27 ]: Compiling model.incremental_test_model.incremental_test_model
20:05:57.190716 [debug] [Thread-29 ]: Began compiling node seed.incremental_test_model.base
20:05:57.199203 [debug] [Thread-28 ]: Compiling seed.incremental_test_model.added
20:05:57.214917 [debug] [Thread-29 ]: Compiling seed.incremental_test_model.base
20:05:57.221884 [debug] [Thread-28 ]: Writing injected SQL for node "seed.incremental_test_model.added"
20:05:57.228105 [debug] [Thread-27 ]: Writing injected SQL for node "model.incremental_test_model.incremental_test_model"
20:05:57.230202 [debug] [Thread-28 ]: finished collecting timing info
20:05:57.233635 [debug] [Thread-29 ]: Writing injected SQL for node "seed.incremental_test_model.base"
20:05:57.238919 [debug] [Thread-28 ]: Began executing node seed.incremental_test_model.added
20:05:57.240827 [debug] [Thread-29 ]: finished collecting timing info
20:05:57.246189 [debug] [Thread-27 ]: finished collecting timing info
20:05:57.248009 [debug] [Thread-28 ]: finished collecting timing info
20:05:57.249747 [debug] [Thread-29 ]: Began executing node seed.incremental_test_model.base
20:05:57.258391 [debug] [Thread-27 ]: Began executing node model.incremental_test_model.incremental_test_model
20:05:57.260292 [debug] [Thread-28 ]: Finished running node seed.incremental_test_model.added
20:05:57.263694 [debug] [Thread-29 ]: finished collecting timing info
20:05:57.269381 [debug] [Thread-27 ]: finished collecting timing info
20:05:57.273872 [debug] [Thread-29 ]: Finished running node seed.incremental_test_model.base
20:05:57.276034 [debug] [Thread-27 ]: Finished running node model.incremental_test_model.incremental_test_model
20:05:57.281534 [debug] [MainThread]: Connection 'master' was properly closed.
20:05:57.284567 [debug] [MainThread]: Connection 'model.incremental_test_model.incremental_test_model' was properly closed.
20:05:57.287579 [debug] [MainThread]: Connection 'seed.incremental_test_model.added' was properly closed.
20:05:57.290630 [debug] [MainThread]: Connection 'seed.incremental_test_model.base' was properly closed.
20:05:57.315240 [info ] [MainThread]: Done.
20:05:57.320482 [debug] [MainThread]: Acquiring new impala connection "generate_catalog"
20:05:57.321953 [info ] [MainThread]: Building catalog
20:05:57.324823 [debug] [ThreadPool]: Acquiring new impala connection "test16830579085311601108_test_basic"
20:05:57.329045 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:57.329565 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:57.330124 [debug] [ThreadPool]: Impala adapter: NotImplemented: add_begin_query
20:05:57.330632 [debug] [ThreadPool]: Using impala connection "test16830579085311601108_test_basic"
20:05:57.331151 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:57.331662 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830579085311601108_test_basic'}
20:05:57.332166 [debug] [ThreadPool]: On test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */

      describe extended test16830579085311601108_test_basic.added
  
20:05:57.332681 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:05:57.333185 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:05:57.463759 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:57.465149 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:05:57.707179 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:57.710346 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.added\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:05:57.713430 [debug] [ThreadPool]: SQL status: OK in 0.37 seconds
20:05:58.075382 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:58.078468 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:58.081822 [debug] [ThreadPool]: Using impala connection "test16830579085311601108_test_basic"
20:05:58.084997 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:58.089984 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830579085311601108_test_basic'}
20:05:58.091939 [debug] [ThreadPool]: On test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */

      describe extended test16830579085311601108_test_basic.base
  
20:05:58.430372 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:58.433444 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.base\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:05:58.436428 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:05:58.791717 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:58.794842 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:58.798319 [debug] [ThreadPool]: Using impala connection "test16830579085311601108_test_basic"
20:05:58.801528 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:58.804539 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830579085311601108_test_basic'}
20:05:58.806575 [debug] [ThreadPool]: On test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */

      describe extended test16830579085311601108_test_basic.incremental_test_model
  
20:05:59.156865 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:59.159993 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:59.163054 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:05:59.518812 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:59.521957 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830579085311601108_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:05:59.525194 [debug] [ThreadPool]: Using impala connection "test16830579085311601108_test_basic"
20:05:59.528345 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:59.531346 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830579085311601108_test_basic'}
20:05:59.534106 [debug] [ThreadPool]: On test16830579085311601108_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */

      describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp
  
20:05:59.885352 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:05:59.888540 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830579085311601108_test_basic"} */\n\n      describe extended test16830579085311601108_test_basic.incremental_test_model__dbt_tmp\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:05:59.891606 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:06:00.253931 [debug] [ThreadPool]: On test16830579085311601108_test_basic: ROLLBACK
20:06:00.257033 [debug] [ThreadPool]: Impala adapter: NotImplemented: rollback
20:06:00.260079 [debug] [ThreadPool]: On test16830579085311601108_test_basic: Close
20:06:00.499994 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:06:00.503076 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.25'}
20:06:00.515541 [info ] [MainThread]: Catalog written to /tmp/pytest-of-vkolanu/pytest-363/project0/target/catalog.json
20:06:00.516540 [debug] [MainThread]: Flushing usage events
20:06:00.517503 [debug] [MainThread]: Connection 'generate_catalog' was properly closed.
20:06:00.518060 [debug] [MainThread]: Connection 'test16830579085311601108_test_basic' was properly closed.
PASSED20:06:00.519440 [debug] [MainThread]: Acquiring new impala connection "_test"
20:06:00.520033 [debug] [MainThread]: Dropping schema "_ReferenceKey(database=None, schema='test16830579085311601108_test_basic', identifier=None)".
20:06:00.523840 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:06:00.524370 [debug] [MainThread]: Using impala connection "_test"
20:06:00.524915 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:06:00.525437 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\ndrop schema if exists test16830579085311601108_test_basic cascade', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:06:00.525946 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */
drop schema if exists test16830579085311601108_test_basic cascade
20:06:00.526459 [debug] [MainThread]: Opening a new connection, currently in state init
20:06:00.526965 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:06:00.659668 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:06:00.662694 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:06:02.376508 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:06:02.379187 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '/* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */\ndrop schema if exists test16830579085311601108_test_basic cascade', 'elapsed_time': '1.85', 'status': 'OK', 'profile_name': 'test'}
20:06:02.379706 [debug] [MainThread]: SQL status: OK in 1.85 seconds
20:06:02.380713 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:06:02.381334 [debug] [MainThread]: On _test: ROLLBACK
20:06:02.381855 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:06:02.382381 [debug] [MainThread]: On _test: Close
20:06:02.645595 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:06:02.648676 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.26'}
20:06:02.653840 [debug] [MainThread]: Connection '_test' was properly closed.


=============================== warnings summary ===============================
tests/functional/adapter/test_basic.py: 21 warnings
  /home/vkolanu/dbt_impala/lib/python3.8/site-packages/impyla-0.18.0-py3.8.egg/impala/_thrift_gen/TCLIService/TCLIService.py:1415: DeprecationWarning: PY_SSIZE_T_CLEAN will be required for '#' formats

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
======================= 1 passed, 21 warnings in 54.93s ========================