dbt.log

mail@pastecode.io avatar
unknown
plain_text
2 years ago
21 kB
3
Indexable
Never
============================== 2022-12-19 15:21:17.539429 | d68df76e-b16a-452a-b2f2-a672c566fc27 ==============================
15:21:17.539429 [info ] [MainThread]: Running with dbt=1.3.0
15:21:17.541363 [debug] [MainThread]: running dbt with arguments {'write_json': True, 'use_colors': True, 'printer_width': 80, 'version_check': True, 'partial_parse': True, 'static_parser': True, 'profiles_dir': 'C:\\Users\\tomicm\\.dbt', 'send_anonymous_usage_stats': False, 'event_buffer_size': 100000, 'quiet': False, 'no_print': False, 'select': ['tomicm_test'], 'which': 'run', 'rpc_method': 'run', 'indirect_selection': 'eager'}
15:21:17.541363 [debug] [MainThread]: Tracking: do not track
15:21:17.624171 [debug] [MainThread]: Partial parsing enabled: 0 files deleted, 0 files added, 0 files changed.
15:21:17.624171 [debug] [MainThread]: Partial parsing enabled, no changes found, skipping parsing
15:21:17.639292 [info ] [MainThread]: Found 2 models, 4 tests, 0 snapshots, 0 analyses, 327 macros, 0 operations, 0 seed files, 1 source, 0 exposures, 0 metrics
15:21:17.640292 [info ] [MainThread]: 
15:21:17.641571 [debug] [MainThread]: Acquiring new oracle connection "master"
15:21:17.642083 [debug] [ThreadPool]: Acquiring new oracle connection "list_None"
15:21:17.656904 [debug] [ThreadPool]: oracle adapter: Using oracle connection "list_None".
15:21:17.656904 [debug] [ThreadPool]: oracle adapter: On list_None: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "connection_name": "list_None"} */
select username as "name"
      from sys.all_users
      order by username
  
15:21:17.656904 [debug] [ThreadPool]: Opening a new connection, currently in state init
15:21:17.657904 [debug] [ThreadPool]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:18.135845 [debug] [ThreadPool]: oracle adapter: SQL status: OK in 0.4789416790008545 seconds
15:21:18.175251 [debug] [ThreadPool]: On list_None: Close
15:21:18.226454 [debug] [ThreadPool]: Acquiring new oracle connection "list_None_stg"
15:21:18.232548 [debug] [ThreadPool]: oracle adapter: Using oracle connection "list_None_stg".
15:21:18.232548 [debug] [ThreadPool]: oracle adapter: On list_None_stg: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "connection_name": "list_None_stg"} */

    select SYS_CONTEXT('userenv', 'DB_NAME') FROM DUAL
  
15:21:18.232548 [debug] [ThreadPool]: Opening a new connection, currently in state init
15:21:18.233540 [debug] [ThreadPool]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:18.791751 [debug] [ThreadPool]: oracle adapter: SQL status: OK in 0.5592026710510254 seconds
15:21:18.791751 [debug] [ThreadPool]: oracle adapter: Using oracle connection "list_None_stg".
15:21:18.791751 [debug] [ThreadPool]: oracle adapter: On list_None_stg: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "connection_name": "list_None_stg"} */
with tables as
      <tables>
  
15:21:18.895853 [debug] [ThreadPool]: oracle adapter: SQL status: OK in 0.10410213470458984 seconds
15:21:19.171239 [debug] [ThreadPool]: On list_None_stg: ROLLBACK
15:21:19.176767 [debug] [ThreadPool]: On list_None_stg: Close
15:21:19.209265 [debug] [MainThread]: Opening a new connection, currently in state init
15:21:19.209265 [debug] [MainThread]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:19.584732 [debug] [MainThread]: On master: COMMIT
15:21:19.584732 [debug] [MainThread]: oracle adapter: Using oracle connection "master".
15:21:19.584732 [debug] [MainThread]: oracle adapter: On master: fCOMMIT
15:21:19.609355 [debug] [MainThread]: oracle adapter: SQL status: OK in 0.024623632431030273 seconds
15:21:19.609355 [debug] [MainThread]: On master: Close
15:21:19.634052 [info ] [MainThread]: Concurrency: 4 threads (target='dev')
15:21:19.634759 [info ] [MainThread]: 
15:21:19.639515 [debug] [Thread-1  ]: Began running node model.poc_dbt.tomicm_test
15:21:19.639515 [info ] [Thread-1  ]: 1 of 1 START sql table model stg.tomicm_test ................................... [RUN]
15:21:19.640895 [debug] [Thread-1  ]: Acquiring new oracle connection "model.poc_dbt.tomicm_test"
15:21:19.640895 [debug] [Thread-1  ]: Began compiling node model.poc_dbt.tomicm_test
15:21:19.640895 [debug] [Thread-1  ]: Compiling model.poc_dbt.tomicm_test
15:21:19.644865 [debug] [Thread-1  ]: Writing injected SQL for node "model.poc_dbt.tomicm_test"
15:21:19.646902 [debug] [Thread-1  ]: finished collecting timing info
15:21:19.647403 [debug] [Thread-1  ]: Began executing node model.poc_dbt.tomicm_test
15:21:19.716980 [debug] [Thread-1  ]: Preexisting intermediate relation=None
15:21:19.716980 [debug] [Thread-1  ]: Preexisting backup relation=None
15:21:19.736848 [debug] [Thread-1  ]: Writing runtime sql for node "model.poc_dbt.tomicm_test"
15:21:19.739957 [debug] [Thread-1  ]: Opening a new connection, currently in state init
15:21:19.740831 [debug] [Thread-1  ]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:20.025939 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:20.025939 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */

    
  
    

  create  table stg.tomicm_test__dbt_tmp
  
  as
    


