Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
None
-
None
-
ghx-label-13
Description
The error happens in loading a partition while a concurrent DROP DATABASE CASCADE is running. Impalad logs:
I0217 06:55:58.696295 28500 Frontend.java:2070] 8b4a15df68c9c5dd:f21c5bb200000000] Analyzing query: DROP DATABASE `test_read_hive_inserts_8bb30aca` CASCADE db: default
catalogd logs:
I0217 06:55:58.696962 28650 JniUtil.java:166] 8b4a15df68c9c5dd:f21c5bb200000000] execDdl request: DROP_DATABASE test_read_hive_inserts_8bb30aca issued by jenkins
I0217 06:55:58.751202 5748 MetastoreEventsProcessor.java:909] Received 2 events. Start event id : 51397
I0217 06:55:58.751662 5748 MetastoreEvents.java:293] Total number of events received: 2 Total number of events filtered out: 0
I0217 06:55:58.751700 5748 MetastoreEvents.java:297] Incremented skipped metric to 8174
I0217 06:55:58.751801 5748 CatalogServiceCatalog.java:1060] Not a self-event since the given version is -1 and service id is empty
I0217 06:55:58.751914 5748 HdfsTable.java:2851] Reloading partition metadata for table: test_read_hive_inserts_8bb30aca.test_read_hive_inserts (ALTER_PARTITION EVENT FOR TRANSACTIONAL TABLE)
I0217 06:55:58.752924 5749 MetastoreEventsProcessor.java:1023] Latest event in HMS: id=51399, time=1708181758. Last synced event: id=51397, time=1708181750.
W0217 06:55:58.752954 5749 MetastoreEventsProcessor.java:1026] Lag: 8s. 2 events pending to be processed.
I0217 06:55:58.754891 5748 HdfsTable.java:2943] Setting the latest refresh event id to 51399 for the reloaded 1 partitions
I0217 06:55:58.756098 5748 HdfsTable.java:2851] Reloading partition metadata for table: test_read_hive_inserts_8bb30aca.test_read_hive_inserts (Processing event id: 51399, event type: COMMIT_TXN)
I0217 06:55:58.756839 5748 HdfsTable.java:2943] Setting the latest refresh event id to 51401 for the reloaded 1 partitions
I0217 06:55:58.756867 5748 HdfsTable.java:2946] for table test_read_hive_inserts_8bb30aca.test_read_hive_inserts, file metadataOps: FORCE_LOAD, refreshing file metadata for 1 out of 1 partitions to reload in reloadPartitions()
E0217 06:55:58.761873 5748 ParallelFileMetadataLoader.java:194] Refreshing file and block metadata for 1 paths for table test_read_hive_inserts_8bb30aca.test_read_hive_inserts encountered an error loading data for path hdfs://localhost:20500/test-warehouse/managed/test_read_hive_inserts_8bb30aca.db/test_read_hive_inserts/p=1
Java exception follows:
java.util.concurrent.ExecutionException: java.io.FileNotFoundException: File does not exist: /test-warehouse/managed/test_read_hive_inserts_8bb30aca.db/test_read_hive_inserts/p=1/delta_0000010_0000010_0000/000000_0
...
I0217 06:55:58.762064 5748 CatalogOpExecutor.java:5006] Rolling back the write id list of table test_read_hive_inserts_8bb30aca.test_read_hive_inserts because reloading for event 51399 is failed: Refreshing file and block metadata for 1 paths for table test_read_hive_inserts_8bb30aca.test_read_hive_inserts: failed to load 1 paths. Check the catalog server log for more details.
I0217 06:55:58.762253 5748 MetastoreEventsProcessor.java:1189] Time elapsed in processing event batch: 10.977ms
E0217 06:55:58.762821 5748 MetastoreEventsProcessor.java:981] Event processing needs a invalidate command to resolve the state
Java exception follows:
org.apache.impala.catalog.events.MetastoreNotificationNeedsInvalidateException: EventId: 51399 EventType: COMMIT_TXN Failed to mark committed write ids and refresh partitions for txn {}. Event processing cannot continue. Issue an invalidate metadata command to reset event processor.
at org.apache.impala.compat.MetastoreShim$CommitTxnEvent.process(MetastoreShim.java:870)
at org.apache.impala.catalog.events.MetastoreEvents$MetastoreEvent.processIfEnabled(MetastoreEvents.java:672)
at org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:1164)
at org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:972)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.impala.catalog.TableLoadingException: Refreshing file and block metadata for 1 paths for table test_read_hive_inserts_8bb30aca.test_read_hive_inserts: failed to load 1 paths. Check the catalog server log for more details.
at org.apache.impala.catalog.ParallelFileMetadataLoader.loadInternal(ParallelFileMetadataLoader.java:210)
at org.apache.impala.catalog.ParallelFileMetadataLoader.load(ParallelFileMetadataLoader.java:140)
at org.apache.impala.catalog.HdfsTable.loadFileMetadataForPartitions(HdfsTable.java:805)
at org.apache.impala.catalog.HdfsTable.loadFileMetadataForPartitions(HdfsTable.java:761)
at org.apache.impala.catalog.HdfsTable.reloadPartitions(HdfsTable.java:2951)
at org.apache.impala.catalog.HdfsTable.reloadPartitions(HdfsTable.java:2884)
at org.apache.impala.catalog.HdfsTable.reloadPartitionsFromEvent(HdfsTable.java:2864)
at org.apache.impala.service.CatalogOpExecutor.addCommittedWriteIdsAndReloadPartitionsIfExist(CatalogOpExecutor.java:4994)
at org.apache.impala.compat.MetastoreShim$CommitTxnEvent.addCommittedWriteIdsAndRefreshPartitions(MetastoreShim.java:911)
at org.apache.impala.compat.MetastoreShim$CommitTxnEvent.process(MetastoreShim.java:865)
... 10 more
This seems a bug of event-processor.