insert overwrite

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::TestInsertoverwriteImpala::test_incremental 
=== Test project_root: /tmp/pytest-of-vkolanu/pytest-364/project0
20:09:23.968288 [info ] [MainThread]: Partial parse save file not found. Starting full parse.
20:09:24.295498 [debug] [MainThread]: Acquiring new impala connection "_test"
20:09:24.296062 [debug] [MainThread]: Acquiring new impala connection "_test"
20:09:24.296680 [debug] [MainThread]: Creating schema "_ReferenceKey(database=None, schema='test16830581647929404551_test_basic', identifier=None)"
20:09:24.304589 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:09:24.305124 [debug] [MainThread]: Using impala connection "_test"
20:09:24.305652 [debug] [MainThread]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:09:24.306417 [debug] [MainThread]: On _test: create schema if not exists test16830581647929404551_test_basic
  
20:09:24.306945 [debug] [MainThread]: Opening a new connection, currently in state init
20:09:24.307462 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:24.308162 [debug] [Thread-1  ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:09:24.308698 [debug] [Thread-1  ]: Tracker adapter: Disabling usage tracking due to error.
20:09:25.021821 [debug] [MainThread]: Impala adapter: IMPALA VERSION ImpalaConnectionManager.impala_version
20:09:25.024987 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:25.028021 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:25.865864 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:25.869126 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': 'create schema if not exists test16830581647929404551_test_basic\n  ', 'elapsed_time': '1.56', 'status': 'OK', 'profile_name': 'test'}
20:09:25.872176 [debug] [MainThread]: SQL status: OK in 1.56 seconds
20:09:25.878034 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:09:25.881597 [debug] [MainThread]: On _test: ROLLBACK
20:09:25.885024 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:09:25.888023 [debug] [MainThread]: On _test: Close
20:09:26.125878 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:26.129014 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}


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