select 1 as id from dual
union 
select 2 as id from dual
  
15:21:20.332805 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.3068664073944092 seconds
15:21:20.338840 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:20.338840 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */
ALTER table STG.TOMICM_TEST rename to tomicm_test__dbt_backup
15:21:20.385873 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.04703330993652344 seconds
15:21:20.385873 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:20.385873 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */
ALTER table stg.tomicm_test__dbt_tmp rename to tomicm_test
15:21:20.434464 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.04859137535095215 seconds
15:21:20.444719 [debug] [Thread-1  ]: On model.poc_dbt.tomicm_test: COMMIT
15:21:20.444719 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:20.445795 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: fCOMMIT
15:21:20.468498 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.02188873291015625 seconds
15:21:20.475103 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:20.475103 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */
DECLARE
     dne_942    EXCEPTION;
     PRAGMA EXCEPTION_INIT(dne_942, -942);
     attempted_ddl_on_in_use_GTT EXCEPTION;
     pragma EXCEPTION_INIT(attempted_ddl_on_in_use_GTT, -14452);
  BEGIN
     SAVEPOINT start_transaction;
     EXECUTE IMMEDIATE 'DROP table stg.tomicm_test__dbt_backup cascade constraint';
     COMMIT;
  EXCEPTION
     WHEN attempted_ddl_on_in_use_GTT THEN
        NULL; -- if it its a global temporary table, leave it alone.
     WHEN dne_942 THEN
        NULL;
  END;
15:21:20.579032 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.10292768478393555 seconds
15:21:20.585608 [debug] [Thread-1  ]: finished collecting timing info
15:21:20.585608 [debug] [Thread-1  ]: On model.poc_dbt.tomicm_test: Close
15:21:20.641238 [info ] [Thread-1  ]: 1 of 1 OK created sql table model stg.tomicm_test .............................. [OK in 1.00s]
15:21:20.642350 [debug] [Thread-1  ]: Finished running node model.poc_dbt.tomicm_test
15:21:20.643946 [debug] [MainThread]: Acquiring new oracle connection "master"
15:21:20.643946 [debug] [MainThread]: Opening a new connection, currently in state closed
15:21:20.643946 [debug] [MainThread]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:21.232848 [debug] [MainThread]: On master: COMMIT
15:21:21.232848 [debug] [MainThread]: oracle adapter: Using oracle connection "master".
15:21:21.232848 [debug] [MainThread]: oracle adapter: On master: fCOMMIT
15:21:21.329902 [debug] [MainThread]: oracle adapter: SQL status: OK in 0.09705448150634766 seconds
15:21:21.331308 [debug] [MainThread]: On master: Close
15:21:21.381220 [info ] [MainThread]: 
15:21:21.381836 [info ] [MainThread]: Finished running 1 table model in 0 hours 0 minutes and 3.74 seconds (3.74s).
15:21:21.382336 [debug] [MainThread]: Connection 'master' was properly closed.
15:21:21.382336 [debug] [MainThread]: Connection 'list_None' was properly closed.
15:21:21.382336 [debug] [MainThread]: Connection 'list_None_stg' was properly closed.
15:21:21.382822 [debug] [MainThread]: Connection 'model.poc_dbt.tomicm_test' was properly closed.
15:21:21.390968 [info ] [MainThread]: 
15:21:21.391470 [info ] [MainThread]: Completed successfully
15:21:21.391969 [info ] [MainThread]: 
15:21:21.391969 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
15:21:21.391969 [debug] [MainThread]: Flushing usage events


