Quanlong Huang created IMPALA-12637:
---------------------------------------

             Summary: Failed to process CREATE_TABLE events if the db is 
unloaded
                 Key: IMPALA-12637
                 URL: https://issues.apache.org/jira/browse/IMPALA-12637
             Project: IMPALA
          Issue Type: Bug
          Components: Catalog
            Reporter: Quanlong Huang


Applying a CREATE_TABLE event could fail by DatabaseNotFoundException is the db 
is unloaded. The exception is thrown by 
CatalogOpExecutor#addTableIfNotRemovedLater():
[https://github.com/apache/impala/blob/3af193022916e42c33d6eafafb6f9560a0789895/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java#L826-L831]

In fact, there are cases that the db exists in HMS but is unloaded in catalogd 
(even if HMS event processing is enabled). For instance, when HMS is restarted 
during the launching period of catalogd, some dbs might be failed in loading:
{noformat}
W1215 08:27:27.811750 26987 CatalogServiceCatalog.java:2014] Encountered an 
exception while invalidating database: default. Ignoring further load of this 
db.
Java exception follows:
MetaException(message:Could not connect to meta store using any of the URIs 
provided. Most recent failure: org.apache.thrift.transport.TTransportException: 
java.net.ConnectException: Connection refused (Connection refused)
        at org.apache.thrift.transport.TSocket.open(TSocket.java:255)
        at 
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.open(HiveMetaStoreClient.java:755)
        at 
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.reconnect(HiveMetaStoreClient.java:448)
        at 
org.apache.hadoop.hive.metastore.RetryingMetaStoreClient$1.run(RetryingMetaStoreClient.java:191)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:422)
        at 
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1899)
        at 
org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:187)
        at com.sun.proxy.$Proxy11.getFunctions(Unknown Source)
        at 
org.apache.impala.catalog.CatalogServiceCatalog.invalidateDb(CatalogServiceCatalog.java:1943)
        at 
org.apache.impala.catalog.CatalogServiceCatalog.reset(CatalogServiceCatalog.java:2103)
        at org.apache.impala.service.JniCatalog.<init>(JniCatalog.java:175)
Caused by: java.net.ConnectException: Connection refused (Connection refused)
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at 
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
        at 
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
        at 
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
        at java.net.Socket.connect(Socket.java:607)
        at org.apache.thrift.transport.TSocket.open(TSocket.java:250)
        ... 11 more
)
        at 
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.open(HiveMetaStoreClient.java:826)
        at 
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.reconnect(HiveMetaStoreClient.java:448)
        at 
org.apache.hadoop.hive.metastore.RetryingMetaStoreClient$1.run(RetryingMetaStoreClient.java:191)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:422)
        at 
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1899)
        at 
org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:187)
        at com.sun.proxy.$Proxy11.getFunctions(Unknown Source)
        at 
org.apache.impala.catalog.CatalogServiceCatalog.invalidateDb(CatalogServiceCatalog.java:1943)
        at 
org.apache.impala.catalog.CatalogServiceCatalog.reset(CatalogServiceCatalog.java:2103)
        at 
org.apache.impala.service.JniCatalog.<init>(JniCatalog.java:175){noformat}
I can reproduce the issue by adding a breakpoint in 
CatalogServiceCatalog#invalidateDb() and attach to the process by IntelliJ 
during catalogd is launching. Then kill HMS and resume catalogd. After seeing 
this log, restart HMS and resume catalogd again.

The event processor will go into the ERROR state when processing any 
CREATE_TABLE event in that db:
{noformat}
E1215 08:29:54.121959 27281 MetastoreEventsProcessor.java:979] Unexpected 
exception received while processing event
Java exception follows:
org.apache.impala.catalog.events.MetastoreNotificationException: EventId: 
8411895 EventType: CREATE_TABLE Unable to process event
        at 
org.apache.impala.catalog.events.MetastoreEvents$CreateTableEvent.process(MetastoreEvents.java:1213)
        at 
org.apache.impala.catalog.events.MetastoreEvents$MetastoreEvent.processIfEnabled(MetastoreEvents.java:528)
        at 
org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:1153)
        at 
org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:961)
        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)
Caused by: org.apache.impala.catalog.DatabaseNotFoundException: default not 
found
        at 
org.apache.impala.service.CatalogOpExecutor.addTableIfNotRemovedLater(CatalogOpExecutor.java:831)
        at 
org.apache.impala.catalog.events.MetastoreEvents$CreateTableEvent.process(MetastoreEvents.java:1200)
        ... 10 more 
E1215 08:29:54.137053 27281 MetastoreEventsProcessor.java:1237] Event id: 
8411895
Event Type: CREATE_TABLE
Event time: 1702600193
Database name: default
Table name: newtbl
Event message: 
H4sIAAAAAAAAAL1V23LaMBD9Fz87xjK5AG+0uNO0DGTAmelMyTACL1itkB1JTkoY/j1rySTYuGn70LxgsUfeyzm7652jQD6AdHqOTiRb6V6rxdMl5UmqdK/rd9qOa66wJdxIJpYsoxwvozVe4DOGFc25xr+aLjigRcCjXvCDIdpmhTH8FoWTUX84j/ofhuEBHC9+fFGpQHw3c8jM6eFDaYmHWelm5uzdmRNUoTKmxdpV7D6ngqdibcFzC7J24YFc+cGl75Nuu4AujiG/sFyeWK6sRcLSHsoUucLYve8l4BL3NHvWmDgTRdL7uwYoiVeqQn3gX/h+S4PSZ49UQpLmClrHpNQKT+XaoxldJuAlNE7TzNvQTELsRfBLX4ss159SuaG6QszvX07YA3j33GOp9xmP12uRSvgK28LbONc1dyWZetXI5RlpIjP4qxSw9WIIPE6ftt4Qf6Zsk3GYghxAhQYs1mpi/LmHp9EGfTDK2RPVLBXeqsy7Z0RDMfaFm05NWvu6b6TqNspuMeK/Gd93d1ZuQv7QS8cBgxpmDiVWr9di1XimIhJURGms8riS7puFXBRERpP+aDrsR+FgHo3nh5k2VEaT29Bc15IKxUDoOadKD2IesQ1Ytl/mz1xc5MufoJlYz3H9KFTGXAoMhk0GUlDumTXhZblcQzVMQ/CS6FpfVTeP7RnSbhbjpHZLrmmi18XyStx5w+Rfj6bhJKqM//EU/MO6qg8WQQlP403DYfjxHePd3gywAd4v3gDr+2/x7l6G5by+wchVbUHjNiq7p3PiNjjsu8vCD+l0SYDei88cNr/SdJMdf35cZ8U4KGyku/0zLOV3nYAHAAA=
W1215 08:29:54.979072 27281 MetastoreEventsProcessor.java:950] Event processing 
is skipped since status is ERROR. Last synced event id is 8411894{noformat}



--
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

Reply via email to