============================== 2023-05-02 20:09:26.182128 | 2bdbb115-28e4-433b-9344-746adaefee06 ==============================
20:09:26.182136 [info ] [MainThread]: Running with dbt=1.3.3
20:09:26.183069 [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-364/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:09:26.183847 [debug] [MainThread]: Tracking: do not track
20:09:26.193768 [info ] [MainThread]: Partial parse save file not found. Starting full parse.
20:09:26.204846 [debug] [MainThread]: Parsing macros/adapters.sql
20:09:26.264580 [debug] [MainThread]: Parsing macros/catalog.sql
20:09:26.265396 [debug] [MainThread]: Parsing macros/incremental.sql
20:09:26.276812 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:09:26.279394 [debug] [MainThread]: Parsing macros/seed.sql
20:09:26.282795 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:09:26.288114 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:09:26.288963 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:09:26.289788 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:09:26.290666 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:09:26.292117 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:09:26.293742 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:09:26.294595 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:09:26.295524 [debug] [MainThread]: Parsing macros/utils/position.sql
20:09:26.296489 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:09:26.297634 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:09:26.309927 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:09:26.310695 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:09:26.311566 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:09:26.312533 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:09:26.313376 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:09:26.314233 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:09:26.316375 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:09:26.317895 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:09:26.319424 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:09:26.323046 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:09:26.325037 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:09:26.332018 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:09:26.342348 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:09:26.344224 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:09:26.349651 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:09:26.359857 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:09:26.362777 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:09:26.365154 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:09:26.366284 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:09:26.367607 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:09:26.368920 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:09:26.370041 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:09:26.371264 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:09:26.372533 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:09:26.373741 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:09:26.375720 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:09:26.377512 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:09:26.378715 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:09:26.380038 [debug] [MainThread]: Parsing macros/utils/position.sql
20:09:26.381385 [debug] [MainThread]: Parsing macros/utils/except.sql
20:09:26.382672 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:09:26.387943 [debug] [MainThread]: Parsing macros/utils/length.sql
20:09:26.389124 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:09:26.390184 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:09:26.392042 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:09:26.393425 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:09:26.394563 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:09:26.395859 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:09:26.397394 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:09:26.398615 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:09:26.399821 [debug] [MainThread]: Parsing macros/utils/right.sql
20:09:26.401127 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:09:26.403252 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:09:26.406371 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:09:26.411661 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:09:26.417600 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:09:26.428910 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:09:26.436206 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:09:26.437694 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:09:26.447971 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:09:26.450648 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:09:26.452759 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:09:26.456895 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:09:26.458244 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:09:26.462326 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:09:26.465230 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:09:26.473423 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:09:26.484707 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:09:26.486291 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:09:26.495117 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:09:26.496844 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:09:26.500388 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:09:26.502047 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:09:26.507005 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:09:26.519457 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:09:26.523971 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:09:26.527962 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:09:26.533998 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:09:26.534932 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:09:26.535972 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:09:26.537380 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:09:26.538422 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:09:26.783131 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:09:26.796289 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:09:26.887366 [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:09:26.888590 [info ] [MainThread]: 
20:09:26.889358 [debug] [MainThread]: Acquiring new impala connection "master"
20:09:26.890403 [debug] [ThreadPool]: Acquiring new impala connection "list_schemas"
20:09:26.894734 [debug] [ThreadPool]: Using impala connection "list_schemas"
20:09:26.895289 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:09:26.896344 [debug] [Thread-2  ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:09:26.896925 [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:09:26.897530 [debug] [Thread-2  ]: Tracker adapter: Disabling usage tracking due to error.
20:09:26.897854 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:09:26.898399 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:27.035669 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:27.038995 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:27.278257 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:27.278809 [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:09:27.279345 [debug] [ThreadPool]: SQL status: OK in 0.38 seconds
20:09:27.635245 [debug] [ThreadPool]: On list_schemas: Close
20:09:27.864819 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:27.867876 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:09:27.875294 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830581647929404551_test_basic"
20:09:27.912882 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:27.914504 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:27.916023 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:27.917267 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic
  
20:09:27.918489 [debug] [ThreadPool]: Opening a new connection, currently in state closed
20:09:27.919712 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:28.054017 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:28.054632 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:28.290675 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:28.293864 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:09:28.296983 [debug] [ThreadPool]: SQL status: OK in 0.37 seconds
20:09:28.527019 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: Close
20:09:28.745823 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:28.749199 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:09:28.753977 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:09:28.757160 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:09:28.761288 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:09:28.764441 [info ] [MainThread]: 
20:09:28.778665 [debug] [Thread-3  ]: Began running node seed.incremental_test_model.added
20:09:28.781350 [debug] [Thread-4  ]: Began running node seed.incremental_test_model.base
20:09:28.783979 [info ] [Thread-3  ]: 1 of 2 START seed file test16830581647929404551_test_basic.added ............... [RUN]
20:09:28.787071 [info ] [Thread-4  ]: 2 of 2 START seed file test16830581647929404551_test_basic.base ................ [RUN]
20:09:28.788187 [debug] [Thread-3  ]: Acquiring new impala connection "seed.incremental_test_model.added"
20:09:28.793021 [debug] [Thread-4  ]: Acquiring new impala connection "seed.incremental_test_model.base"
20:09:28.795568 [debug] [Thread-3  ]: Began compiling node seed.incremental_test_model.added
20:09:28.796792 [debug] [Thread-4  ]: Began compiling node seed.incremental_test_model.base
20:09:28.800480 [debug] [Thread-3  ]: finished collecting timing info
20:09:28.801625 [debug] [Thread-4  ]: finished collecting timing info
20:09:28.805249 [debug] [Thread-3  ]: Began executing node seed.incremental_test_model.added
20:09:28.816687 [debug] [Thread-4  ]: Began executing node seed.incremental_test_model.base
20:09:28.944485 [debug] [Thread-3  ]: Impala adapter: NotImplemented: add_begin_query
20:09:28.945832 [debug] [Thread-4  ]: Impala adapter: NotImplemented: add_begin_query
20:09:28.947265 [debug] [Thread-3  ]: Using impala connection "seed.incremental_test_model.added"
20:09:28.947958 [debug] [Thread-4  ]: Using impala connection "seed.incremental_test_model.base"
20:09:28.950168 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:28.951528 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:28.952907 [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 test16830581647929404551_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:09:28.953551 [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 test16830581647929404551_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:09:28.955698 [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 test16830581647929404551_test_basic.added (id integer,name string,some_date timestamp)
  
20:09:28.956390 [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 test16830581647929404551_test_basic.base (id integer,name string,some_date timestamp)
  
20:09:28.958483 [debug] [Thread-3  ]: Opening a new connection, currently in state closed
20:09:28.959117 [debug] [Thread-4  ]: Opening a new connection, currently in state init
20:09:28.961210 [debug] [Thread-3  ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:28.961847 [debug] [Thread-4  ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:29.085352 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:29.085890 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:29.095091 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:29.095645 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:29.659049 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:29.659856 [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 test16830581647929404551_test_basic.base (id integer,name string,some_date timestamp)\n  ', 'elapsed_time': '0.70', 'status': 'OK', 'profile_name': 'test'}
20:09:29.660655 [debug] [Thread-4  ]: SQL status: OK in 0.7 seconds
20:09:29.692094 [debug] [Thread-4  ]: Using impala connection "seed.incremental_test_model.base"
20:09:29.692719 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:29.693271 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '\n          insert into test16830581647929404551_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:09:29.693809 [debug] [Thread-4  ]: On seed.incremental_test_model.base: 
          insert into test16830581647929404551_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:09:30.004016 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.004563 [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 test16830581647929404551_test_basic.added (id integer,name string,some_date timestamp)\n  ', 'elapsed_time': '1.05', 'status': 'OK', 'profile_name': 'test'}
20:09:30.005087 [debug] [Thread-3  ]: SQL status: OK in 1.05 seconds
20:09:30.040887 [debug] [Thread-3  ]: Using impala connection "seed.incremental_test_model.added"
20:09:30.041435 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.041981 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'start_query', 'sql': '\n          insert into test16830581647929404551_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:09:30.042500 [debug] [Thread-3  ]: On seed.incremental_test_model.added: 
          insert into test16830581647929404551_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:09:30.571487 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.572042 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '\n          insert into test16830581647929404551_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.88', 'status': 'OK', 'profile_name': 'test'}
20:09:30.572610 [debug] [Thread-4  ]: SQL status: OK in 0.88 seconds
20:09:30.577637 [debug] [Thread-4  ]: Writing runtime SQL for node "seed.incremental_test_model.base"
20:09:30.578928 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.579463 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:30.593472 [debug] [Thread-4  ]: Impala adapter: NotImplemented: commit
20:09:30.594155 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.594685 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:30.595291 [debug] [Thread-4  ]: finished collecting timing info
20:09:30.595912 [debug] [Thread-4  ]: On seed.incremental_test_model.base: ROLLBACK
20:09:30.596445 [debug] [Thread-4  ]: Impala adapter: NotImplemented: rollback
20:09:30.596967 [debug] [Thread-4  ]: On seed.incremental_test_model.base: Close
20:09:30.818943 [debug] [Thread-4  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.822686 [debug] [Thread-4  ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:09:30.827248 [info ] [Thread-4  ]: 2 of 2 OK loaded seed file test16830581647929404551_test_basic.base ............ [INSERT 10 in 2.04s]
20:09:30.830986 [debug] [Thread-4  ]: Finished running node seed.incremental_test_model.base
20:09:30.847767 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.850909 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'end_query', 'sql': '\n          insert into test16830581647929404551_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.80', 'status': 'OK', 'profile_name': 'test'}
20:09:30.854016 [debug] [Thread-3  ]: SQL status: OK in 0.8 seconds
20:09:30.860898 [debug] [Thread-3  ]: Writing runtime SQL for node "seed.incremental_test_model.added"
20:09:30.866916 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.870069 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:30.881151 [debug] [Thread-3  ]: Impala adapter: NotImplemented: commit
20:09:30.883397 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:30.885007 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:30.886724 [debug] [Thread-3  ]: finished collecting timing info
20:09:30.888019 [debug] [Thread-3  ]: On seed.incremental_test_model.added: ROLLBACK
20:09:30.889295 [debug] [Thread-3  ]: Impala adapter: NotImplemented: rollback
20:09:30.890530 [debug] [Thread-3  ]: On seed.incremental_test_model.added: Close
20:09:31.104492 [debug] [Thread-3  ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:31.105030 [debug] [Thread-3  ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:09:31.105855 [info ] [Thread-3  ]: 1 of 2 OK loaded seed file test16830581647929404551_test_basic.added ........... [INSERT 20 in 2.32s]
20:09:31.106468 [debug] [Thread-3  ]: Finished running node seed.incremental_test_model.added
20:09:31.107901 [debug] [MainThread]: Acquiring new impala connection "master"
20:09:31.108474 [debug] [MainThread]: On master: ROLLBACK
20:09:31.109019 [debug] [MainThread]: Opening a new connection, currently in state init
20:09:31.109707 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:31.230920 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:31.231829 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:31.232714 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:09:31.233504 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:09:31.234259 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:09:31.235040 [debug] [MainThread]: On master: ROLLBACK
20:09:31.235791 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:09:31.236549 [debug] [MainThread]: On master: Close
20:09:31.360756 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:31.363918 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.12'}
20:09:31.368257 [info ] [MainThread]: 
20:09:31.371368 [info ] [MainThread]: Finished running 2 seeds in 0 hours 0 minutes and 4.48 seconds (4.48s).
20:09:31.374466 [debug] [MainThread]: Connection 'master' was properly closed.
20:09:31.377597 [debug] [MainThread]: Connection 'seed.incremental_test_model.added' was properly closed.
20:09:31.380762 [debug] [MainThread]: Connection 'seed.incremental_test_model.base' was properly closed.
20:09:31.399244 [info ] [MainThread]: 
20:09:31.400540 [info ] [MainThread]: Completed successfully
20:09:31.401833 [info ] [MainThread]: 
20:09:31.402863 [info ] [MainThread]: Done. PASS=2 WARN=0 ERROR=0 SKIP=0 TOTAL=2
20:09:31.403950 [debug] [MainThread]: Flushing usage events
20:09:31.404641 [debug] [MainThread]: Integration Test: test connection "__test" executing: select count(*) as num_rows from test16830581647929404551_test_basic.base
20:09:31.406079 [debug] [MainThread]: Acquiring new impala connection "_test"
20:09:31.407098 [debug] [MainThread]: Opening a new connection, currently in state init
20:09:31.407981 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:31.544845 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:31.548099 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:32.178685 [debug] [MainThread]: On _test: Close
20:09:32.415566 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:32.418808 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}
20:09:32.421500 [debug] [MainThread]: Integration Test: test connection "__test" executing: select count(*) as num_rows from test16830581647929404551_test_basic.added
20:09:32.425572 [debug] [MainThread]: Acquiring new impala connection "_test"
20:09:32.429290 [debug] [MainThread]: Opening a new connection, currently in state closed
20:09:32.432510 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:32.564202 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:32.567446 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.01'}
20:09:33.045874 [debug] [MainThread]: On _test: Close
20:09:33.279455 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:33.282547 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}


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


============================== 2023-05-02 20:09:33.333673 | 2bdbb115-28e4-433b-9344-746adaefee06 ==============================
20:09:33.333679 [info ] [MainThread]: Running with dbt=1.3.3
20:09:33.334499 [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-364/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:09:33.335269 [debug] [MainThread]: Tracking: do not track
20:09:33.357992 [info ] [MainThread]: Unable to do partial parsing because config vars, config profile, or config target have changed
20:09:33.367644 [debug] [MainThread]: Parsing macros/adapters.sql
20:09:33.427475 [debug] [MainThread]: Parsing macros/catalog.sql
20:09:33.428286 [debug] [MainThread]: Parsing macros/incremental.sql
20:09:33.439865 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:09:33.442487 [debug] [MainThread]: Parsing macros/seed.sql
20:09:33.445881 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:09:33.451215 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:09:33.452043 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:09:33.452886 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:09:33.453772 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:09:33.455284 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:09:33.456942 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:09:33.457796 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:09:33.458711 [debug] [MainThread]: Parsing macros/utils/position.sql
20:09:33.459619 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:09:33.460731 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:09:33.472823 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:09:33.473587 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:09:33.474446 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:09:33.475426 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:09:33.476267 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:09:33.477134 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:09:33.479324 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:09:33.480816 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:09:33.482349 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:09:33.485933 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:09:33.487899 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:09:33.494832 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:09:33.505167 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:09:33.507000 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:09:33.512442 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:09:33.522351 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:09:33.525174 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:09:33.527508 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:09:33.528672 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:09:33.530033 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:09:33.531282 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:09:33.532446 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:09:33.533806 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:09:33.535011 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:09:33.536225 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:09:33.538265 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:09:33.540062 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:09:33.541302 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:09:33.542655 [debug] [MainThread]: Parsing macros/utils/position.sql
20:09:33.543893 [debug] [MainThread]: Parsing macros/utils/except.sql
20:09:33.544968 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:09:33.550279 [debug] [MainThread]: Parsing macros/utils/length.sql
20:09:33.551427 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:09:33.552506 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:09:33.554391 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:09:33.555733 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:09:33.556898 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:09:33.558255 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:09:33.559807 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:09:33.561052 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:09:33.562268 [debug] [MainThread]: Parsing macros/utils/right.sql
20:09:33.563510 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:09:33.565584 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:09:33.568693 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:09:33.574045 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:09:33.579942 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:09:33.591271 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:09:33.598662 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:09:33.600222 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:09:33.610539 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:09:33.613239 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:09:33.615292 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:09:33.619377 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:09:33.620732 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:09:33.624754 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:09:33.627631 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:09:33.635674 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:09:33.646917 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:09:33.648491 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:09:33.657321 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:09:33.659012 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:09:33.662558 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:09:33.664190 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:09:33.669075 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:09:33.681465 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:09:33.685972 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:09:33.689984 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:09:33.696056 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:09:33.697011 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:09:33.698018 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:09:33.699416 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:09:33.700468 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:09:33.939481 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:09:33.944318 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:09:33.986873 [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:09:33.987782 [info ] [MainThread]: 
20:09:33.988544 [debug] [MainThread]: Acquiring new impala connection "master"
20:09:33.989456 [debug] [ThreadPool]: Acquiring new impala connection "list_schemas"
20:09:33.991634 [debug] [ThreadPool]: Using impala connection "list_schemas"
20:09:33.992166 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:09:33.993188 [debug] [Thread-10 ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:09:33.993764 [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:09:33.994343 [debug] [Thread-10 ]: Tracker adapter: Disabling usage tracking due to error.
20:09:33.994691 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:09:33.995277 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:34.133341 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:34.135166 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:34.374007 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:34.377092 [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:09:34.380130 [debug] [ThreadPool]: SQL status: OK in 0.38 seconds
20:09:34.702206 [debug] [ThreadPool]: On list_schemas: Close
20:09:34.932192 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:34.935336 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:09:34.942712 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830581647929404551_test_basic"
20:09:34.956078 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:34.959258 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:34.962268 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:34.965231 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic
  
20:09:34.967749 [debug] [ThreadPool]: Opening a new connection, currently in state closed
20:09:34.969884 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:35.107758 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:35.110879 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:35.344361 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:35.347974 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic\n  ', 'elapsed_time': '0.38', 'status': 'OK', 'profile_name': 'test'}
20:09:35.348530 [debug] [ThreadPool]: SQL status: OK in 0.38 seconds
20:09:35.724984 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:35.726657 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:35.728214 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "added"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:35.729737 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "added"
  
20:09:36.072739 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:36.073344 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "added"\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:09:36.073912 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:09:36.405301 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:36.408517 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:36.411545 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:36.414625 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.added
  
20:09:36.755517 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:36.756319 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.added\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:09:36.757086 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:09:37.087387 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:37.087943 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:37.088470 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "base"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:37.088991 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "base"
  
20:09:37.417846 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:37.422360 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "base"\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:09:37.425451 [debug] [ThreadPool]: SQL status: OK in 0.33 seconds
20:09:37.779533 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:37.782611 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:37.785590 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:37.788586 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.base
  
20:09:38.151017 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.154297 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.base\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:09:38.157395 [debug] [ThreadPool]: SQL status: OK in 0.36 seconds
20:09:38.515690 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.518804 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:38.521970 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.525050 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:38.528150 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: Close
20:09:38.750254 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.753402 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:09:38.759328 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:09:38.762534 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:09:38.763270 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:09:38.763823 [info ] [MainThread]: 
20:09:38.765521 [debug] [Thread-11 ]: Began running node model.incremental_test_model.incremental_test_model
20:09:38.766131 [info ] [Thread-11 ]: 1 of 1 START sql incremental model test16830581647929404551_test_basic.incremental_test_model  [RUN]
20:09:38.766841 [debug] [Thread-11 ]: Acquiring new impala connection "model.incremental_test_model.incremental_test_model"
20:09:38.767503 [debug] [Thread-11 ]: Began compiling node model.incremental_test_model.incremental_test_model
20:09:38.768076 [debug] [Thread-11 ]: Compiling model.incremental_test_model.incremental_test_model
20:09:38.771355 [debug] [Thread-11 ]: Writing injected SQL for node "model.incremental_test_model.incremental_test_model"
20:09:38.772059 [debug] [Thread-11 ]: finished collecting timing info
20:09:38.772591 [debug] [Thread-11 ]: Began executing node model.incremental_test_model.incremental_test_model
20:09:38.789014 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.789548 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:38.792755 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.793290 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:38.796140 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.796668 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:38.800040 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.800579 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_backup', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:38.804714 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.805248 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'incremental', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': 'insert_overwrite'}
20:09:38.815694 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.816216 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:38.831789 [debug] [Thread-11 ]: Writing runtime sql for node "model.incremental_test_model.incremental_test_model"
20:09:38.832519 [debug] [Thread-11 ]: Impala adapter: NotImplemented: add_begin_query
20:09:38.833045 [debug] [Thread-11 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:09:38.833591 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.834123 [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    test16830581647929404551_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 test16830581647929404551_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:09:38.834639 [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
    test16830581647929404551_test_basic.incremental_test_model
    
      partitioned by (id_partition)
    
    
    
    
    
    
     
    
    
  as 
    
 select *, id as id_partition from test16830581647929404551_test_basic.base
 
  ;
  
  
20:09:38.835159 [debug] [Thread-11 ]: Opening a new connection, currently in state closed
20:09:38.835670 [debug] [Thread-11 ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:38.962227 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:38.965252 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:43.471542 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:43.474740 [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    test16830581647929404551_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 test16830581647929404551_test_basic.base\n \n  ;\n  \n  ', 'elapsed_time': '4.63', 'status': 'OK', 'profile_name': 'test'}
20:09:43.477833 [debug] [Thread-11 ]: SQL status: OK in 4.63 seconds
20:09:43.492910 [debug] [Thread-11 ]: Impala adapter: NotImplemented: commit
20:09:43.496825 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:43.499458 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:43.501702 [debug] [Thread-11 ]: finished collecting timing info
20:09:43.503709 [debug] [Thread-11 ]: On model.incremental_test_model.incremental_test_model: ROLLBACK
20:09:43.505259 [debug] [Thread-11 ]: Impala adapter: NotImplemented: rollback
20:09:43.506766 [debug] [Thread-11 ]: On model.incremental_test_model.incremental_test_model: Close
20:09:43.730748 [debug] [Thread-11 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:43.733792 [debug] [Thread-11 ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:09:43.738496 [info ] [Thread-11 ]: 1 of 1 OK created sql incremental model test16830581647929404551_test_basic.incremental_test_model  [OK in 4.97s]
20:09:43.742028 [debug] [Thread-11 ]: Finished running node model.incremental_test_model.incremental_test_model
20:09:43.748742 [debug] [MainThread]: Acquiring new impala connection "master"
20:09:43.750825 [debug] [MainThread]: On master: ROLLBACK
20:09:43.751345 [debug] [MainThread]: Opening a new connection, currently in state init
20:09:43.751869 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:43.876741 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:43.879742 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:43.882711 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:09:43.885694 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:09:43.888622 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:09:43.891620 [debug] [MainThread]: On master: ROLLBACK
20:09:43.894585 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:09:43.897487 [debug] [MainThread]: On master: Close
20:09:44.008696 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:44.011818 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.12'}
20:09:44.016038 [info ] [MainThread]: 
20:09:44.019043 [info ] [MainThread]: Finished running 1 incremental model in 0 hours 0 minutes and 10.03 seconds (10.03s).
20:09:44.022064 [debug] [MainThread]: Connection 'master' was properly closed.
20:09:44.025071 [debug] [MainThread]: Connection 'model.incremental_test_model.incremental_test_model' was properly closed.
20:09:44.046761 [info ] [MainThread]: 
20:09:44.048421 [info ] [MainThread]: Completed successfully
20:09:44.049738 [info ] [MainThread]: 
20:09:44.050943 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
20:09:44.052253 [debug] [MainThread]: Flushing usage events
20:09:44.054083 [debug] [MainThread]: Acquiring new impala connection "_test"
20:09:44.059979 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:09:44.060507 [debug] [MainThread]: Using impala connection "_test"
20:09:44.061037 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:44.061554 [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 test16830581647929404551_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:09:44.062062 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */

      describe extended test16830581647929404551_test_basic.base
  
20:09:44.062579 [debug] [MainThread]: Opening a new connection, currently in state init
20:09:44.063092 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:44.195147 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:44.198219 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:44.431781 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:44.434940 [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 test16830581647929404551_test_basic.base\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:09:44.437961 [debug] [MainThread]: SQL status: OK in 0.37 seconds
20:09:44.794009 [debug] [MainThread]: Using impala connection "_test"
20:09:44.797403 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:44.800652 [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 test16830581647929404551_test_basic.base EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.base)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_test_basic.base\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_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:09:44.803724 [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 test16830581647929404551_test_basic.base EXCEPT
             SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model)
             UNION ALL
            (SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model EXCEPT
             SELECT id, name, some_date FROM test16830581647929404551_test_basic.base)
        ) as a
), table_a as (
    SELECT COUNT(*) as num_rows FROM test16830581647929404551_test_basic.base
), table_b as (
    SELECT COUNT(*) as num_rows FROM test16830581647929404551_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:09:45.498235 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:45.501369 [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 test16830581647929404551_test_basic.base EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.base)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_test_basic.base\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_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.69', 'status': 'OK', 'profile_name': 'test'}
20:09:45.504409 [debug] [MainThread]: SQL status: OK in 0.69 seconds
20:09:45.864497 [debug] [MainThread]: On _test: ROLLBACK
20:09:45.865305 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:09:45.865828 [debug] [MainThread]: On _test: Close
20:09:46.091574 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:46.094647 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}


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


============================== 2023-05-02 20:09:46.109955 | 2bdbb115-28e4-433b-9344-746adaefee06 ==============================
20:09:46.109959 [info ] [MainThread]: Running with dbt=1.3.3
20:09:46.110523 [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-364/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:09:46.111058 [debug] [MainThread]: Tracking: do not track
20:09:46.123300 [info ] [MainThread]: Unable to do partial parsing because config vars, config profile, or config target have changed
20:09:46.133033 [debug] [MainThread]: Parsing macros/adapters.sql
20:09:46.193167 [debug] [MainThread]: Parsing macros/catalog.sql
20:09:46.193979 [debug] [MainThread]: Parsing macros/incremental.sql
20:09:46.205476 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:09:46.208064 [debug] [MainThread]: Parsing macros/seed.sql
20:09:46.211467 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:09:46.216807 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:09:46.217642 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:09:46.218501 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:09:46.219384 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:09:46.220868 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:09:46.222509 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:09:46.223360 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:09:46.224285 [debug] [MainThread]: Parsing macros/utils/position.sql
20:09:46.225169 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:09:46.226279 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:09:46.238146 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:09:46.238914 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:09:46.239775 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:09:46.240755 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:09:46.241612 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:09:46.242471 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:09:46.244623 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:09:46.246093 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:09:46.247638 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:09:46.251243 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:09:46.253225 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:09:46.260232 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:09:46.270552 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:09:46.272379 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:09:46.277766 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:09:46.287623 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:09:46.290454 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:09:46.292774 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:09:46.293904 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:09:46.295215 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:09:46.296457 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:09:46.297602 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:09:46.298839 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:09:46.300046 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:09:46.301271 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:09:46.303299 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:09:46.305069 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:09:46.306295 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:09:46.307632 [debug] [MainThread]: Parsing macros/utils/position.sql
20:09:46.308897 [debug] [MainThread]: Parsing macros/utils/except.sql
20:09:46.309981 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:09:46.315252 [debug] [MainThread]: Parsing macros/utils/length.sql
20:09:46.316426 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:09:46.317488 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:09:46.319379 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:09:46.320724 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:09:46.321887 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:09:46.323194 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:09:46.324705 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:09:46.325945 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:09:46.327160 [debug] [MainThread]: Parsing macros/utils/right.sql
20:09:46.328416 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:09:46.330536 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:09:46.333644 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:09:46.339058 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:09:46.344904 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:09:46.381854 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:09:46.389091 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:09:46.390585 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:09:46.400730 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:09:46.403384 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:09:46.405437 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:09:46.409479 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:09:46.410844 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:09:46.414839 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:09:46.417710 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:09:46.425666 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:09:46.436797 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:09:46.438359 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:09:46.447151 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:09:46.448867 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:09:46.452441 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:09:46.454133 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:09:46.459131 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:09:46.471551 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:09:46.476119 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:09:46.480153 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:09:46.486214 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:09:46.487188 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:09:46.488222 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:09:46.489651 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:09:46.490729 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:09:46.728475 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:09:46.733289 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:09:46.775963 [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:09:46.776972 [info ] [MainThread]: 
20:09:46.777688 [debug] [MainThread]: Acquiring new impala connection "master"
20:09:46.778610 [debug] [ThreadPool]: Acquiring new impala connection "list_schemas"
20:09:46.780749 [debug] [ThreadPool]: Using impala connection "list_schemas"
20:09:46.781286 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:09:46.781993 [debug] [Thread-18 ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:09:46.782828 [debug] [Thread-18 ]: Tracker adapter: Disabling usage tracking due to error.
20:09:46.783196 [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:09:46.783727 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:09:46.784248 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:46.919789 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:46.922748 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:47.148269 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:47.150843 [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.36', 'status': 'OK', 'profile_name': 'test'}
20:09:47.151376 [debug] [ThreadPool]: SQL status: OK in 0.36 seconds
20:09:47.482213 [debug] [ThreadPool]: On list_schemas: Close
20:09:47.711163 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:47.714302 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.23'}
20:09:47.721369 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830581647929404551_test_basic"
20:09:47.734364 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:47.737567 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:47.740591 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:47.742984 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic
  
20:09:47.745021 [debug] [ThreadPool]: Opening a new connection, currently in state closed
20:09:47.746960 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:47.881937 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:47.886530 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:09:48.128037 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:48.131209 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic\n  ', 'elapsed_time': '0.38', 'status': 'OK', 'profile_name': 'test'}
20:09:48.134336 [debug] [ThreadPool]: SQL status: OK in 0.38 seconds
20:09:48.467614 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:48.468655 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:48.469630 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "added"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:48.470608 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "added"
  
20:09:48.822704 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:48.825892 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "added"\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:09:48.828936 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:09:49.171170 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:49.174394 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:49.177425 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:49.180589 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.added
  
20:09:49.536326 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:49.539419 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.added\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:09:49.542755 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:09:49.879853 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:49.883020 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:49.886072 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "base"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:49.889074 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "base"
  
20:09:50.246390 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:50.249063 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "base"\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:09:50.249588 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:09:50.595376 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:50.595930 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:50.596466 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:50.596984 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.base
  
20:09:50.943819 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:50.947034 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.base\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:09:50.950083 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:09:51.298534 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:51.301699 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:51.304857 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "incremental_test_model"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:51.307860 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "incremental_test_model"
  
20:09:51.640179 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:51.643404 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "incremental_test_model"\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:09:51.646676 [debug] [ThreadPool]: SQL status: OK in 0.33 seconds
20:09:52.007312 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:09:52.010468 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:52.013614 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:09:52.016690 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.incremental_test_model
  
20:09:52.369212 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:52.372432 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:09:52.375392 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:09:52.726277 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:52.729477 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:52.732670 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:52.736002 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:52.739448 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:52.742596 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:52.745822 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: Close
20:09:52.996193 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:52.999377 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.25'}
20:09:53.004448 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:09:53.007528 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:09:53.011702 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:09:53.014982 [info ] [MainThread]: 
20:09:53.022326 [debug] [Thread-19 ]: Began running node model.incremental_test_model.incremental_test_model
20:09:53.025708 [info ] [Thread-19 ]: 1 of 1 START sql incremental model test16830581647929404551_test_basic.incremental_test_model  [RUN]
20:09:53.026731 [debug] [Thread-19 ]: Acquiring new impala connection "model.incremental_test_model.incremental_test_model"
20:09:53.027375 [debug] [Thread-19 ]: Began compiling node model.incremental_test_model.incremental_test_model
20:09:53.027899 [debug] [Thread-19 ]: Compiling model.incremental_test_model.incremental_test_model
20:09:53.031154 [debug] [Thread-19 ]: Writing injected SQL for node "model.incremental_test_model.incremental_test_model"
20:09:53.031837 [debug] [Thread-19 ]: finished collecting timing info
20:09:53.032382 [debug] [Thread-19 ]: Began executing node model.incremental_test_model.incremental_test_model
20:09:53.034202 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.034722 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:53.035840 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.036360 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:53.037524 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.038057 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:53.039197 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.039718 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_backup', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:53.040474 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.040998 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'incremental', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': 'insert_overwrite'}
20:09:53.042950 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.043474 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:09:53.044786 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:09:53.045321 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.045853 [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    test16830581647929404551_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 test16830581647929404551_test_basic.added\n \n where id > (select max(id) from test16830581647929404551_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:09:53.046372 [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
    test16830581647929404551_test_basic.incremental_test_model__dbt_tmp
    
      partitioned by (id_partition)
    
    
    
    
    
    
     
    
    
  as 
    
 select *, id as id_partition from test16830581647929404551_test_basic.added
 
 where id > (select max(id) from test16830581647929404551_test_basic.incremental_test_model)
 
  ;
  
  
20:09:53.046901 [debug] [Thread-19 ]: Opening a new connection, currently in state closed
20:09:53.047428 [debug] [Thread-19 ]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:09:53.183648 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:09:53.186818 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:10:01.103146 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:01.106332 [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    test16830581647929404551_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 test16830581647929404551_test_basic.added\n \n where id > (select max(id) from test16830581647929404551_test_basic.incremental_test_model)\n \n  ;\n  \n  ', 'elapsed_time': '8.05', 'status': 'OK', 'profile_name': 'test'}
20:10:01.109430 [debug] [Thread-19 ]: SQL status: OK in 8.05 seconds
20:10:01.473128 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:01.476121 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:01.479442 [debug] [Thread-19 ]: Impala adapter: NotImplemented: add_begin_query
20:10:01.482580 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:10:01.485614 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:01.488167 [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 test16830581647929404551_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:10:01.490302 [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 test16830581647929404551_test_basic.incremental_test_model__dbt_tmp
  
20:10:01.922288 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:01.925452 [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 test16830581647929404551_test_basic.incremental_test_model__dbt_tmp\n  ', 'elapsed_time': '0.43', 'status': 'OK', 'profile_name': 'test'}
20:10:01.928457 [debug] [Thread-19 ]: SQL status: OK in 0.43 seconds
20:10:02.340869 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:02.344110 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:02.347655 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:10:02.350842 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:02.352946 [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 test16830581647929404551_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:10:02.355004 [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 test16830581647929404551_test_basic.incremental_test_model
  
20:10:02.704258 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:02.707508 [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 test16830581647929404551_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:10:02.710647 [debug] [Thread-19 ]: SQL status: OK in 0.35 seconds
20:10:03.083163 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:03.084926 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:03.086576 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:10:03.088159 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:03.089531 [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 test16830581647929404551_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:10:03.090747 [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 test16830581647929404551_test_basic.incremental_test_model
  
20:10:03.427530 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:03.430747 [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 test16830581647929404551_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:10:03.433943 [debug] [Thread-19 ]: SQL status: OK in 0.33 seconds
20:10:03.819774 [debug] [Thread-19 ]: Writing runtime sql for node "model.incremental_test_model.incremental_test_model"
20:10:03.821147 [debug] [Thread-19 ]: Using impala connection "model.incremental_test_model.incremental_test_model"
20:10:03.822193 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:03.823158 [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 overwrite test16830581647929404551_test_basic.incremental_test_model (id, name, some_date) partition(id_partition)\n            select id, name, some_date, id_partition\n            from test16830581647929404551_test_basic.incremental_test_model__dbt_tmp\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:10:03.824018 [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 overwrite test16830581647929404551_test_basic.incremental_test_model (id, name, some_date) partition(id_partition)
            select id, name, some_date, id_partition
            from test16830581647929404551_test_basic.incremental_test_model__dbt_tmp
    
  
20:10:05.845661 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:05.849032 [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 overwrite test16830581647929404551_test_basic.incremental_test_model (id, name, some_date) partition(id_partition)\n            select id, name, some_date, id_partition\n            from test16830581647929404551_test_basic.incremental_test_model__dbt_tmp\n    \n  ', 'elapsed_time': '2.02', 'status': 'OK', 'profile_name': 'test'}
20:10:05.852079 [debug] [Thread-19 ]: SQL status: OK in 2.02 seconds
20:10:05.865072 [debug] [Thread-19 ]: Impala adapter: NotImplemented: commit
20:10:05.868943 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:05.872032 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:05.874588 [debug] [Thread-19 ]: finished collecting timing info
20:10:05.876705 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: ROLLBACK
20:10:05.878492 [debug] [Thread-19 ]: Impala adapter: NotImplemented: rollback
20:10:05.880007 [debug] [Thread-19 ]: On model.incremental_test_model.incremental_test_model: Close
20:10:06.101758 [debug] [Thread-19 ]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:06.106234 [debug] [Thread-19 ]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.22'}
20:10:06.111029 [info ] [Thread-19 ]: 1 of 1 OK created sql incremental model test16830581647929404551_test_basic.incremental_test_model  [OK in 13.08s]
20:10:06.114666 [debug] [Thread-19 ]: Finished running node model.incremental_test_model.incremental_test_model
20:10:06.118551 [debug] [MainThread]: Acquiring new impala connection "master"
20:10:06.119089 [debug] [MainThread]: On master: ROLLBACK
20:10:06.119616 [debug] [MainThread]: Opening a new connection, currently in state init
20:10:06.120142 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:10:06.269457 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:06.272599 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:10:06.275850 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:10:06.279036 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:10:06.281977 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:10:06.285204 [debug] [MainThread]: On master: ROLLBACK
20:10:06.288153 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:10:06.291063 [debug] [MainThread]: On master: Close
20:10:06.411992 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:06.415138 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.13'}
20:10:06.419597 [info ] [MainThread]: 
20:10:06.422676 [info ] [MainThread]: Finished running 1 incremental model in 0 hours 0 minutes and 19.64 seconds (19.64s).
20:10:06.425843 [debug] [MainThread]: Connection 'master' was properly closed.
20:10:06.428916 [debug] [MainThread]: Connection 'model.incremental_test_model.incremental_test_model' was properly closed.
20:10:06.450723 [info ] [MainThread]: 
20:10:06.452312 [info ] [MainThread]: Completed successfully
20:10:06.453731 [info ] [MainThread]: 
20:10:06.454934 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
20:10:06.456315 [debug] [MainThread]: Flushing usage events
20:10:06.458124 [debug] [MainThread]: Acquiring new impala connection "_test"
20:10:06.462385 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:10:06.463296 [debug] [MainThread]: Using impala connection "_test"
20:10:06.464172 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:06.465045 [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 test16830581647929404551_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:10:06.465951 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */

      describe extended test16830581647929404551_test_basic.added
  
20:10:06.466823 [debug] [MainThread]: Opening a new connection, currently in state init
20:10:06.467691 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:10:06.595157 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:06.598406 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:10:06.827274 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:06.830649 [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 test16830581647929404551_test_basic.added\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:10:06.833706 [debug] [MainThread]: SQL status: OK in 0.36 seconds
20:10:07.180114 [debug] [MainThread]: Using impala connection "_test"
20:10:07.183343 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:07.186599 [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 test16830581647929404551_test_basic.added EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.added)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_test_basic.added\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_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:10:07.189686 [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 test16830581647929404551_test_basic.added EXCEPT
             SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model)
             UNION ALL
            (SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model EXCEPT
             SELECT id, name, some_date FROM test16830581647929404551_test_basic.added)
        ) as a
), table_a as (
    SELECT COUNT(*) as num_rows FROM test16830581647929404551_test_basic.added
), table_b as (
    SELECT COUNT(*) as num_rows FROM test16830581647929404551_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:10:07.892683 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:07.895844 [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 test16830581647929404551_test_basic.added EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model)\n             UNION ALL\n            (SELECT id, name, some_date FROM test16830581647929404551_test_basic.incremental_test_model EXCEPT\n             SELECT id, name, some_date FROM test16830581647929404551_test_basic.added)\n        ) as a\n), table_a as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_test_basic.added\n), table_b as (\n    SELECT COUNT(*) as num_rows FROM test16830581647929404551_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.70', 'status': 'OK', 'profile_name': 'test'}
20:10:07.898889 [debug] [MainThread]: SQL status: OK in 0.7 seconds
20:10:08.234803 [debug] [MainThread]: On _test: ROLLBACK
20:10:08.237968 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:10:08.240987 [debug] [MainThread]: On _test: Close
20:10:08.493887 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:08.494508 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.26'}


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


============================== 2023-05-02 20:10:08.513325 | 2bdbb115-28e4-433b-9344-746adaefee06 ==============================
20:10:08.513330 [info ] [MainThread]: Running with dbt=1.3.3
20:10:08.514028 [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-364/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:10:08.514681 [debug] [MainThread]: Tracking: do not track
20:10:08.529032 [info ] [MainThread]: Unable to do partial parsing because config vars, config profile, or config target have changed
20:10:08.538826 [debug] [MainThread]: Parsing macros/adapters.sql
20:10:08.598744 [debug] [MainThread]: Parsing macros/catalog.sql
20:10:08.599550 [debug] [MainThread]: Parsing macros/incremental.sql
20:10:08.611025 [debug] [MainThread]: Parsing macros/apply_grants.sql
20:10:08.613634 [debug] [MainThread]: Parsing macros/seed.sql
20:10:08.617019 [debug] [MainThread]: Parsing macros/insertoverwrite.sql
20:10:08.622283 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:10:08.623118 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:10:08.623943 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:10:08.624824 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:10:08.626287 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:10:08.627944 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:10:08.628798 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:10:08.629737 [debug] [MainThread]: Parsing macros/utils/position.sql
20:10:08.630611 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:10:08.631754 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:10:08.643667 [debug] [MainThread]: Parsing macros/utils/timestamps.sql
20:10:08.644432 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:10:08.645287 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:10:08.646251 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:10:08.647118 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:10:08.647968 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
20:10:08.650095 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
20:10:08.651557 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
20:10:08.653094 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
20:10:08.656737 [debug] [MainThread]: Parsing macros/adapters/schema.sql
20:10:08.658702 [debug] [MainThread]: Parsing macros/adapters/columns.sql
20:10:08.665627 [debug] [MainThread]: Parsing macros/adapters/relation.sql
20:10:08.675880 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
20:10:08.677719 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
20:10:08.683129 [debug] [MainThread]: Parsing macros/adapters/apply_grants.sql
20:10:08.693071 [debug] [MainThread]: Parsing macros/adapters/timestamps.sql
20:10:08.695878 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
20:10:08.698212 [debug] [MainThread]: Parsing macros/utils/bool_or.sql
20:10:08.699353 [debug] [MainThread]: Parsing macros/utils/replace.sql
20:10:08.700686 [debug] [MainThread]: Parsing macros/utils/safe_cast.sql
20:10:08.701928 [debug] [MainThread]: Parsing macros/utils/literal.sql
20:10:08.703059 [debug] [MainThread]: Parsing macros/utils/any_value.sql
20:10:08.704286 [debug] [MainThread]: Parsing macros/utils/escape_single_quotes.sql
20:10:08.705490 [debug] [MainThread]: Parsing macros/utils/cast_bool_to_text.sql
20:10:08.706712 [debug] [MainThread]: Parsing macros/utils/listagg.sql
20:10:08.708726 [debug] [MainThread]: Parsing macros/utils/last_day.sql
20:10:08.710442 [debug] [MainThread]: Parsing macros/utils/array_concat.sql
20:10:08.711649 [debug] [MainThread]: Parsing macros/utils/dateadd.sql
20:10:08.713016 [debug] [MainThread]: Parsing macros/utils/position.sql
20:10:08.714267 [debug] [MainThread]: Parsing macros/utils/except.sql
20:10:08.715328 [debug] [MainThread]: Parsing macros/utils/data_types.sql
20:10:08.720598 [debug] [MainThread]: Parsing macros/utils/length.sql
20:10:08.721759 [debug] [MainThread]: Parsing macros/utils/intersect.sql
20:10:08.722822 [debug] [MainThread]: Parsing macros/utils/split_part.sql
20:10:08.724693 [debug] [MainThread]: Parsing macros/utils/datediff.sql
20:10:08.726031 [debug] [MainThread]: Parsing macros/utils/concat.sql
20:10:08.727190 [debug] [MainThread]: Parsing macros/utils/hash.sql
20:10:08.728500 [debug] [MainThread]: Parsing macros/utils/array_construct.sql
20:10:08.730003 [debug] [MainThread]: Parsing macros/utils/array_append.sql
20:10:08.731212 [debug] [MainThread]: Parsing macros/utils/date_trunc.sql
20:10:08.732418 [debug] [MainThread]: Parsing macros/utils/right.sql
20:10:08.733659 [debug] [MainThread]: Parsing macros/materializations/configs.sql
20:10:08.735714 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
20:10:08.738846 [debug] [MainThread]: Parsing macros/materializations/models/incremental/strategies.sql
20:10:08.744124 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
20:10:08.750007 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
20:10:08.761549 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
20:10:08.769017 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
20:10:08.770476 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
20:10:08.780678 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
20:10:08.783378 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
20:10:08.785438 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
20:10:08.789515 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
20:10:08.790857 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
20:10:08.794900 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
20:10:08.797764 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
20:10:08.805747 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
20:10:08.816976 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
20:10:08.818544 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
20:10:08.827345 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
20:10:08.829052 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
20:10:08.832589 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
20:10:08.834234 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
20:10:08.839184 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
20:10:08.851629 [debug] [MainThread]: Parsing macros/python_model/python.sql
20:10:08.856160 [debug] [MainThread]: Parsing macros/etc/statement.sql
20:10:08.860134 [debug] [MainThread]: Parsing macros/etc/datetime.sql
20:10:08.866181 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
20:10:08.867122 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
20:10:08.868149 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
20:10:08.869543 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
20:10:08.870594 [debug] [MainThread]: Parsing tests/generic/builtin.sql
20:10:09.108119 [debug] [MainThread]: 1603: static parser failed on incremental_test_model.sql
20:10:09.112918 [debug] [MainThread]: 1602: parser fallback to jinja rendering on incremental_test_model.sql
20:10:09.155043 [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:10:09.155998 [info ] [MainThread]: 
20:10:09.156763 [debug] [MainThread]: Acquiring new impala connection "master"
20:10:09.157740 [debug] [ThreadPool]: Acquiring new impala connection "list_None_test16830581647929404551_test_basic"
20:10:09.159848 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:09.160467 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag True. To turn on/off use usage_tracking flag in profiles.yml
20:10:09.161133 [debug] [Thread-26 ]: Tracker adapter: Error reading tracking config. SNOWPLOW_ENDPOINT not found. Declare it as envvar or define a default value.
20:10:09.161664 [debug] [Thread-26 ]: Tracker adapter: Disabling usage tracking due to error.
20:10:09.162215 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic
  
20:10:09.162734 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:10:09.163249 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:10:09.302092 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:09.304844 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:10:09.522487 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:09.525779 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic\n  ', 'elapsed_time': '0.36', 'status': 'OK', 'profile_name': 'test'}
20:10:09.528917 [debug] [ThreadPool]: SQL status: OK in 0.36 seconds
20:10:09.867837 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:09.871058 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:09.874137 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "added"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:10:09.877135 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "added"
  
20:10:10.245831 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:10.249070 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "added"\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:10:10.251986 [debug] [ThreadPool]: SQL status: OK in 0.37 seconds
20:10:10.603195 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:10.604047 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:10.604900 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:10:10.605724 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.added
  
20:10:10.957879 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:10.960945 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.added\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:10:10.963929 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:10:11.304612 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:11.307830 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:11.310924 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "base"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:10:11.314025 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "base"
  
20:10:11.685739 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:11.688026 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "base"\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:10:11.688557 [debug] [ThreadPool]: SQL status: OK in 0.37 seconds
20:10:12.055923 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:12.059033 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:12.062031 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:10:12.064996 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.base
  
20:10:12.406251 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:12.409313 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.base\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:10:12.412265 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:10:12.753258 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:12.753819 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:12.754354 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "incremental_test_model"\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:10:12.754871 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "incremental_test_model"
  
20:10:13.079051 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:13.082220 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "incremental_test_model"\n  ', 'elapsed_time': '0.32', 'status': 'OK', 'profile_name': 'test'}
20:10:13.085241 [debug] [ThreadPool]: SQL status: OK in 0.32 seconds
20:10:13.422621 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:13.425800 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:13.428831 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'list_None_test16830581647929404551_test_basic'}
20:10:13.431814 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.incremental_test_model
  
20:10:13.787805 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:13.790998 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.35', 'status': 'OK', 'profile_name': 'test'}
20:10:13.794132 [debug] [ThreadPool]: SQL status: OK in 0.35 seconds
20:10:14.140635 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:14.143881 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:14.146984 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_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_test16830581647929404551_test_basic'}
20:10:14.150062 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    show tables in test16830581647929404551_test_basic like "incremental_test_model__dbt_tmp"
  
20:10:14.495169 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:14.498301 [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_test16830581647929404551_test_basic"} */\n\n    show tables in test16830581647929404551_test_basic like "incremental_test_model__dbt_tmp"\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:10:14.501314 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:10:14.860673 [debug] [ThreadPool]: Using impala connection "list_None_test16830581647929404551_test_basic"
20:10:14.863865 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:14.867119 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_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_test16830581647929404551_test_basic'}
20:10:14.870285 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "list_None_test16830581647929404551_test_basic"} */

    describe extended test16830581647929404551_test_basic.incremental_test_model__dbt_tmp
  
20:10:15.201543 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:15.204757 [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_test16830581647929404551_test_basic"} */\n\n    describe extended test16830581647929404551_test_basic.incremental_test_model__dbt_tmp\n  ', 'elapsed_time': '0.33', 'status': 'OK', 'profile_name': 'test'}
20:10:15.207767 [debug] [ThreadPool]: SQL status: OK in 0.33 seconds
20:10:15.550554 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:15.554543 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:15.557694 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:15.560805 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:15.564044 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:15.567107 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:15.570455 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:15.573482 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:15.575749 [debug] [ThreadPool]: On list_None_test16830581647929404551_test_basic: Close
20:10:15.813707 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:15.816799 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}
20:10:15.822674 [info ] [MainThread]: Concurrency: 4 threads (target='default')
20:10:15.825726 [info ] [MainThread]: 
20:10:15.834873 [debug] [Thread-27 ]: Began running node model.incremental_test_model.incremental_test_model
20:10:15.840901 [debug] [Thread-28 ]: Began running node seed.incremental_test_model.added
20:10:15.845735 [debug] [Thread-27 ]: Acquiring new impala connection "model.incremental_test_model.incremental_test_model"
20:10:15.849786 [debug] [Thread-29 ]: Began running node seed.incremental_test_model.base
20:10:15.854391 [debug] [Thread-28 ]: Acquiring new impala connection "seed.incremental_test_model.added"
20:10:15.858031 [debug] [Thread-27 ]: Began compiling node model.incremental_test_model.incremental_test_model
20:10:15.859887 [debug] [Thread-29 ]: Acquiring new impala connection "seed.incremental_test_model.base"
20:10:15.863252 [debug] [Thread-28 ]: Began compiling node seed.incremental_test_model.added
20:10:15.868682 [debug] [Thread-27 ]: Compiling model.incremental_test_model.incremental_test_model
20:10:15.870687 [debug] [Thread-29 ]: Began compiling node seed.incremental_test_model.base
20:10:15.872365 [debug] [Thread-28 ]: Compiling seed.incremental_test_model.added
20:10:15.897770 [debug] [Thread-29 ]: Compiling seed.incremental_test_model.base
20:10:15.902161 [debug] [Thread-27 ]: Writing injected SQL for node "model.incremental_test_model.incremental_test_model"
20:10:15.909563 [debug] [Thread-28 ]: Writing injected SQL for node "seed.incremental_test_model.added"
20:10:15.915529 [debug] [Thread-28 ]: finished collecting timing info
20:10:15.919142 [debug] [Thread-29 ]: Writing injected SQL for node "seed.incremental_test_model.base"
20:10:15.924238 [debug] [Thread-28 ]: Began executing node seed.incremental_test_model.added
20:10:15.927681 [debug] [Thread-29 ]: finished collecting timing info
20:10:15.930919 [debug] [Thread-27 ]: finished collecting timing info
20:10:15.934569 [debug] [Thread-28 ]: finished collecting timing info
20:10:15.939368 [debug] [Thread-29 ]: Began executing node seed.incremental_test_model.base
20:10:15.942910 [debug] [Thread-27 ]: Began executing node model.incremental_test_model.incremental_test_model
20:10:15.946347 [debug] [Thread-28 ]: Finished running node seed.incremental_test_model.added
20:10:15.948202 [debug] [Thread-29 ]: finished collecting timing info
20:10:15.950354 [debug] [Thread-27 ]: finished collecting timing info
20:10:15.958362 [debug] [Thread-29 ]: Finished running node seed.incremental_test_model.base
20:10:15.960411 [debug] [Thread-27 ]: Finished running node model.incremental_test_model.incremental_test_model
20:10:15.965918 [debug] [MainThread]: Connection 'master' was properly closed.
20:10:15.968982 [debug] [MainThread]: Connection 'model.incremental_test_model.incremental_test_model' was properly closed.
20:10:15.971906 [debug] [MainThread]: Connection 'seed.incremental_test_model.added' was properly closed.
20:10:15.974845 [debug] [MainThread]: Connection 'seed.incremental_test_model.base' was properly closed.
20:10:15.998633 [info ] [MainThread]: Done.
20:10:16.003386 [debug] [MainThread]: Acquiring new impala connection "generate_catalog"
20:10:16.004617 [info ] [MainThread]: Building catalog
20:10:16.007614 [debug] [ThreadPool]: Acquiring new impala connection "test16830581647929404551_test_basic"
20:10:16.011988 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:16.013057 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.added', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:16.014160 [debug] [ThreadPool]: Impala adapter: NotImplemented: add_begin_query
20:10:16.015173 [debug] [ThreadPool]: Using impala connection "test16830581647929404551_test_basic"
20:10:16.016200 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:16.017217 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.added\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830581647929404551_test_basic'}
20:10:16.018213 [debug] [ThreadPool]: On test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830581647929404551_test_basic"} */

      describe extended test16830581647929404551_test_basic.added
  
20:10:16.019211 [debug] [ThreadPool]: Opening a new connection, currently in state init
20:10:16.020210 [debug] [ThreadPool]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:10:16.146307 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:16.149572 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:10:16.389496 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:16.393732 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.added\n  ', 'elapsed_time': '0.37', 'status': 'OK', 'profile_name': 'test'}
20:10:16.396856 [debug] [ThreadPool]: SQL status: OK in 0.37 seconds
20:10:16.760564 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:16.763624 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.base', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:16.766854 [debug] [ThreadPool]: Using impala connection "test16830581647929404551_test_basic"
20:10:16.769943 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:16.772765 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.base\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830581647929404551_test_basic'}
20:10:16.774760 [debug] [ThreadPool]: On test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830581647929404551_test_basic"} */

      describe extended test16830581647929404551_test_basic.base
  
20:10:17.158226 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:17.161267 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.base\n  ', 'elapsed_time': '0.38', 'status': 'OK', 'profile_name': 'test'}
20:10:17.164238 [debug] [ThreadPool]: SQL status: OK in 0.38 seconds
20:10:17.543861 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:17.547012 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:17.550338 [debug] [ThreadPool]: Using impala connection "test16830581647929404551_test_basic"
20:10:17.553431 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:17.556482 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.incremental_test_model\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830581647929404551_test_basic'}
20:10:17.559004 [debug] [ThreadPool]: On test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830581647929404551_test_basic"} */

      describe extended test16830581647929404551_test_basic.incremental_test_model
  
20:10:17.905300 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:17.908569 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.incremental_test_model\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:10:17.911600 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:10:18.271533 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:18.272079 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'model_access', 'model_name': 'test16830581647929404551_test_basic.incremental_test_model__dbt_tmp', 'model_type': <RelationType.Table: 'table'>, 'incremental_strategy': ''}
20:10:18.272642 [debug] [ThreadPool]: Using impala connection "test16830581647929404551_test_basic"
20:10:18.273178 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:18.273695 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.incremental_test_model__dbt_tmp\n  ', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': 'test16830581647929404551_test_basic'}
20:10:18.274202 [debug] [ThreadPool]: On test16830581647929404551_test_basic: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "test16830581647929404551_test_basic"} */

      describe extended test16830581647929404551_test_basic.incremental_test_model__dbt_tmp
  
20:10:18.620227 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:18.623292 [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": "test16830581647929404551_test_basic"} */\n\n      describe extended test16830581647929404551_test_basic.incremental_test_model__dbt_tmp\n  ', 'elapsed_time': '0.34', 'status': 'OK', 'profile_name': 'test'}
20:10:18.626702 [debug] [ThreadPool]: SQL status: OK in 0.34 seconds
20:10:18.985040 [debug] [ThreadPool]: On test16830581647929404551_test_basic: ROLLBACK
20:10:18.988069 [debug] [ThreadPool]: Impala adapter: NotImplemented: rollback
20:10:18.991054 [debug] [ThreadPool]: On test16830581647929404551_test_basic: Close
20:10:19.221809 [debug] [ThreadPool]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:19.224885 [debug] [ThreadPool]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}
20:10:19.256302 [info ] [MainThread]: Catalog written to /tmp/pytest-of-vkolanu/pytest-364/project0/target/catalog.json
20:10:19.259529 [debug] [MainThread]: Flushing usage events
20:10:19.261690 [debug] [MainThread]: Connection 'generate_catalog' was properly closed.
20:10:19.263718 [debug] [MainThread]: Connection 'test16830581647929404551_test_basic' was properly closed.
PASSED20:10:19.267531 [debug] [MainThread]: Acquiring new impala connection "_test"
20:10:19.269268 [debug] [MainThread]: Dropping schema "_ReferenceKey(database=None, schema='test16830581647929404551_test_basic', identifier=None)".
20:10:19.277321 [debug] [MainThread]: Impala adapter: NotImplemented: add_begin_query
20:10:19.278328 [debug] [MainThread]: Using impala connection "_test"
20:10:19.279343 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:19.280247 [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 test16830581647929404551_test_basic cascade', 'profile_name': 'test', 'app': 'dbt', 'dbt_version': '1.3.3', 'target_name': 'default', 'connection_name': '_test'}
20:10:19.281129 [debug] [MainThread]: On _test: /* {"app": "dbt", "dbt_version": "1.3.3", "profile_name": "test", "target_name": "default", "connection_name": "_test"} */
drop schema if exists test16830581647929404551_test_basic cascade
20:10:19.281983 [debug] [MainThread]: Opening a new connection, currently in state init
20:10:19.282831 [debug] [MainThread]: Impala adapter: Using user agent: dbt/cloudera-impala-v1.3.1
20:10:19.405920 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:19.408936 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'open', 'auth': 'ldap', 'connection_state': <ConnectionState.OPEN: 'open'>, 'elapsed_time': '0.00'}
20:10:21.056432 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:21.059481 [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 test16830581647929404551_test_basic cascade', 'elapsed_time': '1.77', 'status': 'OK', 'profile_name': 'test'}
20:10:21.062498 [debug] [MainThread]: SQL status: OK in 1.77 seconds
20:10:21.067741 [debug] [MainThread]: Impala adapter: NotImplemented: commit
20:10:21.071225 [debug] [MainThread]: On _test: ROLLBACK
20:10:21.074539 [debug] [MainThread]: Impala adapter: NotImplemented: rollback
20:10:21.078280 [debug] [MainThread]: On _test: Close
20:10:21.310377 [debug] [MainThread]: Tracker adapter: Usage tracking flag False. To turn on/off use usage_tracking flag in profiles.yml
20:10:21.313458 [debug] [MainThread]: Tracker adapter: Skipping Event {'event_type': 'close', 'connection_state': <ConnectionState.CLOSED: 'closed'>, 'elapsed_time': '0.24'}
20:10:21.314529 [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 57.45s ========================