============================== 2022-12-19 15:21:32.598157 | 28e432ad-2936-48eb-8da0-7e933e762bb3 ==============================
15:21:32.598157 [info ] [MainThread]: Running with dbt=1.3.0
15:21:32.599236 [debug] [MainThread]: running dbt with arguments {'write_json': True, 'use_colors': True, 'printer_width': 80, 'version_check': True, 'partial_parse': True, 'static_parser': True, 'profiles_dir': 'C:\\Users\\tomicm\\.dbt', 'send_anonymous_usage_stats': False, 'event_buffer_size': 100000, 'quiet': False, 'no_print': False, 'select': ['tomicm_test'], 'full_refresh': True, 'which': 'run', 'rpc_method': 'run', 'indirect_selection': 'eager'}
15:21:32.599236 [debug] [MainThread]: Tracking: do not track
15:21:32.673524 [debug] [MainThread]: Partial parsing enabled: 0 files deleted, 0 files added, 0 files changed.
15:21:32.673524 [debug] [MainThread]: Partial parsing enabled, no changes found, skipping parsing
15:21:32.702316 [info ] [MainThread]: Found 2 models, 4 tests, 0 snapshots, 0 analyses, 327 macros, 0 operations, 0 seed files, 1 source, 0 exposures, 0 metrics
15:21:32.703839 [info ] [MainThread]: 
15:21:32.704823 [debug] [MainThread]: Acquiring new oracle connection "master"
15:21:32.707615 [debug] [ThreadPool]: Acquiring new oracle connection "list_None"
15:21:32.710946 [debug] [ThreadPool]: oracle adapter: Using oracle connection "list_None".
15:21:32.710946 [debug] [ThreadPool]: oracle adapter: On list_None: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "connection_name": "list_None"} */
select username as "name"
      from sys.all_users
      order by username
  
15:21:32.710946 [debug] [ThreadPool]: Opening a new connection, currently in state init
15:21:32.710946 [debug] [ThreadPool]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:33.076163 [debug] [ThreadPool]: oracle adapter: SQL status: OK in 0.3652167320251465 seconds
15:21:33.124129 [debug] [ThreadPool]: On list_None: Close
15:21:33.143557 [debug] [ThreadPool]: Acquiring new oracle connection "list_None_stg"
15:21:33.159336 [debug] [ThreadPool]: oracle adapter: Using oracle connection "list_None_stg".
15:21:33.159336 [debug] [ThreadPool]: oracle adapter: On list_None_stg: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "connection_name": "list_None_stg"} */

    select SYS_CONTEXT('userenv', 'DB_NAME') FROM DUAL
  
15:21:33.159336 [debug] [ThreadPool]: Opening a new connection, currently in state init
15:21:33.159336 [debug] [ThreadPool]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:33.481023 [debug] [ThreadPool]: oracle adapter: SQL status: OK in 0.3216872215270996 seconds
15:21:33.486444 [debug] [ThreadPool]: oracle adapter: Using oracle connection "list_None_stg".
15:21:33.486444 [debug] [ThreadPool]: oracle adapter: On list_None_stg: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "connection_name": "list_None_stg"} */
with tables as
      <tables>
  
15:21:33.592300 [debug] [ThreadPool]: oracle adapter: SQL status: OK in 0.10585689544677734 seconds
15:21:33.857341 [debug] [ThreadPool]: On list_None_stg: ROLLBACK
15:21:33.929373 [debug] [ThreadPool]: On list_None_stg: Close
15:21:34.029048 [debug] [MainThread]: Opening a new connection, currently in state init
15:21:34.029048 [debug] [MainThread]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:34.536333 [debug] [MainThread]: On master: COMMIT
15:21:34.536333 [debug] [MainThread]: oracle adapter: Using oracle connection "master".
15:21:34.537405 [debug] [MainThread]: oracle adapter: On master: fCOMMIT
15:21:34.548219 [debug] [MainThread]: oracle adapter: SQL status: OK in 0.010814189910888672 seconds
15:21:34.564031 [debug] [MainThread]: On master: Close
15:21:34.581606 [info ] [MainThread]: Concurrency: 4 threads (target='dev')
15:21:34.581606 [info ] [MainThread]: 
15:21:34.607576 [debug] [Thread-1  ]: Began running node model.poc_dbt.tomicm_test
15:21:34.608595 [info ] [Thread-1  ]: 1 of 1 START sql table model stg.tomicm_test ................................... [RUN]
15:21:34.609337 [debug] [Thread-1  ]: Acquiring new oracle connection "model.poc_dbt.tomicm_test"
15:21:34.609337 [debug] [Thread-1  ]: Began compiling node model.poc_dbt.tomicm_test
15:21:34.609337 [debug] [Thread-1  ]: Compiling model.poc_dbt.tomicm_test
15:21:34.612416 [debug] [Thread-1  ]: Writing injected SQL for node "model.poc_dbt.tomicm_test"
15:21:34.613473 [debug] [Thread-1  ]: finished collecting timing info
15:21:34.613473 [debug] [Thread-1  ]: Began executing node model.poc_dbt.tomicm_test
15:21:34.653962 [debug] [Thread-1  ]: Preexisting intermediate relation=None
15:21:34.653962 [debug] [Thread-1  ]: Preexisting backup relation=None
15:21:34.663636 [debug] [Thread-1  ]: Writing runtime sql for node "model.poc_dbt.tomicm_test"
15:21:34.663636 [debug] [Thread-1  ]: Opening a new connection, currently in state init
15:21:34.663636 [debug] [Thread-1  ]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:35.247853 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:35.247853 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */

    
  
    

  create  table stg.tomicm_test__dbt_tmp
  
  as
    


