[
https://issues.apache.org/jira/browse/IMPALA-12997?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17836321#comment-17836321
]
Michael Smith edited comment on IMPALA-12997 at 4/11/24 7:04 PM:
-----------------------------------------------------------------
Relevant catalogd logs from when the error first started
{code}
I0410 12:47:58.355312 3681745 catalog-server.cc:616] A catalog update with 2
entries is assembled. Catalog version: 2135 Last sent catalog version: 2133
I0410 12:47:58.473973 3681750 TAcceptQueueServer.cpp:355] New connection to
server CatalogService from client <Host: 127.0.0.1 Port: 54134>
I0410 12:47:58.478902 3681750 TAcceptQueueServer.cpp:355] New connection to
server CatalogService from client <Host: 127.0.0.1 Port: 54140>
I0410 12:47:58.491712 3681796 JniUtil.java:166]
e040d751d8ffae68:d64122e100000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:58.491765 3681795 JniUtil.java:166]
6041e7dc71f87b5b:9a4ff6f000000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:58.492286 3681795 JniUtil.java:177]
6041e7dc71f87b5b:9a4ff6f000000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent: 1ms
I0410 12:47:58.492334 3681796 JniUtil.java:177]
e040d751d8ffae68:d64122e100000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent: 1ms
I0410 12:47:58.492388 3681327 TableLoadingMgr.java:310] Metadata load request
already in progress for table: sys.impala_query_log
I0410 12:47:58.494186 3681797 TableLoader.java:81] Loading metadata for:
sys.impala_query_log (background load)
I0410 12:47:58.494704 3681326 TableLoadingMgr.java:74] Loading metadata for
table: sys.impala_query_log
I0410 12:47:58.494817 3681326 TableLoadingMgr.java:76] Remaining items in
queue: 0. Loads in progress: 1
I0410 12:47:58.536164 3681797 Table.java:248] createEventId_ for table:
sys.impala_query_log set to: -1
W0410 12:47:58.575927 3681797 HiveConf.java:6718] HiveConf of name
hive.metastore.partitions.parameters.exclude.pattern does not exist
I0410 12:47:58.603469 3681797 CatalogUtil.java:302] Loading custom FileIO
implementation: org.apache.iceberg.hadoop.HadoopFileIO
W0410 12:47:58.681820 3681797 HiveConf.java:6718] HiveConf of name
hive.metastore.partitions.parameters.exclude.pattern does not exist
I0410 12:47:58.686848 3681797 HiveMetaStoreClient.java:280] HMS client
filtering is enabled.
I0410 12:47:58.687023 3681797 HiveMetaStoreClient.java:738] Trying to connect
to metastore with URI (thrift://localhost:9083) in binary transport mode
I0410 12:47:58.687292 3681797 HiveMetaStoreClient.java:769] Opened a connection
to metastore, URI (thrift://localhost:9083) current connections: 11
I0410 12:47:58.687708 3681797 HiveMetaStoreClient.java:839] Connected to
metastore.
I0410 12:47:58.687781 3681797 RetryingMetaStoreClient.java:100]
RetryingMetaStoreClient proxy=class
org.apache.hadoop.hive.metastore.HiveMetaStoreClient ugi=jenkins (auth:SIMPLE)
retries=1 delay=1 lifetime=0
I0410 12:47:58.696296 3681797 BaseMetastoreTableOperations.java:199] Refreshing
table metadata from new version:
hdfs://localhost:20500/test-warehouse/sys.db/impala_query_log/metadata/00004-f507db8e-8d90-476e-b09b-c7c81a608641.metadata.json
I0410 12:47:59.041594 3681797 BaseMetastoreCatalog.java:67] Table loaded by
catalog: ImpalaHiveCatalog.sys.impala_query_log
I0410 12:47:59.066388 3681797 SnapshotScan.java:124] Scanning table
ImpalaHiveCatalog.sys.impala_query_log snapshot 4998562745977744358 created at
2024-04-10T19:47:53.382+00:00 with filter true
I0410 12:47:59.360441 3681797 LoggingMetricsReporter.java:38] Received metrics
report: ScanReport{tableName=ImpalaHiveCatalog.sys.impala_query_log,
snapshotId=4998562745977744358, filter=true, schemaId=0, projectedFieldIds=[1,
2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23,
24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43,
44, 45, 46, 47, 48, 49], projectedFieldNames=[cluster_id, query_id, session_id,
session_type, hiveserver2_protocol_version, db_user, db_user_connection,
db_name, impala_coordinator, query_status, query_state, impala_query_end_state,
query_type, network_address, start_time_utc, total_time_ms, query_opts_config,
resource_pool, per_host_mem_estimate, dedicated_coord_mem_estimate,
per_host_fragment_instances, backends_count, admission_result,
cluster_memory_admitted, executor_group, executor_groups, exec_summary,
num_rows_fetched, row_materialization_rows_per_sec,
row_materialization_time_ms, compressed_bytes_spilled, event_planning_finished,
event_submit_for_admission, event_completed_admission,
event_all_backends_started, event_rows_available, event_first_row_fetched,
event_last_row_fetched, event_unregister_query, read_io_wait_total_ms,
read_io_wait_mean_ms, bytes_read_cache_total, bytes_read_total,
pernode_peak_mem_min, pernode_peak_mem_max, pernode_peak_mem_mean, sql, plan,
tables_queried],
scanMetrics=ScanMetricsResult{totalPlanningDuration=TimerResult{timeUnit=NANOSECONDS,
totalDuration=PT0.269319826S, count=1},
resultDataFiles=CounterResult{unit=COUNT, value=4},
resultDeleteFiles=CounterResult{unit=COUNT, value=0},
totalDataManifests=CounterResult{unit=COUNT, value=4},
totalDeleteManifests=CounterResult{unit=COUNT, value=0},
scannedDataManifests=CounterResult{unit=COUNT, value=4},
skippedDataManifests=CounterResult{unit=COUNT, value=0},
totalFileSizeInBytes=CounterResult{unit=BYTES, value=117588},
totalDeleteFileSizeInBytes=CounterResult{unit=BYTES, value=0},
skippedDataFiles=CounterResult{unit=COUNT, value=0},
skippedDeleteFiles=CounterResult{unit=COUNT, value=0},
scannedDeleteManifests=CounterResult{unit=COUNT, value=0},
skippedDeleteManifests=CounterResult{unit=COUNT, value=0},
indexedDeleteFiles=CounterResult{unit=COUNT, value=0},
equalityDeleteFiles=CounterResult{unit=COUNT, value=0},
positionalDeleteFiles=CounterResult{unit=COUNT, value=0}},
metadata={iceberg-version=Apache Iceberg 1.4.3.2024.0.18.0-116 (commit
0bd5277fce0286da2f95288c72ac078b6adfac87)}}
I0410 12:47:59.360661 3681797 HdfsTable.java:1255] Loading metadata for table
definition and all partition(s) of sys.impala_query_log (background load)
I0410 12:47:59.415186 3681797 HdfsTable.java:1907] Loaded 49 columns from HMS.
Actual columns: 49
I0410 12:47:59.445432 3681797 HdfsTable.java:3116] Load Valid Write Id List
Done. Time taken: 31.471us
I0410 12:47:59.445495 3681797 HdfsTable.java:1297] Fetching partition metadata
from the Metastore: sys.impala_query_log
I0410 12:47:59.450807 3681797 MetaStoreUtil.java:190] Fetching 0 partitions
for: sys.impala_query_log using partition batch size: 1000
I0410 12:47:59.450852 3681797 HdfsTable.java:1304] Fetched partition metadata
from the Metastore: sys.impala_query_log
I0410 12:47:59.509284 3681796 JniUtil.java:166]
e040d751d8ffae68:d64122e100000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:59.509341 3681796 JniUtil.java:177]
e040d751d8ffae68:d64122e100000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent:
I0410 12:47:59.510876 3681797 ParallelFileMetadataLoader.java:224] Parallel
Iceberg file metadata listing using a thread pool of size 4
I0410 12:47:59.533716 3681797 HdfsTable.java:836] Loaded file and block
metadata for sys.impala_query_log partitions: . Time taken: 42.050ms
I0410 12:47:59.554518 3681795 JniUtil.java:166]
6041e7dc71f87b5b:9a4ff6f000000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:59.554579 3681795 JniUtil.java:177]
6041e7dc71f87b5b:9a4ff6f000000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent:
I0410 12:47:59.554750 3681797 Table.java:1125] last refreshed event id for
table: sys.impala_query_log set to: -1
I0410 12:47:59.554843 3681797 TableLoader.java:182] Loaded metadata for:
sys.impala_query_log (1060ms)
I0410 12:47:59.558753 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2135
I0410 12:47:59.605238 3681736 catalog-server.cc:1257] Collected update:
1:TABLE:sys.impala_query_log, version=2136, original size=22187, compressed
size=6053
I0410 12:47:59.607175 3681736 catalog-server.cc:1257] Collected update:
1:CATALOG_SERVICE_ID, version=2136, original size=60, compressed size=58
I0410 12:47:59.607280 3681736 JniUtil.java:177] Finished getCatalogDelta
request: Getting catalog delta from version 2135. Time spent: 49ms
I0410 12:47:59.608808 3681745 catalog-server.cc:616] A catalog update with 2
entries is assembled. Catalog version: 2136 Last sent catalog version: 2135
I0410 12:48:00.277279 3681790 JniUtil.java:166]
6041e7dc71f87b5b:9a4ff6f000000000] execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala
I0410 12:48:00.277343 3681793 JniUtil.java:166]
e040d751d8ffae68:d64122e100000000] execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala
I0410 12:48:00.278004 3681790 CatalogServiceCatalog.java:3546]
6041e7dc71f87b5b:9a4ff6f000000000] Should wait for next update for
TABLE:sys.impala_query_log: older version 2136 is sent. Expects a version >=
2137.
I0410 12:48:00.278081 3681790 CatalogServiceCatalog.java:3456]
6041e7dc71f87b5b:9a4ff6f000000000] Topic update for updates not found yet. Last
sent catalog version: 2136. Updated objects: [TABLE:sys.impala_query_log
version: 2137], deleted objects: []
I0410 12:48:00.278314 3681793 CatalogServiceCatalog.java:3546]
e040d751d8ffae68:d64122e100000000] Should wait for next update for
TABLE:sys.impala_query_log: older version 2136 is sent. Expects a version >=
2138.
I0410 12:48:00.278407 3681793 CatalogServiceCatalog.java:3456]
e040d751d8ffae68:d64122e100000000] Topic update for updates not found yet. Last
sent catalog version: 2136. Updated objects: [TABLE:sys.impala_query_log
version: 2138], deleted objects: []
I0410 12:48:00.311198 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2136
I0410 12:48:00.313215 3681736 catalog-server.cc:1257] Collected update:
1:TABLE:sys.impala_query_log, version=2138, original size=22187, compressed
size=6053
I0410 12:48:00.314191 3681736 catalog-server.cc:1257] Collected update:
1:CATALOG_SERVICE_ID, version=2138, original size=60, compressed size=58
I0410 12:48:00.314291 3681736 JniUtil.java:177] Finished getCatalogDelta
request: Getting catalog delta from version 2136. Time spent: 3ms
I0410 12:48:00.314371 3681793 CatalogServiceCatalog.java:3493]
e040d751d8ffae68:d64122e100000000] Operation using SYNC_DDL is waiting for
catalog version 2138 to be sent. Time to identify topic update (msec): 36.
I0410 12:48:00.314430 3681790 CatalogServiceCatalog.java:3493]
6041e7dc71f87b5b:9a4ff6f000000000] Operation using SYNC_DDL is waiting for
catalog version 2138 to be sent. Time to identify topic update (msec): 37.
I0410 12:48:00.315104 3681793 JniUtil.java:177]
e040d751d8ffae68:d64122e100000000] Finished execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala. Time spent: 38ms
I0410 12:48:00.315157 3681790 JniUtil.java:177]
6041e7dc71f87b5b:9a4ff6f000000000] Finished execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala. Time spent: 38ms
I0410 12:48:00.361189 3681745 catalog-server.cc:616] A catalog update with 2
entries is assembled. Catalog version: 2138 Last sent catalog version: 2136
I0410 12:48:03.926739 3681795 JniUtil.java:166]
404bfde9c36d4ec4:c380132f00000000] prioritizeLoad request: Prioritize load on
table(s): functional.tinytable
I0410 12:48:03.926837 3681795 JniUtil.java:177]
404bfde9c36d4ec4:c380132f00000000] Finished prioritizeLoad request: Prioritize
load on table(s): functional.tinytable. Time spent:
I0410 12:48:03.927119 3681328 TableLoadingMgr.java:74] Loading metadata for
table: functional.tinytable
I0410 12:48:03.927191 3681865 TableLoader.java:81] Loading metadata for:
functional.tinytable (background load)
I0410 12:48:03.927349 3681328 TableLoadingMgr.java:76] Remaining items in
queue: 0. Loads in progress: 1
I0410 12:48:03.931860 3681865 Table.java:248] createEventId_ for table:
functional.tinytable set to: -1
I0410 12:48:03.932072 3681865 HdfsTable.java:1255] Loading metadata for table
definition and all partition(s) of functional.tinytable (background load)
I0410 12:48:03.932713 3681865 HdfsTable.java:1907] Loaded 2 columns from HMS.
Actual columns: 2
I0410 12:48:03.937162 3681865 HdfsTable.java:3116] Load Valid Write Id List
Done. Time taken: 5.486us
I0410 12:48:03.937204 3681865 HdfsTable.java:1297] Fetching partition metadata
from the Metastore: functional.tinytable
I0410 12:48:03.937896 3681865 MetaStoreUtil.java:190] Fetching 0 partitions
for: functional.tinytable using partition batch size: 1000
I0410 12:48:03.937924 3681865 HdfsTable.java:1304] Fetched partition metadata
from the Metastore: functional.tinytable
I0410 12:48:03.941433 3681865 HdfsTable.java:836] Loaded file and block
metadata for functional.tinytable partitions: . Time taken: 1.938ms
I0410 12:48:03.941846 3681865 Table.java:1125] last refreshed event id for
table: functional.tinytable set to: -1
I0410 12:48:03.941905 3681865 TableLoader.java:182] Loaded metadata for:
functional.tinytable (14ms)
I0410 12:48:03.969413 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2138
I0410 12:48:03.972474 3681736 HdfsTable.java:2261] Skipped 0 partitions of
table functional.tinytable in the incremental update
I0410 12:48:03.972782 3681736 CatalogServiceCatalog.java:1720] Collected 1
partition update(s): 1:HDFS_PARTITION:functional.tinytable:, version=2139,
original size=355, compressed size=297
I0410 12:48:03.972954 3681736 catalog-server.cc:1257] Collected update:
1:TABLE:functional.tinytable, version=2139, original size=1766, compressed
size=1054
I0410 12:48:03.975296 3681736 catalog-server.cc:1257] Collected update:
1:CATALOG_SERVICE_ID, version=2139, original size=60, compressed size=58
I0410 12:48:03.975366 3681736 JniUtil.java:177] Finished getCatalogDelta
request: Getting catalog delta from version 2138. Time spent: 6ms
I0410 12:48:04.019423 3681745 catalog-server.cc:616] A catalog update with 3
entries is assembled. Catalog version: 2139 Last sent catalog version: 2138
I0410 12:48:04.684219 3681790 JniUtil.java:166]
6647229faf7637d5:3ec7565b00000000] updateCatalog request: Update catalog for
sys.impala_query_log
I0410 12:48:04.721669 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2139
I0410 12:48:04.972295 3681790 SnapshotProducer.java:414]
6647229faf7637d5:3ec7565b00000000] Committed snapshot 2413899761335225842
(MergeAppend)
I0410 12:48:04.986073 3681790 LoggingMetricsReporter.java:38]
6647229faf7637d5:3ec7565b00000000] Received metrics report:
CommitReport{tableName=ImpalaHiveCatalog.sys.impala_query_log,
snapshotId=2413899761335225842, sequenceNumber=5, operation=append,
commitMetrics=CommitMetricsResult{totalDuration=TimerResult{timeUnit=NANOSECONDS,
totalDuration=PT0.257751342S, count=1}, attempts=CounterResult{unit=COUNT,
value=1}, addedDataFiles=CounterResult{unit=COUNT, value=1},
removedDataFiles=null, totalDataFiles=CounterResult{unit=COUNT, value=5},
addedDeleteFiles=null, addedEqualityDeleteFiles=null,
addedPositionalDeleteFiles=null, removedDeleteFiles=null,
removedEqualityDeleteFiles=null, removedPositionalDeleteFiles=null,
totalDeleteFiles=CounterResult{unit=COUNT, value=0},
addedRecords=CounterResult{unit=COUNT, value=1}, removedRecords=null,
totalRecords=CounterResult{unit=COUNT, value=9},
addedFilesSizeInBytes=CounterResult{unit=BYTES, value=29355},
removedFilesSizeInBytes=null, totalFilesSizeInBytes=CounterResult{unit=BYTES,
value=146943}, addedPositionalDeletes=null, removedPositionalDeletes=null,
totalPositionalDeletes=CounterResult{unit=COUNT, value=0},
addedEqualityDeletes=null, removedEqualityDeletes=null,
totalEqualityDeletes=CounterResult{unit=COUNT, value=0}},
metadata={iceberg-version=Apache Iceberg 1.4.3.2024.0.18.0-116 (commit
0bd5277fce0286da2f95288c72ac078b6adfac87)}}
I0410 12:48:04.992753 3681790 CatalogServiceCatalog.java:1243]
6647229faf7637d5:3ec7565b00000000] Added catalog version 2140 in table's
sys.impala_query_log in-flight events
W0410 12:48:05.051760 3681790 Tasks.java:456]
6647229faf7637d5:3ec7565b00000000] Retrying task after failure: Waiting for
lock on table sys.impala_query_log
Java exception follows:
org.apache.iceberg.hive.MetastoreLock$WaitingForLockException: Waiting for lock
on table sys.impala_query_log
at
org.apache.iceberg.hive.MetastoreLock.lambda$acquireLock$1(MetastoreLock.java:217)
at
org.apache.iceberg.util.Tasks$Builder.runTaskWithRetry(Tasks.java:413)
at
org.apache.iceberg.util.Tasks$Builder.runSingleThreaded(Tasks.java:219)
at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:203)
at
org.apache.iceberg.hive.MetastoreLock.acquireLock(MetastoreLock.java:209)
at org.apache.iceberg.hive.MetastoreLock.lock(MetastoreLock.java:146)
at
org.apache.iceberg.hive.HiveTableOperations.doCommit(HiveTableOperations.java:194)
at
org.apache.iceberg.BaseMetastoreTableOperations.commit(BaseMetastoreTableOperations.java:135)
at
org.apache.iceberg.BaseTransaction.lambda$commitSimpleTransaction$3(BaseTransaction.java:417)
at
org.apache.iceberg.util.Tasks$Builder.runTaskWithRetry(Tasks.java:413)
at
org.apache.iceberg.util.Tasks$Builder.runSingleThreaded(Tasks.java:219)
at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:203)
at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:196)
at
org.apache.iceberg.BaseTransaction.commitSimpleTransaction(BaseTransaction.java:413)
at
org.apache.iceberg.BaseTransaction.commitTransaction(BaseTransaction.java:308)
at
org.apache.impala.service.CatalogOpExecutor.updateCatalogImpl(CatalogOpExecutor.java:7220)
at
org.apache.impala.service.CatalogOpExecutor.updateCatalog(CatalogOpExecutor.java:6939)
at
org.apache.impala.service.JniCatalog.lambda$updateCatalog$15(JniCatalog.java:504)
at
org.apache.impala.service.JniCatalogOp.lambda$execAndSerialize$1(JniCatalogOp.java:90)
at org.apache.impala.service.JniCatalogOp.execOp(JniCatalogOp.java:58)
at
org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:89)
at
org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:100)
at
org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:245)
at
org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:259)
at
org.apache.impala.service.JniCatalog.updateCatalog(JniCatalog.java:503)
{code}
I haven't found anything interesting in HMS logs.
was (Author: JIRAUSER288956):
Relevant catalogd logs from when the error first started
{code}
I0410 12:47:58.355312 3681745 catalog-server.cc:616] A catalog update with 2
entries is assembled. Catalog version: 2135 Last sent catalog version: 2133
I0410 12:47:58.473973 3681750 TAcceptQueueServer.cpp:355] New connection to
server CatalogService from client <Host: 127.0.0.1 Port: 54134>
I0410 12:47:58.478902 3681750 TAcceptQueueServer.cpp:355] New connection to
server CatalogService from client <Host: 127.0.0.1 Port: 54140>
I0410 12:47:58.491712 3681796 JniUtil.java:166]
e040d751d8ffae68:d64122e100000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:58.491765 3681795 JniUtil.java:166]
6041e7dc71f87b5b:9a4ff6f000000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:58.492286 3681795 JniUtil.java:177]
6041e7dc71f87b5b:9a4ff6f000000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent: 1ms
I0410 12:47:58.492334 3681796 JniUtil.java:177]
e040d751d8ffae68:d64122e100000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent: 1ms
I0410 12:47:58.492388 3681327 TableLoadingMgr.java:310] Metadata load request
already in progress for table: sys.impala_query_log
I0410 12:47:58.494186 3681797 TableLoader.java:81] Loading metadata for:
sys.impala_query_log (background load)
I0410 12:47:58.494704 3681326 TableLoadingMgr.java:74] Loading metadata for
table: sys.impala_query_log
I0410 12:47:58.494817 3681326 TableLoadingMgr.java:76] Remaining items in
queue: 0. Loads in progress: 1
I0410 12:47:58.536164 3681797 Table.java:248] createEventId_ for table:
sys.impala_query_log set to: -1
W0410 12:47:58.575927 3681797 HiveConf.java:6718] HiveConf of name
hive.metastore.partitions.parameters.exclude.pattern does not exist
I0410 12:47:58.603469 3681797 CatalogUtil.java:302] Loading custom FileIO
implementation: org.apache.iceberg.hadoop.HadoopFileIO
W0410 12:47:58.681820 3681797 HiveConf.java:6718] HiveConf of name
hive.metastore.partitions.parameters.exclude.pattern does not exist
I0410 12:47:58.686848 3681797 HiveMetaStoreClient.java:280] HMS client
filtering is enabled.
I0410 12:47:58.687023 3681797 HiveMetaStoreClient.java:738] Trying to connect
to metastore with URI (thrift://localhost:9083) in binary transport mode
I0410 12:47:58.687292 3681797 HiveMetaStoreClient.java:769] Opened a connection
to metastore, URI (thrift://localhost:9083) current connections: 11
I0410 12:47:58.687708 3681797 HiveMetaStoreClient.java:839] Connected to
metastore.
I0410 12:47:58.687781 3681797 RetryingMetaStoreClient.java:100]
RetryingMetaStoreClient proxy=class
org.apache.hadoop.hive.metastore.HiveMetaStoreClient ugi=jenkins (auth:SIMPLE)
retries=1 delay=1 lifetime=0
I0410 12:47:58.696296 3681797 BaseMetastoreTableOperations.java:199] Refreshing
table metadata from new version:
hdfs://localhost:20500/test-warehouse/sys.db/impala_query_log/metadata/00004-f507db8e-8d90-476e-b09b-c7c81a608641.metadata.json
I0410 12:47:59.041594 3681797 BaseMetastoreCatalog.java:67] Table loaded by
catalog: ImpalaHiveCatalog.sys.impala_query_log
I0410 12:47:59.066388 3681797 SnapshotScan.java:124] Scanning table
ImpalaHiveCatalog.sys.impala_query_log snapshot 4998562745977744358 created at
2024-04-10T19:47:53.382+00:00 with filter true
I0410 12:47:59.360441 3681797 LoggingMetricsReporter.java:38] Received metrics
report: ScanReport{tableName=ImpalaHiveCatalog.sys.impala_query_log,
snapshotId=4998562745977744358, filter=true, schemaId=0, projectedFieldIds=[1,
2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23,
24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43,
44, 45, 46, 47, 48, 49], projectedFieldNames=[cluster_id, query_id, session_id,
session_type, hiveserver2_protocol_version, db_user, db_user_connection,
db_name, impala_coordinator, query_status, query_state, impala_query_end_state,
query_type, network_address, start_time_utc, total_time_ms, query_opts_config,
resource_pool, per_host_mem_estimate, dedicated_coord_mem_estimate,
per_host_fragment_instances, backends_count, admission_result,
cluster_memory_admitted, executor_group, executor_groups, exec_summary,
num_rows_fetched, row_materialization_rows_per_sec,
row_materialization_time_ms, compressed_bytes_spilled, event_planning_finished,
event_submit_for_admission, event_completed_admission,
event_all_backends_started, event_rows_available, event_first_row_fetched,
event_last_row_fetched, event_unregister_query, read_io_wait_total_ms,
read_io_wait_mean_ms, bytes_read_cache_total, bytes_read_total,
pernode_peak_mem_min, pernode_peak_mem_max, pernode_peak_mem_mean, sql, plan,
tables_queried],
scanMetrics=ScanMetricsResult{totalPlanningDuration=TimerResult{timeUnit=NANOSECONDS,
totalDuration=PT0.269319826S, count=1},
resultDataFiles=CounterResult{unit=COUNT, value=4},
resultDeleteFiles=CounterResult{unit=COUNT, value=0},
totalDataManifests=CounterResult{unit=COUNT, value=4},
totalDeleteManifests=CounterResult{unit=COUNT, value=0},
scannedDataManifests=CounterResult{unit=COUNT, value=4},
skippedDataManifests=CounterResult{unit=COUNT, value=0},
totalFileSizeInBytes=CounterResult{unit=BYTES, value=117588},
totalDeleteFileSizeInBytes=CounterResult{unit=BYTES, value=0},
skippedDataFiles=CounterResult{unit=COUNT, value=0},
skippedDeleteFiles=CounterResult{unit=COUNT, value=0},
scannedDeleteManifests=CounterResult{unit=COUNT, value=0},
skippedDeleteManifests=CounterResult{unit=COUNT, value=0},
indexedDeleteFiles=CounterResult{unit=COUNT, value=0},
equalityDeleteFiles=CounterResult{unit=COUNT, value=0},
positionalDeleteFiles=CounterResult{unit=COUNT, value=0}},
metadata={iceberg-version=Apache Iceberg 1.4.3.2024.0.18.0-116 (commit
0bd5277fce0286da2f95288c72ac078b6adfac87)}}
I0410 12:47:59.360661 3681797 HdfsTable.java:1255] Loading metadata for table
definition and all partition(s) of sys.impala_query_log (background load)
I0410 12:47:59.415186 3681797 HdfsTable.java:1907] Loaded 49 columns from HMS.
Actual columns: 49
I0410 12:47:59.445432 3681797 HdfsTable.java:3116] Load Valid Write Id List
Done. Time taken: 31.471us
I0410 12:47:59.445495 3681797 HdfsTable.java:1297] Fetching partition metadata
from the Metastore: sys.impala_query_log
I0410 12:47:59.450807 3681797 MetaStoreUtil.java:190] Fetching 0 partitions
for: sys.impala_query_log using partition batch size: 1000
I0410 12:47:59.450852 3681797 HdfsTable.java:1304] Fetched partition metadata
from the Metastore: sys.impala_query_log
I0410 12:47:59.509284 3681796 JniUtil.java:166]
e040d751d8ffae68:d64122e100000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:59.509341 3681796 JniUtil.java:177]
e040d751d8ffae68:d64122e100000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent:
I0410 12:47:59.510876 3681797 ParallelFileMetadataLoader.java:224] Parallel
Iceberg file metadata listing using a thread pool of size 4
I0410 12:47:59.533716 3681797 HdfsTable.java:836] Loaded file and block
metadata for sys.impala_query_log partitions: . Time taken: 42.050ms
I0410 12:47:59.554518 3681795 JniUtil.java:166]
6041e7dc71f87b5b:9a4ff6f000000000] prioritizeLoad request: Prioritize load on
table(s): sys.impala_query_log
I0410 12:47:59.554579 3681795 JniUtil.java:177]
6041e7dc71f87b5b:9a4ff6f000000000] Finished prioritizeLoad request: Prioritize
load on table(s): sys.impala_query_log. Time spent:
I0410 12:47:59.554750 3681797 Table.java:1125] last refreshed event id for
table: sys.impala_query_log set to: -1
I0410 12:47:59.554843 3681797 TableLoader.java:182] Loaded metadata for:
sys.impala_query_log (1060ms)
I0410 12:47:59.558753 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2135
I0410 12:47:59.605238 3681736 catalog-server.cc:1257] Collected update:
1:TABLE:sys.impala_query_log, version=2136, original size=22187, compressed
size=6053
I0410 12:47:59.607175 3681736 catalog-server.cc:1257] Collected update:
1:CATALOG_SERVICE_ID, version=2136, original size=60, compressed size=58
I0410 12:47:59.607280 3681736 JniUtil.java:177] Finished getCatalogDelta
request: Getting catalog delta from version 2135. Time spent: 49ms
I0410 12:47:59.608808 3681745 catalog-server.cc:616] A catalog update with 2
entries is assembled. Catalog version: 2136 Last sent catalog version: 2135
I0410 12:48:00.277279 3681790 JniUtil.java:166]
6041e7dc71f87b5b:9a4ff6f000000000] execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala
I0410 12:48:00.277343 3681793 JniUtil.java:166]
e040d751d8ffae68:d64122e100000000] execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala
I0410 12:48:00.278004 3681790 CatalogServiceCatalog.java:3546]
6041e7dc71f87b5b:9a4ff6f000000000] Should wait for next update for
TABLE:sys.impala_query_log: older version 2136 is sent. Expects a version >=
2137.
I0410 12:48:00.278081 3681790 CatalogServiceCatalog.java:3456]
6041e7dc71f87b5b:9a4ff6f000000000] Topic update for updates not found yet. Last
sent catalog version: 2136. Updated objects: [TABLE:sys.impala_query_log
version: 2137], deleted objects: []
I0410 12:48:00.278314 3681793 CatalogServiceCatalog.java:3546]
e040d751d8ffae68:d64122e100000000] Should wait for next update for
TABLE:sys.impala_query_log: older version 2136 is sent. Expects a version >=
2138.
I0410 12:48:00.278407 3681793 CatalogServiceCatalog.java:3456]
e040d751d8ffae68:d64122e100000000] Topic update for updates not found yet. Last
sent catalog version: 2136. Updated objects: [TABLE:sys.impala_query_log
version: 2138], deleted objects: []
I0410 12:48:00.311198 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2136
I0410 12:48:00.313215 3681736 catalog-server.cc:1257] Collected update:
1:TABLE:sys.impala_query_log, version=2138, original size=22187, compressed
size=6053
I0410 12:48:00.314191 3681736 catalog-server.cc:1257] Collected update:
1:CATALOG_SERVICE_ID, version=2138, original size=60, compressed size=58
I0410 12:48:00.314291 3681736 JniUtil.java:177] Finished getCatalogDelta
request: Getting catalog delta from version 2136. Time spent: 3ms
I0410 12:48:00.314371 3681793 CatalogServiceCatalog.java:3493]
e040d751d8ffae68:d64122e100000000] Operation using SYNC_DDL is waiting for
catalog version 2138 to be sent. Time to identify topic update (msec): 36.
I0410 12:48:00.314430 3681790 CatalogServiceCatalog.java:3493]
6041e7dc71f87b5b:9a4ff6f000000000] Operation using SYNC_DDL is waiting for
catalog version 2138 to be sent. Time to identify topic update (msec): 37.
I0410 12:48:00.315104 3681793 JniUtil.java:177]
e040d751d8ffae68:d64122e100000000] Finished execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala. Time spent: 38ms
I0410 12:48:00.315157 3681790 JniUtil.java:177]
6041e7dc71f87b5b:9a4ff6f000000000] Finished execDdl request: CREATE_TABLE
sys.impala_query_log issued by impala. Time spent: 38ms
I0410 12:48:00.361189 3681745 catalog-server.cc:616] A catalog update with 2
entries is assembled. Catalog version: 2138 Last sent catalog version: 2136
I0410 12:48:03.926739 3681795 JniUtil.java:166]
404bfde9c36d4ec4:c380132f00000000] prioritizeLoad request: Prioritize load on
table(s): functional.tinytable
I0410 12:48:03.926837 3681795 JniUtil.java:177]
404bfde9c36d4ec4:c380132f00000000] Finished prioritizeLoad request: Prioritize
load on table(s): functional.tinytable. Time spent:
I0410 12:48:03.927119 3681328 TableLoadingMgr.java:74] Loading metadata for
table: functional.tinytable
I0410 12:48:03.927191 3681865 TableLoader.java:81] Loading metadata for:
functional.tinytable (background load)
I0410 12:48:03.927349 3681328 TableLoadingMgr.java:76] Remaining items in
queue: 0. Loads in progress: 1
I0410 12:48:03.931860 3681865 Table.java:248] createEventId_ for table:
functional.tinytable set to: -1
I0410 12:48:03.932072 3681865 HdfsTable.java:1255] Loading metadata for table
definition and all partition(s) of functional.tinytable (background load)
I0410 12:48:03.932713 3681865 HdfsTable.java:1907] Loaded 2 columns from HMS.
Actual columns: 2
I0410 12:48:03.937162 3681865 HdfsTable.java:3116] Load Valid Write Id List
Done. Time taken: 5.486us
I0410 12:48:03.937204 3681865 HdfsTable.java:1297] Fetching partition metadata
from the Metastore: functional.tinytable
I0410 12:48:03.937896 3681865 MetaStoreUtil.java:190] Fetching 0 partitions
for: functional.tinytable using partition batch size: 1000
I0410 12:48:03.937924 3681865 HdfsTable.java:1304] Fetched partition metadata
from the Metastore: functional.tinytable
I0410 12:48:03.941433 3681865 HdfsTable.java:836] Loaded file and block
metadata for functional.tinytable partitions: . Time taken: 1.938ms
I0410 12:48:03.941846 3681865 Table.java:1125] last refreshed event id for
table: functional.tinytable set to: -1
I0410 12:48:03.941905 3681865 TableLoader.java:182] Loaded metadata for:
functional.tinytable (14ms)
I0410 12:48:03.969413 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2138
I0410 12:48:03.972474 3681736 HdfsTable.java:2261] Skipped 0 partitions of
table functional.tinytable in the incremental update
I0410 12:48:03.972782 3681736 CatalogServiceCatalog.java:1720] Collected 1
partition update(s): 1:HDFS_PARTITION:functional.tinytable:, version=2139,
original size=355, compressed size=297
I0410 12:48:03.972954 3681736 catalog-server.cc:1257] Collected update:
1:TABLE:functional.tinytable, version=2139, original size=1766, compressed
size=1054
I0410 12:48:03.975296 3681736 catalog-server.cc:1257] Collected update:
1:CATALOG_SERVICE_ID, version=2139, original size=60, compressed size=58
I0410 12:48:03.975366 3681736 JniUtil.java:177] Finished getCatalogDelta
request: Getting catalog delta from version 2138. Time spent: 6ms
I0410 12:48:04.019423 3681745 catalog-server.cc:616] A catalog update with 3
entries is assembled. Catalog version: 2139 Last sent catalog version: 2138
I0410 12:48:04.684219 3681790 JniUtil.java:166]
6647229faf7637d5:3ec7565b00000000] updateCatalog request: Update catalog for
sys.impala_query_log
I0410 12:48:04.721669 3681736 JniUtil.java:166] getCatalogDelta request:
Getting catalog delta from version 2139
I0410 12:48:04.972295 3681790 SnapshotProducer.java:414]
6647229faf7637d5:3ec7565b00000000] Committed snapshot 2413899761335225842
(MergeAppend)
I0410 12:48:04.986073 3681790 LoggingMetricsReporter.java:38]
6647229faf7637d5:3ec7565b00000000] Received metrics report:
CommitReport{tableName=ImpalaHiveCatalog.sys.impala_query_log,
snapshotId=2413899761335225842, sequenceNumber=5, operation=append,
commitMetrics=CommitMetricsResult{totalDuration=TimerResult{timeUnit=NANOSECONDS,
totalDuration=PT0.257751342S, count=1}, attempts=CounterResult{unit=COUNT,
value=1}, addedDataFiles=CounterResult{unit=COUNT, value=1},
removedDataFiles=null, totalDataFiles=CounterResult{unit=COUNT, value=5},
addedDeleteFiles=null, addedEqualityDeleteFiles=null,
addedPositionalDeleteFiles=null, removedDeleteFiles=null,
removedEqualityDeleteFiles=null, removedPositionalDeleteFiles=null,
totalDeleteFiles=CounterResult{unit=COUNT, value=0},
addedRecords=CounterResult{unit=COUNT, value=1}, removedRecords=null,
totalRecords=CounterResult{unit=COUNT, value=9},
addedFilesSizeInBytes=CounterResult{unit=BYTES, value=29355},
removedFilesSizeInBytes=null, totalFilesSizeInBytes=CounterResult{unit=BYTES,
value=146943}, addedPositionalDeletes=null, removedPositionalDeletes=null,
totalPositionalDeletes=CounterResult{unit=COUNT, value=0},
addedEqualityDeletes=null, removedEqualityDeletes=null,
totalEqualityDeletes=CounterResult{unit=COUNT, value=0}},
metadata={iceberg-version=Apache Iceberg 1.4.3.2024.0.18.0-116 (commit
0bd5277fce0286da2f95288c72ac078b6adfac87)}}
I0410 12:48:04.992753 3681790 CatalogServiceCatalog.java:1243]
6647229faf7637d5:3ec7565b00000000] Added catalog version 2140 in table's
sys.impala_query_log in-flight events
W0410 12:48:05.051760 3681790 Tasks.java:456]
6647229faf7637d5:3ec7565b00000000] Retrying task after failure: Waiting for
lock on table sys.impala_query_log
Java exception follows:
org.apache.iceberg.hive.MetastoreLock$WaitingForLockException: Waiting for lock
on table sys.impala_query_log
at
org.apache.iceberg.hive.MetastoreLock.lambda$acquireLock$1(MetastoreLock.java:217)
at
org.apache.iceberg.util.Tasks$Builder.runTaskWithRetry(Tasks.java:413)
at
org.apache.iceberg.util.Tasks$Builder.runSingleThreaded(Tasks.java:219)
at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:203)
at
org.apache.iceberg.hive.MetastoreLock.acquireLock(MetastoreLock.java:209)
at org.apache.iceberg.hive.MetastoreLock.lock(MetastoreLock.java:146)
at
org.apache.iceberg.hive.HiveTableOperations.doCommit(HiveTableOperations.java:194)
at
org.apache.iceberg.BaseMetastoreTableOperations.commit(BaseMetastoreTableOperations.java:135)
at
org.apache.iceberg.BaseTransaction.lambda$commitSimpleTransaction$3(BaseTransaction.java:417)
at
org.apache.iceberg.util.Tasks$Builder.runTaskWithRetry(Tasks.java:413)
at
org.apache.iceberg.util.Tasks$Builder.runSingleThreaded(Tasks.java:219)
at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:203)
at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:196)
at
org.apache.iceberg.BaseTransaction.commitSimpleTransaction(BaseTransaction.java:413)
at
org.apache.iceberg.BaseTransaction.commitTransaction(BaseTransaction.java:308)
at
org.apache.impala.service.CatalogOpExecutor.updateCatalogImpl(CatalogOpExecutor.java:7220)
at
org.apache.impala.service.CatalogOpExecutor.updateCatalog(CatalogOpExecutor.java:6939)
at
org.apache.impala.service.JniCatalog.lambda$updateCatalog$15(JniCatalog.java:504)
at
org.apache.impala.service.JniCatalogOp.lambda$execAndSerialize$1(JniCatalogOp.java:90)
at org.apache.impala.service.JniCatalogOp.execOp(JniCatalogOp.java:58)
at
org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:89)
at
org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:100)
at
org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:245)
at
org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:259)
at
org.apache.impala.service.JniCatalog.updateCatalog(JniCatalog.java:503)
{code}
> test_query_log tests get stuck trying to write to the log
> ---------------------------------------------------------
>
> Key: IMPALA-12997
> URL: https://issues.apache.org/jira/browse/IMPALA-12997
> Project: IMPALA
> Issue Type: Bug
> Components: Catalog
> Affects Versions: Impala 4.4.0
> Reporter: Michael Smith
> Priority: Major
>
> In some test runs, most tests under test_query_log will start to fail on
> various conditions like
> {code}
> custom_cluster/test_query_log.py:452: in
> test_query_log_table_query_select_mt_dop
> "impala-server.completed-queries.written", 1, 60)
> common/impala_service.py:144: in wait_for_metric_value
> self.__metric_timeout_assert(metric_name, expected_value, timeout)
> common/impala_service.py:213: in __metric_timeout_assert
> assert 0, assert_string
> E AssertionError: Metric impala-server.completed-queries.written did not
> reach value 1 in 60s.
> E Dumping debug webpages in JSON format...
> E Dumped memz JSON to
> $IMPALA_HOME/logs/metric_timeout_diags_20240410_12:49:04/json/memz.json
> E Dumped metrics JSON to
> $IMPALA_HOME/logs/metric_timeout_diags_20240410_12:49:04/json/metrics.json
> E Dumped queries JSON to
> $IMPALA_HOME/logs/metric_timeout_diags_20240410_12:49:04/json/queries.json
> E Dumped sessions JSON to
> $IMPALA_HOME/logs/metric_timeout_diags_20240410_12:49:04/json/sessions.json
> E Dumped threadz JSON to
> $IMPALA_HOME/logs/metric_timeout_diags_20240410_12:49:04/json/threadz.json
> E Dumped rpcz JSON to
> $IMPALA_HOME/logs/metric_timeout_diags_20240410_12:49:04/json/rpcz.json
> E Dumping minidumps for impalads/catalogds...
> E Dumped minidump for Impalad PID 3680802
> E Dumped minidump for Impalad PID 3680805
> E Dumped minidump for Impalad PID 3680809
> E Dumped minidump for Catalogd PID 3680732
> {code}
> or
> {code}
> custom_cluster/test_query_log.py:921: in test_query_log_ignored_sqls
> assert len(sql_results.data) == 1, "query not found in completed queries
> table"
> E AssertionError: query not found in completed queries table
> E assert 0 == 1
> E + where 0 = len([])
> E + where [] = <tests.common.impala_connection.ImpylaHS2ResultSet
> object at 0xffffa00cc350>.data
> {code}
> One symptom that seems related to this is INSERT operations into
> sys.impala_query_log that start "UnregisterQuery()" but never finish (with
> "Query successfully unregistered").
> We can identify cases like that with
> {code}
> for log in $(ag -l 'INSERT INTO sys.impala_query_log' impalad.*); do echo
> $log; for qid in $(ag -o '[0-9a-f]*:[0-9a-f]*\] Analyzing query: INSERT INTO
> sys.impala_query_log' $log | cut -d']' -f1); do if ! ag "Query successfully
> unregistered: query_id=$qid" $log; then echo "$qid not unregistered"; fi;
> done; done
> {code}
> A similar case may occur with creating the table too
> {code}
> for log in $(ag -l 'CREATE TABLE IF NOT EXISTS sys.impala_query_log'
> impalad.impala-ec2-rhel88-m7g-4xlarge-ondemand-0a5a.vpc.cloudera.com.jenkins.log.INFO.20240410-*);
> do QID=$(ag -o '[0-9a-f]*:[0-9a-f]*\] Analyzing query: INSERT INTO
> sys.impala_query_log' $log | cut -d']' -f1); echo $log; ag "Query
> successfully unregistered: query_id=$QID" $log; done
> {code}
> although these frequently fail because the test completes and shuts down
> Impala before the CREATE TABLE query completes.
> Tracking one of those cases led to catalogd errors that repeated for 1m27s
> before the test suite restarted catalogd:
> {code}
> W0410 12:48:05.051760 3681790 Tasks.java:456]
> 6647229faf7637d5:3ec7565b00000000] Retrying task after failure: Waiting for
> lock on table sys.impala_query_log
> Java exception follows:
> org.apache.iceberg.hive.MetastoreLock$WaitingForLockException: Waiting for
> lock on table sys.impala_query_log
> at
> org.apache.iceberg.hive.MetastoreLock.lambda$acquireLock$1(MetastoreLock.java:217)
> at
> org.apache.iceberg.util.Tasks$Builder.runTaskWithRetry(Tasks.java:413)
> at
> org.apache.iceberg.util.Tasks$Builder.runSingleThreaded(Tasks.java:219)
> at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:203)
> at
> org.apache.iceberg.hive.MetastoreLock.acquireLock(MetastoreLock.java:209)
> at org.apache.iceberg.hive.MetastoreLock.lock(MetastoreLock.java:146)
> at
> org.apache.iceberg.hive.HiveTableOperations.doCommit(HiveTableOperations.java:194)
> at
> org.apache.iceberg.BaseMetastoreTableOperations.commit(BaseMetastoreTableOperations.java:135)
> at
> org.apache.iceberg.BaseTransaction.lambda$commitSimpleTransaction$3(BaseTransaction.java:417)
> at
> org.apache.iceberg.util.Tasks$Builder.runTaskWithRetry(Tasks.java:413)
> at
> org.apache.iceberg.util.Tasks$Builder.runSingleThreaded(Tasks.java:219)
> at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:203)
> at org.apache.iceberg.util.Tasks$Builder.run(Tasks.java:196)
> at
> org.apache.iceberg.BaseTransaction.commitSimpleTransaction(BaseTransaction.java:413)
> at
> org.apache.iceberg.BaseTransaction.commitTransaction(BaseTransaction.java:308)
> at
> org.apache.impala.service.CatalogOpExecutor.updateCatalogImpl(CatalogOpExecutor.java:7220)
> at
> org.apache.impala.service.CatalogOpExecutor.updateCatalog(CatalogOpExecutor.java:6939)
> at
> org.apache.impala.service.JniCatalog.lambda$updateCatalog$15(JniCatalog.java:504)
> at
> org.apache.impala.service.JniCatalogOp.lambda$execAndSerialize$1(JniCatalogOp.java:90)
> at org.apache.impala.service.JniCatalogOp.execOp(JniCatalogOp.java:58)
> at
> org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:89)
> at
> org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:100)
> at
> org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:245)
> at
> org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:259)
> at
> org.apache.impala.service.JniCatalog.updateCatalog(JniCatalog.java:503)
> {code}
> This seems to correspond to the first test failure and persisted through all
> tests afterwards. So this lock was likely acquired from HMS, then never
> released.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscr...@impala.apache.org
For additional commands, e-mail: issues-all-h...@impala.apache.org
