You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hive.apache.org by "Dharmik Thakkar (Jira)" <ji...@apache.org> on 2023/01/18 15:55:00 UTC
[jira] [Work started] (HIVE-26964) Materialized View stored as iceberg v2 format is not used when column values are filtered in a range for iceberg source table.
[ https://issues.apache.org/jira/browse/HIVE-26964?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Work on HIVE-26964 started by Dharmik Thakkar.
----------------------------------------------
> Materialized View stored as iceberg v2 format is not used when column values are filtered in a range for iceberg source table.
> ------------------------------------------------------------------------------------------------------------------------------
>
> Key: HIVE-26964
> URL: https://issues.apache.org/jira/browse/HIVE-26964
> Project: Hive
> Issue Type: Bug
> Components: Iceberg integration
> Reporter: Dharmik Thakkar
> Assignee: Dharmik Thakkar
> Priority: Major
>
> Materialized View stored as iceberg v2 format is not used when column values are filtered in a range for iceberg source table.
> Source Table
> {code:java}
> create table all100k(
> t int,
> si int,
> i int,
> b bigint,
> f float,
> d double,
> s string,
> dc decimal(38,18),
> bo boolean,
> v string,
> c string,
> ts timestamp,
> dt date)
> partitioned by spec (BUCKET(16, t))
> stored by iceberg
> stored as parquet; {code}
> SQL Queries
> {code:java}
> >>> set hive.cbo.enable=true;
> >>> drop materialized view if exists mv_filter;
> >>> create materialized view mv_filter stored by iceberg tblproperties('format-version'='2') as select t, si from all100k where t>115;
> >>> analyze table mv_filter compute statistics for columns;
> >>> set hive.explain.user=false;
> >>> explain select si,t from all100k where t>116 and t<120;
> !!! match row_contains
> alias: iceberg_test_db_hive.mv_filter
> >>> drop materialized view mv_filter;
> {code}
> Actual Output
> {code:java}
> STAGE DEPENDENCIES:
> Stage-0 is a root stage
> STAGE PLANS:
> Stage: Stage-0
> Fetch Operator
> limit: -1
> Processor Tree:
> TableScan
> alias: iceberg_test_db_hive.mv_rewrite
> filterExpr: ((t > 116) and (t < 120)) (type: boolean)
> Filter Operator
> predicate: ((t > 116) and (t < 120)) (type: boolean)
> Select Operator
> expressions: si (type: int), t (type: int)
> outputColumnNames: _col0, _col1
> ListSink
> {code}
> Client Logs
> {code:java}
> 2023-01-18T12:41:23,848 INFO [pool-2-thread-1] jdbc.TestDriver: Beginning Test at 2023-01-18 12:41:23,847
> 2023-01-18T12:41:23,849 INFO [pool-2-thread-1] jdbc.TestDriver: BEGIN MAIN
> 2023-01-18T12:41:23,851 INFO [pool-3-thread-1] jdbc.TestDriver: Running SessionGroup{name='SG_KLTLKDWOSO', initialDelay=0, repeats=1, repeatDelay=0}
> 2023-01-18T12:41:23,856 INFO [pool-3-thread-1] jdbc.TestDriver: Connecting as user 'hrt_qa'
> 2023-01-18T12:41:24,893 INFO [pool-3-thread-1] jdbc.TestDriver: Query: use iceberg_test_db_hive
> 2023-01-18T12:41:25,075 INFO [Thread-1] jdbc.TestDriver: INFO : Compiling command(queryId=hive_20230118124124_ba7f7447-f276-4836-8afe-6f29c1ff6a0d): use iceberg_test_db_hive
> 2023-01-18T12:41:25,075 INFO [Thread-1] jdbc.TestDriver: INFO : Semantic Analysis Completed (retrial = false)
> 2023-01-18T12:41:25,075 INFO [Thread-1] jdbc.TestDriver: INFO : Created Hive schema: Schema(fieldSchemas:null, properties:null)
> 2023-01-18T12:41:25,076 INFO [Thread-1] jdbc.TestDriver: INFO : Completed compiling command(queryId=hive_20230118124124_ba7f7447-f276-4836-8afe-6f29c1ff6a0d); Time taken: 0.007 seconds
> 2023-01-18T12:41:25,076 INFO [Thread-1] jdbc.TestDriver: INFO : Executing command(queryId=hive_20230118124124_ba7f7447-f276-4836-8afe-6f29c1ff6a0d): use iceberg_test_db_hive
> 2023-01-18T12:41:25,076 INFO [Thread-1] jdbc.TestDriver: INFO : Starting task [Stage-0:DDL] in serial mode
> 2023-01-18T12:41:25,076 INFO [Thread-1] jdbc.TestDriver: INFO : Completed executing command(queryId=hive_20230118124124_ba7f7447-f276-4836-8afe-6f29c1ff6a0d); Time taken: 0.009 seconds
> 2023-01-18T12:41:25,076 INFO [Thread-1] jdbc.TestDriver: INFO : OK
> 2023-01-18T12:41:25,202 INFO [pool-3-thread-1] jdbc.TestDriver: Query: set hive.cbo.enable=true
> 2023-01-18T12:41:25,407 INFO [pool-3-thread-1] jdbc.TestDriver: No output to verify
> 2023-01-18T12:41:25,407 INFO [pool-3-thread-1] jdbc.TestDriver: Query: drop materialized view if exists mv_filter
> 2023-01-18T12:41:25,467 INFO [Thread-3] jdbc.TestDriver: INFO : Compiling command(queryId=hive_20230118124125_1851923e-08e4-4919-a7a9-abde3b995743): drop materialized view if exists mv_filter
> 2023-01-18T12:41:25,524 INFO [Thread-3] jdbc.TestDriver: INFO : Semantic Analysis Completed (retrial = false)
> 2023-01-18T12:41:25,524 INFO [Thread-3] jdbc.TestDriver: INFO : Created Hive schema: Schema(fieldSchemas:null, properties:null)
> 2023-01-18T12:41:25,525 INFO [Thread-3] jdbc.TestDriver: INFO : Completed compiling command(queryId=hive_20230118124125_1851923e-08e4-4919-a7a9-abde3b995743); Time taken: 0.028 seconds
> 2023-01-18T12:41:25,525 INFO [Thread-3] jdbc.TestDriver: INFO : Executing command(queryId=hive_20230118124125_1851923e-08e4-4919-a7a9-abde3b995743): drop materialized view if exists mv_filter
> 2023-01-18T12:41:25,525 INFO [Thread-3] jdbc.TestDriver: INFO : Starting task [Stage-0:DDL] in serial mode
> 2023-01-18T12:41:25,525 INFO [Thread-3] jdbc.TestDriver: INFO : Completed executing command(queryId=hive_20230118124125_1851923e-08e4-4919-a7a9-abde3b995743); Time taken: 0.007 seconds
> 2023-01-18T12:41:25,525 INFO [Thread-3] jdbc.TestDriver: INFO : OK
> 2023-01-18T12:41:25,639 INFO [pool-3-thread-1] jdbc.TestDriver: No output to verify
> 2023-01-18T12:41:25,640 INFO [pool-3-thread-1] jdbc.TestDriver: Query: create materialized view mv_filter stored by iceberg tblproperties('format-version'='2') as select t, si from all100k where t>115
> 2023-01-18T12:41:25,699 INFO [Thread-4] jdbc.TestDriver: INFO : Compiling command(queryId=hive_20230118124125_1120a7e7-d16a-4beb-bffb-f29cd607b8f4): create materialized view mv_filter stored by iceberg tblproperties('format-version'='2') as select t, si from all100k where t>115
> 2023-01-18T12:41:26,258 INFO [Thread-4] jdbc.TestDriver: INFO : No Stats for iceberg_test_db_hive@all100k, Columns: t, si
> 2023-01-18T12:41:26,817 INFO [Thread-4] jdbc.TestDriver: INFO : Semantic Analysis Completed (retrial = false)
> 2023-01-18T12:41:26,818 INFO [Thread-4] jdbc.TestDriver: INFO : Created Hive schema: Schema(fieldSchemas:[FieldSchema(name:t, type:int, comment:null), FieldSchema(name:si, type:int, comment:null)], properties:null)
> 2023-01-18T12:41:26,818 INFO [Thread-4] jdbc.TestDriver: INFO : Completed compiling command(queryId=hive_20230118124125_1120a7e7-d16a-4beb-bffb-f29cd607b8f4); Time taken: 0.72 seconds
> 2023-01-18T12:41:26,818 INFO [Thread-4] jdbc.TestDriver: INFO : Executing command(queryId=hive_20230118124125_1120a7e7-d16a-4beb-bffb-f29cd607b8f4): create materialized view mv_filter stored by iceberg tblproperties('format-version'='2') as select t, si from all100k where t>115
> 2023-01-18T12:41:26,818 INFO [Thread-4] jdbc.TestDriver: INFO : Compute 'qe-vw-dwx-hive-oqoa' is active.
> 2023-01-18T12:41:26,818 INFO [Thread-4] jdbc.TestDriver: INFO : Query ID = hive_20230118124125_1120a7e7-d16a-4beb-bffb-f29cd607b8f4
> 2023-01-18T12:41:26,819 INFO [Thread-4] jdbc.TestDriver: INFO : Total jobs = 1
> 2023-01-18T12:41:26,819 INFO [Thread-4] jdbc.TestDriver: INFO : Starting task [Stage-4:DDL] in serial mode
> 2023-01-18T12:41:27,934 INFO [Thread-4] jdbc.TestDriver: INFO : Starting task [Stage-5:DDL] in serial mode
> 2023-01-18T12:41:28,492 INFO [Thread-4] jdbc.TestDriver: INFO : No Stats for iceberg_test_db_hive@all100k, Columns: t, si
> 2023-01-18T12:41:28,492 INFO [Thread-4] jdbc.TestDriver: INFO : Launching Job 1 out of 1
> 2023-01-18T12:41:28,493 INFO [Thread-4] jdbc.TestDriver: INFO : Starting task [Stage-1:MAPRED] in serial mode
> 2023-01-18T12:41:28,493 INFO [Thread-4] jdbc.TestDriver: INFO : Subscribed to counters: [] for queryId: hive_20230118124125_1120a7e7-d16a-4beb-bffb-f29cd607b8f4
> 2023-01-18T12:41:28,493 INFO [Thread-4] jdbc.TestDriver: INFO : Tez session hasn't been created yet. Opening session
> 2023-01-18T12:41:28,493 INFO [Thread-4] jdbc.TestDriver: INFO : Dag name: create materialized view mv_filter s...t>115 (Stage-1)
> 2023-01-18T12:41:28,493 INFO [Thread-4] jdbc.TestDriver: INFO : HS2 Host: [hiveserver2-0], Query ID: [hive_20230118124125_1120a7e7-d16a-4beb-bffb-f29cd607b8f4], Dag ID: [dag_1674041835066_0001_171], DAG Session ID: [application_1674041835066_0001]
> 2023-01-18T12:41:28,493 INFO [Thread-4] jdbc.TestDriver: INFO : Status: Running (Executing on YARN cluster with App id application_1674041835066_0001)
> 2023-01-18T12:41:28,494 INFO [Thread-4] jdbc.TestDriver:
> 2023-01-18T12:41:30,726 INFO [Thread-4] jdbc.TestDriver: INFO : Status: DAG finished successfully in 2.16 seconds
> 2023-01-18T12:41:30,726 INFO [Thread-4] jdbc.TestDriver: INFO : DAG ID: dag_1674041835066_0001_171
> 2023-01-18T12:41:30,727 INFO [Thread-4] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:30,727 INFO [Thread-4] jdbc.TestDriver: INFO : Query Execution Summary
> 2023-01-18T12:41:30,727 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,728 INFO [Thread-4] jdbc.TestDriver: INFO : OPERATION DURATION
> 2023-01-18T12:41:30,728 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,728 INFO [Thread-4] jdbc.TestDriver: INFO : Compile Query 0.72s
> 2023-01-18T12:41:30,728 INFO [Thread-4] jdbc.TestDriver: INFO : Prepare Plan 1.99s
> 2023-01-18T12:41:30,728 INFO [Thread-4] jdbc.TestDriver: INFO : Get Query Coordinator (AM) 0.06s
> 2023-01-18T12:41:30,728 INFO [Thread-4] jdbc.TestDriver: INFO : Submit Plan 0.01s
> 2023-01-18T12:41:30,728 INFO [Thread-4] jdbc.TestDriver: INFO : Start DAG 0.01s
> 2023-01-18T12:41:30,729 INFO [Thread-4] jdbc.TestDriver: INFO : Run DAG 2.16s
> 2023-01-18T12:41:30,729 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,729 INFO [Thread-4] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:30,729 INFO [Thread-4] jdbc.TestDriver: INFO : Task Execution Summary
> 2023-01-18T12:41:30,729 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,729 INFO [Thread-4] jdbc.TestDriver: INFO : VERTICES DURATION(ms) CPU_TIME(ms) GC_TIME(ms) INPUT_RECORDS OUTPUT_RECORDS
> 2023-01-18T12:41:30,730 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,730 INFO [Thread-4] jdbc.TestDriver: INFO : Map 1 1654.00 0 0 4,718 1
> 2023-01-18T12:41:30,730 INFO [Thread-4] jdbc.TestDriver: INFO : Reducer 2 0.00 0 0 1 0
> 2023-01-18T12:41:30,730 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,730 INFO [Thread-4] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:30,730 INFO [Thread-4] jdbc.TestDriver: INFO : LLAP IO Summary
> 2023-01-18T12:41:30,730 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,731 INFO [Thread-4] jdbc.TestDriver: INFO : VERTICES ROWGROUPS META_HIT META_MISS DATA_HIT DATA_MISS TOTAL_IO
> 2023-01-18T12:41:30,731 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,731 INFO [Thread-4] jdbc.TestDriver: INFO : Map 1 0 0 0 0B 0B 0.00s
> 2023-01-18T12:41:30,731 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,731 INFO [Thread-4] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:30,731 INFO [Thread-4] jdbc.TestDriver: INFO : FileSystem Counters Summary
> 2023-01-18T12:41:30,731 INFO [Thread-4] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:30,732 INFO [Thread-4] jdbc.TestDriver: INFO : Scheme: S3A
> 2023-01-18T12:41:30,732 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,732 INFO [Thread-4] jdbc.TestDriver: INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
> 2023-01-18T12:41:30,732 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,732 INFO [Thread-4] jdbc.TestDriver: INFO : Map 1 1.21MB 20 0 23.12KB 0
> 2023-01-18T12:41:30,732 INFO [Thread-4] jdbc.TestDriver: INFO : Reducer 2 0B 0 0 0B 0
> 2023-01-18T12:41:30,732 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,733 INFO [Thread-4] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:30,733 INFO [Thread-4] jdbc.TestDriver: INFO : Scheme: FILE
> 2023-01-18T12:41:30,733 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,733 INFO [Thread-4] jdbc.TestDriver: INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
> 2023-01-18T12:41:30,734 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,734 INFO [Thread-4] jdbc.TestDriver: INFO : Map 1 0B 0 0 761B 0
> 2023-01-18T12:41:30,734 INFO [Thread-4] jdbc.TestDriver: INFO : Reducer 2 646B 0 0 1.38KB 0
> 2023-01-18T12:41:30,734 INFO [Thread-4] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:30,735 INFO [Thread-4] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:30,735 INFO [Thread-4] jdbc.TestDriver: INFO : org.apache.tez.common.counters.DAGCounter:
> 2023-01-18T12:41:30,735 INFO [Thread-4] jdbc.TestDriver: INFO : NUM_SUCCEEDED_TASKS: 2
> 2023-01-18T12:41:30,735 INFO [Thread-4] jdbc.TestDriver: INFO : TOTAL_LAUNCHED_TASKS: 2
> 2023-01-18T12:41:30,735 INFO [Thread-4] jdbc.TestDriver: INFO : RACK_LOCAL_TASKS: 1
> 2023-01-18T12:41:30,735 INFO [Thread-4] jdbc.TestDriver: INFO : AM_CPU_MILLISECONDS: 230
> 2023-01-18T12:41:30,735 INFO [Thread-4] jdbc.TestDriver: INFO : AM_GC_TIME_MILLIS: 0
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : File System Counters:
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : FILE_BYTES_READ: 646
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : FILE_BYTES_WRITTEN: 2139
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : FILE_READ_OPS: 0
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : FILE_LARGE_READ_OPS: 0
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : FILE_WRITE_OPS: 0
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : S3A_BYTES_READ: 1208036
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : S3A_BYTES_WRITTEN: 23118
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : S3A_READ_OPS: 20
> 2023-01-18T12:41:30,736 INFO [Thread-4] jdbc.TestDriver: INFO : S3A_LARGE_READ_OPS: 0
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : S3A_WRITE_OPS: 0
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : org.apache.tez.common.counters.TaskCounter:
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : SPILLED_RECORDS: 0
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : NUM_SHUFFLED_INPUTS: 1
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : NUM_FAILED_SHUFFLE_INPUTS: 0
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : TASK_DURATION_MILLIS: 1932
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : INPUT_RECORDS_PROCESSED: 4719
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : INPUT_SPLIT_LENGTH_BYTES: 3240784
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : OUTPUT_RECORDS: 1
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : APPROXIMATE_INPUT_RECORDS: 1
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : OUTPUT_LARGE_RECORDS: 0
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : OUTPUT_BYTES: 933
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : OUTPUT_BYTES_WITH_OVERHEAD: 943
> 2023-01-18T12:41:30,737 INFO [Thread-4] jdbc.TestDriver: INFO : OUTPUT_BYTES_PHYSICAL: 670
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : ADDITIONAL_SPILLS_BYTES_WRITTEN: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : ADDITIONAL_SPILLS_BYTES_READ: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : ADDITIONAL_SPILL_COUNT: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : SHUFFLE_BYTES: 646
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : SHUFFLE_BYTES_DECOMPRESSED: 943
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : SHUFFLE_BYTES_TO_MEM: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : SHUFFLE_BYTES_TO_DISK: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : SHUFFLE_BYTES_DISK_DIRECT: 646
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : SHUFFLE_PHASE_TIME: 1
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : FIRST_EVENT_RECEIVED: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : LAST_EVENT_RECEIVED: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : DATA_BYTES_VIA_EVENT: 0
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : HIVE:
> 2023-01-18T12:41:30,738 INFO [Thread-4] jdbc.TestDriver: INFO : CREATED_FILES: 2
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : DESERIALIZE_ERRORS: 0
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_IN_Map_1: 4718
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_0: 1
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_1_iceberg_test_db_hive.mv_filter: 4718
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_INTERMEDIATE_Map_1: 1
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_INTERMEDIATE_Reducer_2: 0
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_FIL_14: 4718
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_FS_13: 1
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_FS_3: 4718
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_GBY_11: 1
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_GBY_9: 1
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_MAP_0: 0
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_RS_10: 1
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_SEL_12: 1
> 2023-01-18T12:41:30,739 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_SEL_2: 4718
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_SEL_8: 4718
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_TS_0: 4718
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : TOTAL_TABLE_ROWS_WRITTEN: 4718
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : org.apache.hadoop.hive.llap.counters.LlapWmCounters:
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : GUARANTEED_QUEUED_NS: 0
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : GUARANTEED_RUNNING_NS: 0
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : SPECULATIVE_QUEUED_NS: 144947
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : SPECULATIVE_RUNNING_NS: 1923246017
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : org.apache.hadoop.hive.llap.daemon.impl.StatsRecordingThreadPool$WrappedCallable$LlapExecutorCounters:
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : EXECUTOR_CPU_NS: 220182116
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : EXECUTOR_USER_NS: 160000000
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : org.apache.hadoop.hive.ql.exec.tez.HiveInputCounters:
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : GROUPED_INPUT_SPLITS_Map_1: 1
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : INPUT_DIRECTORIES_Map_1: 1
> 2023-01-18T12:41:30,740 INFO [Thread-4] jdbc.TestDriver: INFO : INPUT_FILES_Map_1: 1
> 2023-01-18T12:41:30,741 INFO [Thread-4] jdbc.TestDriver: INFO : RAW_INPUT_SPLITS_Map_1: 1
> 2023-01-18T12:41:30,741 INFO [Thread-4] jdbc.TestDriver: INFO : Starting task [Stage-2:DEPENDENCY_COLLECTION] in serial mode
> 2023-01-18T12:41:30,741 INFO [Thread-4] jdbc.TestDriver: INFO : Starting task [Stage-0:MOVE] in serial mode
> 2023-01-18T12:41:32,957 INFO [Thread-4] jdbc.TestDriver: INFO : Starting task [Stage-3:STATS] in serial mode
> 2023-01-18T12:41:32,957 INFO [Thread-4] jdbc.TestDriver: INFO : Executing stats task
> 2023-01-18T12:41:33,360 INFO [Thread-4] jdbc.TestDriver: INFO : Table iceberg_test_db_hive.mv_filter stats: [numFiles=1, numRows=4718, totalSize=20588]
> 2023-01-18T12:41:33,360 INFO [Thread-4] jdbc.TestDriver: INFO : Table iceberg_test_db_hive.mv_filter stats: [numFiles=1, numRows=4718, totalSize=20588]
> 2023-01-18T12:41:33,360 INFO [Thread-4] jdbc.TestDriver: INFO : Completed executing command(queryId=hive_20230118124125_1120a7e7-d16a-4beb-bffb-f29cd607b8f4); Time taken: 6.91 seconds
> 2023-01-18T12:41:33,360 INFO [Thread-4] jdbc.TestDriver: INFO : OK
> 2023-01-18T12:41:33,703 INFO [pool-3-thread-1] jdbc.TestDriver: No output to verify
> 2023-01-18T12:41:33,704 INFO [pool-3-thread-1] jdbc.TestDriver: Query: analyze table mv_filter compute statistics for columns
> 2023-01-18T12:41:34,292 INFO [Thread-5] jdbc.TestDriver: INFO : Compiling command(queryId=hive_20230118124133_a1857530-bfbe-4cd7-af0c-1f5ff3f899f7): analyze table mv_filter compute statistics for columns
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Semantic Analysis Completed (retrial = false)
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Created Hive schema: Schema(fieldSchemas:[FieldSchema(name:columntype0, type:string, comment:null), FieldSchema(name:min0, type:bigint, comment:null), FieldSchema(name:max0, type:bigint, comment:null), FieldSchema(name:countnulls0, type:bigint, comment:null), FieldSchema(name:numdistinctvalues0, type:bigint, comment:null), FieldSchema(name:ndvbitvector0, type:binary, comment:null), FieldSchema(name:columntype1, type:string, comment:null), FieldSchema(name:min1, type:bigint, comment:null), FieldSchema(name:max1, type:bigint, comment:null), FieldSchema(name:countnulls1, type:bigint, comment:null), FieldSchema(name:numdistinctvalues1, type:bigint, comment:null), FieldSchema(name:ndvbitvector1, type:binary, comment:null)], properties:null)
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Completed compiling command(queryId=hive_20230118124133_a1857530-bfbe-4cd7-af0c-1f5ff3f899f7); Time taken: 0.21 seconds
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Executing command(queryId=hive_20230118124133_a1857530-bfbe-4cd7-af0c-1f5ff3f899f7): analyze table mv_filter compute statistics for columns
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Compute 'qe-vw-dwx-hive-oqoa' is active.
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Query ID = hive_20230118124133_a1857530-bfbe-4cd7-af0c-1f5ff3f899f7
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Total jobs = 1
> 2023-01-18T12:41:34,293 INFO [Thread-5] jdbc.TestDriver: INFO : Launching Job 1 out of 1
> 2023-01-18T12:41:34,294 INFO [Thread-5] jdbc.TestDriver: INFO : Starting task [Stage-0:MAPRED] in serial mode
> 2023-01-18T12:41:34,294 INFO [Thread-5] jdbc.TestDriver: INFO : Subscribed to counters: [] for queryId: hive_20230118124133_a1857530-bfbe-4cd7-af0c-1f5ff3f899f7
> 2023-01-18T12:41:34,294 INFO [Thread-5] jdbc.TestDriver: INFO : Tez session hasn't been created yet. Opening session
> 2023-01-18T12:41:34,294 INFO [Thread-5] jdbc.TestDriver: INFO : Dag name: analyze table mv_filter compute st...columns (Stage-0)
> 2023-01-18T12:41:34,294 INFO [Thread-5] jdbc.TestDriver: INFO : HS2 Host: [hiveserver2-0], Query ID: [hive_20230118124133_a1857530-bfbe-4cd7-af0c-1f5ff3f899f7], Dag ID: [dag_1674041835066_0001_172], DAG Session ID: [application_1674041835066_0001]
> 2023-01-18T12:41:34,294 INFO [Thread-5] jdbc.TestDriver: INFO : Status: Running (Executing on YARN cluster with App id application_1674041835066_0001)
> 2023-01-18T12:41:34,294 INFO [Thread-5] jdbc.TestDriver:
> 2023-01-18T12:41:35,392 INFO [Thread-5] jdbc.TestDriver: INFO : Status: DAG finished successfully in 0.77 seconds
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : DAG ID: dag_1674041835066_0001_172
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : Query Execution Summary
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : OPERATION DURATION
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : Compile Query 0.21s
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : Prepare Plan 0.06s
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : Get Query Coordinator (AM) 0.06s
> 2023-01-18T12:41:35,393 INFO [Thread-5] jdbc.TestDriver: INFO : Submit Plan 0.01s
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : Start DAG 0.01s
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : Run DAG 0.77s
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : Task Execution Summary
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : VERTICES DURATION(ms) CPU_TIME(ms) GC_TIME(ms) INPUT_RECORDS OUTPUT_RECORDS
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : Map 1 267.00 0 0 4,718 1
> 2023-01-18T12:41:35,394 INFO [Thread-5] jdbc.TestDriver: INFO : Reducer 2 0.00 0 0 1 0
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO : LLAP IO Summary
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO : VERTICES ROWGROUPS META_HIT META_MISS DATA_HIT DATA_MISS TOTAL_IO
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO : Map 1 0 0 0 0B 0B 0.00s
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,395 INFO [Thread-5] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : FileSystem Counters Summary
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : Scheme: S3A
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : Map 1 21.58KB 3 0 0B 0
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : Reducer 2 0B 0 0 0B 0
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,396 INFO [Thread-5] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : Scheme: FILE
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : Map 1 0B 0 0 778B 0
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : Reducer 2 646B 0 0 1.38KB 0
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : ----------------------------------------------------------------------------------------------
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO :
> 2023-01-18T12:41:35,397 INFO [Thread-5] jdbc.TestDriver: INFO : org.apache.tez.common.counters.DAGCounter:
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : NUM_SUCCEEDED_TASKS: 2
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : TOTAL_LAUNCHED_TASKS: 2
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : RACK_LOCAL_TASKS: 1
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : AM_CPU_MILLISECONDS: 150
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : AM_GC_TIME_MILLIS: 0
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : File System Counters:
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : FILE_BYTES_READ: 646
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : FILE_BYTES_WRITTEN: 2156
> 2023-01-18T12:41:35,398 INFO [Thread-5] jdbc.TestDriver: INFO : FILE_READ_OPS: 0
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : FILE_LARGE_READ_OPS: 0
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : FILE_WRITE_OPS: 0
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : S3A_BYTES_READ: 21576
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : S3A_BYTES_WRITTEN: 0
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : S3A_READ_OPS: 3
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : S3A_LARGE_READ_OPS: 0
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : S3A_WRITE_OPS: 0
> 2023-01-18T12:41:35,399 INFO [Thread-5] jdbc.TestDriver: INFO : org.apache.tez.common.counters.TaskCounter:
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : SPILLED_RECORDS: 0
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : NUM_SHUFFLED_INPUTS: 1
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : NUM_FAILED_SHUFFLE_INPUTS: 0
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : TASK_DURATION_MILLIS: 405
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : INPUT_RECORDS_PROCESSED: 4719
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : INPUT_SPLIT_LENGTH_BYTES: 20584
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : OUTPUT_RECORDS: 1
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : APPROXIMATE_INPUT_RECORDS: 1
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : OUTPUT_LARGE_RECORDS: 0
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : OUTPUT_BYTES: 933
> 2023-01-18T12:41:35,400 INFO [Thread-5] jdbc.TestDriver: INFO : OUTPUT_BYTES_WITH_OVERHEAD: 943
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : OUTPUT_BYTES_PHYSICAL: 670
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : ADDITIONAL_SPILLS_BYTES_WRITTEN: 0
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : ADDITIONAL_SPILLS_BYTES_READ: 0
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : ADDITIONAL_SPILL_COUNT: 0
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : SHUFFLE_BYTES: 646
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : SHUFFLE_BYTES_DECOMPRESSED: 943
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : SHUFFLE_BYTES_TO_MEM: 0
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : SHUFFLE_BYTES_TO_DISK: 0
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : SHUFFLE_BYTES_DISK_DIRECT: 646
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : SHUFFLE_PHASE_TIME: 2
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : FIRST_EVENT_RECEIVED: 1
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : LAST_EVENT_RECEIVED: 1
> 2023-01-18T12:41:35,401 INFO [Thread-5] jdbc.TestDriver: INFO : DATA_BYTES_VIA_EVENT: 0
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : HIVE:
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : CREATED_FILES: 1
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : DESERIALIZE_ERRORS: 0
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_IN_Map_1: 4718
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_0: 1
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_INTERMEDIATE_Map_1: 1
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_INTERMEDIATE_Reducer_2: 0
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_FS_6: 1
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_GBY_2: 1
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_GBY_4: 1
> 2023-01-18T12:41:35,402 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_MAP_0: 0
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_RS_3: 1
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_SEL_1: 4718
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_SEL_5: 1
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : RECORDS_OUT_OPERATOR_TS_0: 4718
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : org.apache.hadoop.hive.llap.counters.LlapWmCounters:
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : GUARANTEED_QUEUED_NS: 0
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : GUARANTEED_RUNNING_NS: 0
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : SPECULATIVE_QUEUED_NS: 137174
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : SPECULATIVE_RUNNING_NS: 401635891
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : org.apache.hadoop.hive.llap.daemon.impl.StatsRecordingThreadPool$WrappedCallable$LlapExecutorCounters:
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : EXECUTOR_CPU_NS: 66245919
> 2023-01-18T12:41:35,403 INFO [Thread-5] jdbc.TestDriver: INFO : EXECUTOR_USER_NS: 40000000
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : org.apache.hadoop.hive.ql.exec.tez.HiveInputCounters:
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : GROUPED_INPUT_SPLITS_Map_1: 1
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : INPUT_DIRECTORIES_Map_1: 1
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : INPUT_FILES_Map_1: 1
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : RAW_INPUT_SPLITS_Map_1: 1
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : Starting task [Stage-2:STATS] in serial mode
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : Executing stats task
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : Table iceberg_test_db_hive.mv_filter stats: [numFiles=1, numRows=4718, totalSize=20588]
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : Table iceberg_test_db_hive.mv_filter stats: [numFiles=1, numRows=4718, totalSize=20588]
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : Completed executing command(queryId=hive_20230118124133_a1857530-bfbe-4cd7-af0c-1f5ff3f899f7); Time taken: 1.388 seconds
> 2023-01-18T12:41:35,404 INFO [Thread-5] jdbc.TestDriver: INFO : OK
> 2023-01-18T12:41:35,555 INFO [pool-3-thread-1] jdbc.TestDriver: No output to verify
> 2023-01-18T12:41:35,556 INFO [pool-3-thread-1] jdbc.TestDriver: Query: set hive.explain.user=false
> 2023-01-18T12:41:35,778 INFO [pool-3-thread-1] jdbc.TestDriver: No output to verify
> 2023-01-18T12:41:35,779 INFO [pool-3-thread-1] jdbc.TestDriver: Query: explain select si,t from all100k where t>116 and t<120
> 2023-01-18T12:41:35,836 INFO [Thread-7] jdbc.TestDriver: INFO : Compiling command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e): explain select si,t from all100k where t>116 and t<120
> 2023-01-18T12:41:36,352 INFO [Thread-7] jdbc.TestDriver: INFO : No Stats for iceberg_test_db_hive@all100k, Columns: t, si
> 2023-01-18T12:41:36,353 INFO [Thread-7] jdbc.TestDriver: INFO : Semantic Analysis Completed (retrial = false)
> 2023-01-18T12:41:36,353 INFO [Thread-7] jdbc.TestDriver: INFO : Created Hive schema: Schema(fieldSchemas:[FieldSchema(name:Explain, type:string, comment:null)], properties:null)
> 2023-01-18T12:41:36,353 INFO [Thread-7] jdbc.TestDriver: INFO : Completed compiling command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e); Time taken: 0.458 seconds
> 2023-01-18T12:41:36,353 INFO [Thread-7] jdbc.TestDriver: INFO : Executing command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e): explain select si,t from all100k where t>116 and t<120
> 2023-01-18T12:41:36,353 INFO [Thread-7] jdbc.TestDriver: INFO : Starting task [Stage-1:EXPLAIN] in serial mode
> 2023-01-18T12:41:36,353 INFO [Thread-7] jdbc.TestDriver: INFO : Completed executing command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e); Time taken: 0.039 seconds
> 2023-01-18T12:41:36,353 INFO [Thread-7] jdbc.TestDriver: INFO : OK
> 2023-01-18T12:41:36,605 ERROR [pool-3-thread-1] jdbc.TestDriver: RESULTSET DOES NOT CONTAIN ROW [ alias: iceberg_test_db_hive.mv_filter]
> 2023-01-18T12:41:36,607 INFO [pool-3-thread-1] jdbc.TestDriver: Wrote 18 rows to /hwqe/hadoopqe/artifacts/logs_907762/mv_filter_actual.out
> 2023-01-18T12:41:36,608 INFO [pool-2-thread-1] jdbc.TestDriver: Ending Test at 2023-01-18 12:41:36,608
> 2023-01-18T12:41:36,608 INFO [pool-2-thread-1] jdbc.TestDriver: TEST FAILED in 12 seconds.
> 2023-01-18T12:41:36,608 INFO [pool-2-thread-1] jdbc.TestDriver: Annotations: [iceberg] {code}
> HS2 logs
> {code:java}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.792Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="common.LogUtils" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="e0dfe716-fd63-4766-a6f0-2bc5f973086c etp1139946296-77"] Thread context registration is done.
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.792Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="operation.Operation" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="e0dfe716-fd63-4766-a6f0-2bc5f973086c etp1139946296-77"] [opType=EXECUTE_STATEMENT, queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e, startTime=1674045695792, sessionId=e0dfe716-fd63-4766-a6f0-2bc5f973086c, createTime=1674045684580, userName=dwxdevuser, ipAddress=127.0.0.6]
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.793Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="common.LogUtils" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Thread context registration is done.
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=waitCompile from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=waitCompile start=1674045695794 end=1674045695794 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Compiling command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e): explain select si,t from all100k where t>116 and t<120
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=parse start=1674045695794 end=1674045695794 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.794Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.807Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="lockmgr.DbTxnManager" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Opened txnid:561
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.811Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.ExplainSemanticAnalyzer" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Starting caching scope for: hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.811Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.QueryState" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Query-level HMS cache created for hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.812Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Starting Semantic Analysis
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.817Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Completed phase 1 of Semantic Analysis
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.817Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Get metadata for source tables
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.856Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="iceberg.BaseMetastoreTableOperations" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Refreshing table metadata from new version: s3a://qe-s3-bucket-weekly-5x7j-dwx-external/clusters/env-tp5x7j/warehouse-1674041252-cnc7/warehouse/tablespace/external/hive/iceberg_test_db_hive.db/all100k/metadata/00001-b0ebb286-f600-485a-a94f-46e00040b5f6.metadata.json
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.969Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="iceberg.BaseMetastoreCatalog" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Table loaded by catalog: default_iceberg.iceberg_test_db_hive.all100k
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.969Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Get metadata for subqueries
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.969Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Get metadata for destination tables
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.969Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Context" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] New scratch dir is file:/efs/hive/scratch/hive/e0dfe716-fd63-4766-a6f0-2bc5f973086c/hive_2023-01-18_12-41-35_794_7125415520781922843-255
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.969Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Completed getting MetaData in Semantic Analysis
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.969Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:35.970Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hive.HiveIcebergSerDe" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Using schema from existing table {"type":"struct","schema-id":0,"fields":[{"id":1,"name":"t","required":false,"type":"int"},{"id":2,"name":"si","required":false,"type":"int"},{"id":3,"name":"i","required":false,"type":"int"},{"id":4,"name":"b","required":false,"type":"long"},{"id":5,"name":"f","required":false,"type":"float"},{"id":6,"name":"d","required":false,"type":"double"},{"id":7,"name":"s","required":false,"type":"string"},{"id":8,"name":"dc","required":false,"type":"decimal(38, 18)"},{"id":9,"name":"bo","required":false,"type":"boolean"},{"id":10,"name":"v","required":false,"type":"string"},{"id":11,"name":"c","required":false,"type":"string"},{"id":12,"name":"ts","required":false,"type":"timestamp"},{"id":13,"name":"dt","required":false,"type":"date"}]}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.970Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=getTableConstraints from=org.apache.hadoop.hive.ql.metadata.Hive>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.986Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=getTableConstraints start=1674045695970 end=1674045695986 duration=16 from=org.apache.hadoop.hive.ql.metadata.Hive HS2-cache>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.987Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045695969 end=1674045695987 duration=18 from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction Calcite: Plan generation>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:35.988Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.001Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=partition-retrieving from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.001Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=partition-retrieving start=1674045696001 end=1674045696001 duration=0 from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.001Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="calcite.RelOptHiveTable" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Calculating column statistics for iceberg_test_db_hive.all100k, projIndxSet: [0, 1], allowMissingStats: true
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.001Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=getTableColumnStatistics from=org.apache.hadoop.hive.ql.metadata.Hive>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.018Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=getTableColumnStatistics start=1674045696001 end=1674045696018 duration=17 from=org.apache.hadoop.hive.ql.metadata.Hive HS2-cache>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<12>1 2023-01-18T12:41:36.019Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="calcite.RelOptHiveTable" level="WARN" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] No Stats for iceberg_test_db_hive@all100k, Columns: t, si
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.019Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="SessionState" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] No Stats for iceberg_test_db_hive@all100k, Columns: t, si
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.019Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045695988 end=1674045696019 duration=31 from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction Calcite: Prejoin ordering transformation>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.020Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hive.HiveIcebergSerDe" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Using schema from existing table {"type":"struct","schema-id":0,"fields":[{"id":1,"name":"t","required":false,"type":"int"},{"id":2,"name":"si","required":false,"type":"int"},{"id":3,"name":"i","required":false,"type":"int"},{"id":4,"name":"b","required":false,"type":"long"},{"id":5,"name":"f","required":false,"type":"float"},{"id":6,"name":"d","required":false,"type":"double"},{"id":7,"name":"s","required":false,"type":"string"},{"id":8,"name":"dc","required":false,"type":"decimal(38, 18)"},{"id":9,"name":"bo","required":false,"type":"boolean"},{"id":10,"name":"v","required":false,"type":"string"},{"id":11,"name":"c","required":false,"type":"string"},{"id":12,"name":"ts","required":false,"type":"timestamp"},{"id":13,"name":"dt","required":false,"type":"date"}]}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.021Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hive.HiveIcebergSerDe" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Using schema from existing table {"type":"struct","schema-id":0,"fields":[{"id":1,"name":"t","required":false,"type":"int"},{"id":2,"name":"si","required":false,"type":"int"},{"id":3,"name":"i","required":false,"type":"int"},{"id":4,"name":"b","required":false,"type":"long"},{"id":5,"name":"f","required":false,"type":"float"},{"id":6,"name":"d","required":false,"type":"double"},{"id":7,"name":"s","required":false,"type":"string"},{"id":8,"name":"dc","required":false,"type":"decimal(38, 18)"},{"id":9,"name":"bo","required":false,"type":"boolean"},{"id":10,"name":"v","required":false,"type":"string"},{"id":11,"name":"c","required":false,"type":"string"},{"id":12,"name":"ts","required":false,"type":"timestamp"},{"id":13,"name":"dt","required":false,"type":"date"}]}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.022Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hive.HiveIcebergSerDe" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Using schema from existing table {"type":"struct","schema-id":0,"fields":[{"id":1,"name":"t","required":false,"type":"int"},{"id":2,"name":"si","required":false,"type":"int"},{"id":3,"name":"i","required":false,"type":"int"},{"id":4,"name":"b","required":false,"type":"long"},{"id":5,"name":"f","required":false,"type":"float"},{"id":6,"name":"d","required":false,"type":"double"},{"id":7,"name":"s","required":false,"type":"string"},{"id":8,"name":"dc","required":false,"type":"decimal(38, 18)"},{"id":9,"name":"bo","required":false,"type":"boolean"},{"id":10,"name":"v","required":false,"type":"string"},{"id":11,"name":"c","required":false,"type":"string"},{"id":12,"name":"ts","required":false,"type":"timestamp"},{"id":13,"name":"dt","required":false,"type":"date"}]}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.023Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.025Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=partition-retrieving from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.025Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=partition-retrieving start=1674045696025 end=1674045696025 duration=0 from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.026Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="stats.BasicStats" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Number of partishes : 1
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.026Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=partition-retrieving from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.026Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=partition-retrieving start=1674045696026 end=1674045696026 duration=0 from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.026Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="stats.BasicStats" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Number of partishes : 1
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.054Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="stats.BasicStats" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Number of partishes : 1
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.055Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="stats.BasicStats" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Number of partishes : 1
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.075Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696023 end=1674045696074 duration=51 from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction Calcite: View-based rewriting>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.146Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="iceberg.BaseMetastoreTableOperations" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Refreshing table metadata from new version: s3a://qe-s3-bucket-weekly-5x7j-dwx-managed/clusters/env-tp5x7j/warehouse-1674041252-cnc7/warehouse/tablespace/managed/hive/iceberg_test_db_hive.db/mv_rewrite/metadata/00001-06e9194a-4a9a-4410-8b0f-d8e1945bcb86.metadata.json
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.185Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="iceberg.BaseMetastoreCatalog" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Table loaded by catalog: default_iceberg.iceberg_test_db_hive.mv_rewrite
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.187Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hive.HiveIcebergSerDe" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Using schema from existing table {"type":"struct","schema-id":0,"fields":[{"id":1,"name":"t","required":false,"type":"int"},{"id":2,"name":"si","required":false,"type":"int"},{"id":3,"name":"i","required":false,"type":"int"},{"id":4,"name":"b","required":false,"type":"long"},{"id":5,"name":"f","required":false,"type":"float"},{"id":6,"name":"d","required":false,"type":"double"},{"id":7,"name":"s","required":false,"type":"string"},{"id":8,"name":"dc","required":false,"type":"decimal(38, 18)"},{"id":9,"name":"bo","required":false,"type":"boolean"},{"id":10,"name":"v","required":false,"type":"string"},{"id":11,"name":"c","required":false,"type":"string"},{"id":12,"name":"ts","required":false,"type":"timestamp"},{"id":13,"name":"dt","required":false,"type":"date"}]}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.192Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.204Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="calcite.RelOptHiveTable" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Calculating column statistics for iceberg_test_db_hive.mv_rewrite, projIndxSet: [0, 1], allowMissingStats: true
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.205Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=getTableColumnStatistics from=org.apache.hadoop.hive.ql.metadata.Hive>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.221Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=getTableColumnStatistics start=1674045696205 end=1674045696221 duration=16 from=org.apache.hadoop.hive.ql.metadata.Hive HS2-cache>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.221Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696192 end=1674045696221 duration=29 from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction Calcite: Prejoin ordering transformation>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.222Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.233Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696222 end=1674045696233 duration=11 from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction Calcite: Postjoin ordering transformation>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.244Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Get metadata for source tables
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.245Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Get metadata for subqueries
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.245Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Get metadata for destination tables
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.245Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Context" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] New scratch dir is file:/efs/hive/scratch/hive/e0dfe716-fd63-4766-a6f0-2bc5f973086c/hive_2023-01-18_12-41-35_794_7125415520781922843-255
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.245Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hive.HiveIcebergSerDe" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Using schema from existing table {"type":"struct","schema-id":0,"fields":[{"id":1,"name":"t","required":false,"type":"int"},{"id":2,"name":"si","required":false,"type":"int"}]}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.246Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Context" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] New scratch dir is file:/efs/hive/scratch/hive/e0dfe716-fd63-4766-a6f0-2bc5f973086c/hive_2023-01-18_12-41-35_794_7125415520781922843-255
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.246Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] CBO Succeeded; optimized logical plan.
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.246Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hive.HiveIcebergSerDe" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Using schema from existing table {"type":"struct","schema-id":0,"fields":[{"id":1,"name":"t","required":false,"type":"int"},{"id":2,"name":"si","required":false,"type":"int"},{"id":3,"name":"i","required":false,"type":"int"},{"id":4,"name":"b","required":false,"type":"long"},{"id":5,"name":"f","required":false,"type":"float"},{"id":6,"name":"d","required":false,"type":"double"},{"id":7,"name":"s","required":false,"type":"string"},{"id":8,"name":"dc","required":false,"type":"decimal(38, 18)"},{"id":9,"name":"bo","required":false,"type":"boolean"},{"id":10,"name":"v","required":false,"type":"string"},{"id":11,"name":"c","required":false,"type":"string"},{"id":12,"name":"ts","required":false,"type":"timestamp"},{"id":13,"name":"dt","required":false,"type":"date"}]}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.calcite.translator.HiveOpConverterPostProc>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696247 end=1674045696247 duration=0 from=org.apache.hadoop.hive.ql.optimizer.calcite.translator.HiveOpConverterPostProc org.apache.hadoop.hive.ql.optimizer.calcite.translator.HiveOpConverterPostProc@6c92edb3>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.lineage.Generator>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696247 end=1674045696247 duration=0 from=org.apache.hadoop.hive.ql.optimizer.lineage.Generator org.apache.hadoop.hive.ql.optimizer.lineage.Generator@13c97feb>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.PartitionColumnsSeparator>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696247 end=1674045696247 duration=0 from=org.apache.hadoop.hive.ql.optimizer.PartitionColumnsSeparator org.apache.hadoop.hive.ql.optimizer.PartitionColumnsSeparator@430659a7>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.ppd.SyntheticJoinPredicate>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696247 end=1674045696247 duration=0 from=org.apache.hadoop.hive.ql.ppd.SyntheticJoinPredicate org.apache.hadoop.hive.ql.ppd.SyntheticJoinPredicate@419fdbdc>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.247Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.ppd.SimplePredicatePushDown>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696247 end=1674045696248 duration=1 from=org.apache.hadoop.hive.ql.ppd.SimplePredicatePushDown org.apache.hadoop.hive.ql.ppd.SimplePredicatePushDown@22ca8038>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.RedundantDynamicPruningConditionsRemoval>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.RedundantDynamicPruningConditionsRemoval org.apache.hadoop.hive.ql.optimizer.RedundantDynamicPruningConditionsRemoval@61a906fd>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.SortedDynPartitionTimeGranularityOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.SortedDynPartitionTimeGranularityOptimizer org.apache.hadoop.hive.ql.optimizer.SortedDynPartitionTimeGranularityOptimizer@3a8a6071>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner@7ffc48a1>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.pcr.PartitionConditionRemover>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=partition-retrieving from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=partition-retrieving start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.pcr.PartitionConditionRemover org.apache.hadoop.hive.ql.optimizer.pcr.PartitionConditionRemover@713c5398>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.GroupByOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.GroupByOptimizer org.apache.hadoop.hive.ql.optimizer.GroupByOptimizer@22ecdec9>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.ColumnPruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.ColumnPruner org.apache.hadoop.hive.ql.optimizer.ColumnPruner@7bcc2982>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.CountDistinctRewriteProc>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.CountDistinctRewriteProc org.apache.hadoop.hive.ql.optimizer.CountDistinctRewriteProc@7fb63ce7>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.SamplePruner>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.SamplePruner org.apache.hadoop.hive.ql.optimizer.SamplePruner@4fc4a6de>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.MapJoinProcessor>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.MapJoinProcessor org.apache.hadoop.hive.ql.optimizer.MapJoinProcessor@6a9e33ba>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.248Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.BucketingSortingReduceSinkOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696248 end=1674045696248 duration=0 from=org.apache.hadoop.hive.ql.optimizer.BucketingSortingReduceSinkOptimizer org.apache.hadoop.hive.ql.optimizer.BucketingSortingReduceSinkOptimizer@6794ab2f>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.unionproc.UnionProcessor>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.unionproc.UnionProcessor org.apache.hadoop.hive.ql.optimizer.unionproc.UnionProcessor@22667ede>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.JoinReorder>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.JoinReorder org.apache.hadoop.hive.ql.optimizer.JoinReorder@11f09f0b>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.FixedBucketPruningOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.FixedBucketPruningOptimizer org.apache.hadoop.hive.ql.optimizer.FixedBucketPruningOptimizer@4429034b>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.BucketVersionPopulator>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="optimizer.BucketVersionPopulator" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] not considering bucketingVersion for: %s because it has %d<2 buckets
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.BucketVersionPopulator org.apache.hadoop.hive.ql.optimizer.BucketVersionPopulator@733b47d4>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.correlation.ReduceSinkDeDuplication>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.correlation.ReduceSinkDeDuplication org.apache.hadoop.hive.ql.optimizer.correlation.ReduceSinkDeDuplication@1de712ab>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.NonBlockingOpDeDupProc>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.NonBlockingOpDeDupProc org.apache.hadoop.hive.ql.optimizer.NonBlockingOpDeDupProc@43a53144>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.IdentityProjectRemover>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.IdentityProjectRemover org.apache.hadoop.hive.ql.optimizer.IdentityProjectRemover@d4b8cf8>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.GlobalLimitOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="optimizer.GlobalLimitOptimizer" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Not enabling limit optimization on non native table: mv_rewrite
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.GlobalLimitOptimizer org.apache.hadoop.hive.ql.optimizer.GlobalLimitOptimizer@186d6f7>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.LimitPushdownOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.LimitPushdownOptimizer org.apache.hadoop.hive.ql.optimizer.LimitPushdownOptimizer@4c3463bf>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.OrderlessLimitPushDownOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.OrderlessLimitPushDownOptimizer org.apache.hadoop.hive.ql.optimizer.OrderlessLimitPushDownOptimizer@f41452c>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.StatsOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696249 duration=0 from=org.apache.hadoop.hive.ql.optimizer.StatsOptimizer org.apache.hadoop.hive.ql.optimizer.StatsOptimizer@5f6b0dbf>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.249Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=optimizer from=org.apache.hadoop.hive.ql.optimizer.SimpleFetchOptimizer>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.251Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=optimizer start=1674045696249 end=1674045696251 duration=2 from=org.apache.hadoop.hive.ql.optimizer.SimpleFetchOptimizer org.apache.hadoop.hive.ql.optimizer.SimpleFetchOptimizer@82656da>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.251Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Completed plan generation
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.251Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="parse.CalcitePlanner" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Not eligible for results caching - no mr/tez/impala jobs
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.251Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Semantic Analysis Completed (retrial = false)
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.251Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=semanticAnalyze start=1674045695794 end=1674045696251 duration=457 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.251Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Created Hive schema: Schema(fieldSchemas:[FieldSchema(name:Explain, type:string, comment:null)], properties:null)
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.251Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=doAuthorization from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=doAuthorization start=1674045696251 end=1674045696252 duration=1 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=compile start=1674045695794 end=1674045696252 duration=458 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="metadata.Hive" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Dumping metastore api call timing information for : compilation phase
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="metadata.Hive" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Total time spent in each metastore function (ms): {openTxn_(String, TxnType)=12, getTableColumnStatistics_(String, String, List, String)=33, isCompatibleWith_(Configuration)=0, getAllTableConstraints_(AllTableConstraintsRequest)=16, getTable_(String, String, String, String, boolean, String, boolean)=152, commitTxn_(CommitTxnRequest)=16, getValidWriteIds_(List, String)=10, getTable_(String, String, boolean, String)=110, getValidTxns_(long)=4}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Completed compiling command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e); Time taken: 0.458 seconds
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="reexec.ReExecDriver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Execution #1 of query
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Executing command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e): explain select si,t from all100k where t>116 and t<120
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=PreHook.org.apache.hadoop.hive.ql.hooks.HiveProtoLoggingHook from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.252Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hooks.HiveProtoLoggingHook" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Received pre-hook notification for: hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.255Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=PreHook.org.apache.hadoop.hive.ql.hooks.HiveProtoLoggingHook start=1674045696252 end=1674045696255 duration=3 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.255Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=PreHook.com.github.cloudera.ComputeUnidlingHook from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.255Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=PreHook.com.github.cloudera.ComputeUnidlingHook start=1674045696255 end=1674045696255 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.256Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=PreHook.org.apache.hadoop.hive.ql.security.authorization.plugin.DisallowTransformHook from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.256Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=PreHook.org.apache.hadoop.hive.ql.security.authorization.plugin.DisallowTransformHook start=1674045696256 end=1674045696256 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.256Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.256Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Starting task [Stage-1:EXPLAIN] in serial mode
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=runTasks start=1674045696256 end=1674045696291 duration=35 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=PostHook.org.apache.hadoop.hive.ql.stats.OperatorStatsReaderHook from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=PostHook.org.apache.hadoop.hive.ql.stats.OperatorStatsReaderHook start=1674045696291 end=1674045696291 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=PostHook.org.apache.hadoop.hive.ql.hooks.HiveProtoLoggingHook from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="hooks.HiveProtoLoggingHook" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Received post-hook notification for: hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=PostHook.org.apache.hadoop.hive.ql.hooks.HiveProtoLoggingHook start=1674045696291 end=1674045696291 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=PostHook.com.github.cloudera.ComputeUnidlingHook from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=PostHook.com.github.cloudera.ComputeUnidlingHook start=1674045696291 end=1674045696291 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=PostHook.org.apache.atlas.hive.hook.HiveHook from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=PostHook.org.apache.atlas.hive.hook.HiveHook start=1674045696291 end=1674045696291 duration=0 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=Driver.execute start=1674045696252 end=1674045696291 duration=39 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="metadata.Hive" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Dumping metastore api call timing information for : execution phase
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="metadata.Hive" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Total time spent in each metastore function (ms): {isCompatibleWith_(Configuration)=0}
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Completed executing command(queryId=hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e); Time taken: 0.039 seconds
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="ql.Driver" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] OK
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.291Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="lockmgr.DbTxnManager" level="INFO" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] Stopped heartbeat for query: hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.307Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=releaseLocks start=1674045696291 end=1674045696307 duration=16 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<15>1 2023-01-18T12:41:36.307Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="log.PerfLogger" level="DEBUG" operationLogLevel="EXECUTION" queryId="hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e" sessionId="e0dfe716-fd63-4766-a6f0-2bc5f973086c" thread="HiveServer2-Background-Pool: Thread-7997"] </PERFLOG method=Driver.run start=1674045695794 end=1674045696307 duration=513 from=org.apache.hadoop.hive.ql.Driver>
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.570Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="operation.OperationManager" level="INFO" thread="e0dfe716-fd63-4766-a6f0-2bc5f973086c etp1139946296-77"] Removed queryId: hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e corresponding to operation: OperationHandle [opType=EXECUTE_STATEMENT, getHandleIdentifier()=9305a75b-c3ae-48bd-af2a-65c977a37788] with tag: null
> ./2023-01-18-12-40_hiveserver2_hiveserver2-0_b55faa38-ea9b-4a5d-b69b-210e0bc25824_0.log.gz:<14>1 2023-01-18T12:41:36.587Z hiveserver2-0 hiveserver2 1 b55faa38-ea9b-4a5d-b69b-210e0bc25824 [mdc@18060 class="operation.Operation" level="INFO" thread="e0dfe716-fd63-4766-a6f0-2bc5f973086c etp1139946296-77"] Closing operation log /tmp/hive/operation_logs/e0dfe716-fd63-4766-a6f0-2bc5f973086c/hive_20230118124135_138cc103-c7fe-40f3-be3a-f348b4ffd71e without delay {code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)