select 1 as id from dual
union 
select 2 as id from dual
  
15:21:35.612517 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.36466383934020996 seconds
15:21:35.615657 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:35.615657 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */
ALTER table STG.TOMICM_TEST rename to tomicm_test__dbt_backup
15:21:35.673774 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.05811715126037598 seconds
15:21:35.674775 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:35.674775 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */
ALTER table stg.tomicm_test__dbt_tmp rename to tomicm_test
15:21:35.732152 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.05737662315368652 seconds
15:21:35.747945 [debug] [Thread-1  ]: On model.poc_dbt.tomicm_test: COMMIT
15:21:35.747945 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:35.747945 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: fCOMMIT
15:21:35.880217 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.13227152824401855 seconds
15:21:35.896940 [debug] [Thread-1  ]: oracle adapter: Using oracle connection "model.poc_dbt.tomicm_test".
15:21:35.896940 [debug] [Thread-1  ]: oracle adapter: On model.poc_dbt.tomicm_test: f/* {"app": "dbt", "dbt_version": "1.3.0", "profile_name": "poc_dbt", "target_name": "dev", "node_id": "model.poc_dbt.tomicm_test"} */
DECLARE
     dne_942    EXCEPTION;
     PRAGMA EXCEPTION_INIT(dne_942, -942);
     attempted_ddl_on_in_use_GTT EXCEPTION;
     pragma EXCEPTION_INIT(attempted_ddl_on_in_use_GTT, -14452);
  BEGIN
     SAVEPOINT start_transaction;
     EXECUTE IMMEDIATE 'DROP table stg.tomicm_test__dbt_backup cascade constraint';
     COMMIT;
  EXCEPTION
     WHEN attempted_ddl_on_in_use_GTT THEN
        NULL; -- if it its a global temporary table, leave it alone.
     WHEN dne_942 THEN
        NULL;
  END;
15:21:36.130306 [debug] [Thread-1  ]: oracle adapter: SQL status: OK in 0.2333660125732422 seconds
15:21:36.141935 [debug] [Thread-1  ]: finished collecting timing info
15:21:36.141935 [debug] [Thread-1  ]: On model.poc_dbt.tomicm_test: Close
15:21:36.163462 [info ] [Thread-1  ]: 1 of 1 OK created sql table model stg.tomicm_test .............................. [OK in 1.55s]
15:21:36.179421 [debug] [Thread-1  ]: Finished running node model.poc_dbt.tomicm_test
15:21:36.182782 [debug] [MainThread]: Acquiring new oracle connection "master"
15:21:36.182967 [debug] [MainThread]: Opening a new connection, currently in state closed
15:21:36.183757 [debug] [MainThread]: oracle adapter: Attempting to connect using Oracle method: 'OracleConnectionMethod.CONNECTION_STRING' and dsn: '(<dsn>'
15:21:36.534759 [debug] [MainThread]: On master: COMMIT
15:21:36.534759 [debug] [MainThread]: oracle adapter: Using oracle connection "master".
15:21:36.534759 [debug] [MainThread]: oracle adapter: On master: fCOMMIT
15:21:36.567240 [debug] [MainThread]: oracle adapter: SQL status: OK in 0.032480478286743164 seconds
15:21:36.567240 [debug] [MainThread]: On master: Close
15:21:36.582998 [info ] [MainThread]: 
15:21:36.598797 [info ] [MainThread]: Finished running 1 table model in 0 hours 0 minutes and 3.88 seconds (3.88s).
15:21:36.600304 [debug] [MainThread]: Connection 'master' was properly closed.
15:21:36.600304 [debug] [MainThread]: Connection 'list_None' was properly closed.
15:21:36.600304 [debug] [MainThread]: Connection 'list_None_stg' was properly closed.
15:21:36.601377 [debug] [MainThread]: Connection 'model.poc_dbt.tomicm_test' was properly closed.
15:21:36.609008 [info ] [MainThread]: 
15:21:36.609008 [info ] [MainThread]: Completed successfully
15:21:36.609008 [info ] [MainThread]: 
15:21:36.609008 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
15:21:36.611419 [debug] [MainThread]: Flushing usage events