[IMPALA-12213] Not a self-event because service id of this catalog does not match with one in event

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: Impala 4.3.0
• Fix Version/s: Impala 4.3.0
• Component/s: Catalog
• Epic Color: ghx-label-3
• Assignee: Sai Hemanth Gantasala
• Reporter: Ezra Zerihun
• Created: 14/Jun/23 15:52
• Updated: 26/Jun/23 17:41
• Resolved: 26/Jun/23 17:41

Description

Customer started a few Impala Virtual Warehouses that all connected to the same Database Catalog in DW. After it finished starting, they noticed tables seen in their Hive VW were missing from their Impala VW. Looking in Catalog pod logs we Event Processor was stuck in Error state:

W0528 07:11:42.398236 228 MetastoreEventsProcessor.java:844] Event processing is skipped since status is ERROR. Last synced event id is 33348458

Running "invalidate metadata {table}" or global invalidate metadata shows the tables.

 

Looking at old Catalog pod logs when the error first appeared shows this unique stacktrace that led to the ERROR state

_____________________
I0528 07:11:40.397091 228 MetastoreEvents.java:638] EventId: 33348458 EventType: OTHER Ignoring unknown event type OPEN_TXN
I0528 07:11:40.397158 228 CatalogServiceCatalog.java:1022] Not a self-event because service id of this catalog c1aad0ff73c54b79:96249bcba6589cb8 does not match with one in event 751641d1aed04da4:8929d897001acc0f.
I0528 07:11:40.397374 228 MetastoreEventsProcessor.java:1026] Time elapsed in processing event batch: 1.015ms E0528 07:11:40.397637   228 MetastoreEventsProcessor.java:865] Unexpected exception received while processing event
Java exception follows:
java.lang.NullPointerException
        at org.apache.impala.catalog.events.MetastoreEvents$ReloadEvent.isOlderEvent(MetastoreEvents.java:2526)
        at org.apache.impala.catalog.events.MetastoreEvents$ReloadEvent.process(MetastoreEvents.java:2501)
        at org.apache.impala.catalog.events.MetastoreEvents$MetastoreEvent.processIfEnabled(MetastoreEvents.java:521)
        at org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:1013)
        at org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:851)
        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:750)
E0528 07:11:40.397707 228 MetastoreEventsProcessor.java:1040] Notification event is null
I0528 07:11:41.177731 341 catalog-server.cc:411] A catalog update with 2 entries is assembled. Catalog version: 113555 Last sent catalog version: 113554
I0528 07:11:41.324290 295 catalog-server.cc:824] Collected update: 2:CATALOG_SERVICE_ID, version=113559, original size=60, compressed size=59
I0528 07:11:41.324410 295 JniUtil.java:169] Finished getCatalogDelta request: Getting catalog delta from version 113555. Time spent: 147ms
W0528 07:11:41.397955 228 MetastoreEventsProcessor.java:844] Event processing is skipped since status is ERROR. Last synced event id is 33348458
W0528 07:11:42.398236 228 MetastoreEventsProcessor.java:844] Event processing is skipped since status is ERROR. Last synced event id is 33348458
_____________________

Issue Links

• is caused by: IMPALA-11822 Optimize the Refresh/Invalidate event processing by skipping unnecessary events