You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@impala.apache.org by "Zoltán Borók-Nagy (Jira)" <ji...@apache.org> on 2021/06/14 08:39:00 UTC

[jira] [Resolved] (IMPALA-10187) Event processing fails on multiple events + DROP TABLE

     [ https://issues.apache.org/jira/browse/IMPALA-10187?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Zoltán Borók-Nagy resolved IMPALA-10187.
----------------------------------------
    Fix Version/s: Impala 4.1
       Resolution: Fixed

> Event processing fails on multiple events + DROP TABLE
> ------------------------------------------------------
>
>                 Key: IMPALA-10187
>                 URL: https://issues.apache.org/jira/browse/IMPALA-10187
>             Project: IMPALA
>          Issue Type: Bug
>          Components: Catalog
>            Reporter: Zoltán Borók-Nagy
>            Assignee: Vihang Karajgaonkar
>            Priority: Major
>             Fix For: Impala 4.1
>
>
> I've seen the following during interop testing:
> Some DDL statements (ALTER TABLE + DROP) were executed via Hive on the same table.
> Then CatalogD's event processor tried to process the new events:
> {noformat}
> I0922 14:32:56.590229 13611 HdfsTable.java:709] Loaded file and block metadata for default.insertonly_hiveclient_impalaclient_partitioned_8ff3a1ef_b8a8_4c7a_b1c7_0b8f4c42c61e partitions: category=cat1, category=cat2, category=cat3, and 1 others. Time taken: 55.145ms
> I0922 14:32:56.591078 13611 TableLoader.java:103] Loaded metadata for: default.insertonly_hiveclient_impalaclient_partitioned_8ff3a1ef_b8a8_4c7a_b1c7_0b8f4c42c61e (303ms)
> I0922 14:32:58.022068 10065 MetastoreEventsProcessor.java:482] Received 41 events. Start event id : 39948
> I0922 14:32:58.022266 10065 MetastoreEvents.java:380] EventId: 39949 EventType: ALTER_PARTITION Creating event 39949 of type ALTER_PARTITION on table default.insertonly_hiveclient_impalaclient_partitioned_8ff3a1ef_b8a8_4c7a_b1c7_0b8f4c42c61e
> ...
> I0922 14:32:58.024389 10065 MetastoreEvents.java:380] EventId: 39962 EventType: DROP_TABLE Creating event 39962 of type DROP_TABLE on table default.insertonly_hiveclient_impalaclient_partitioned_8ff3a1ef_b8a8_4c7a_b1c7_0b8f4c42c61e
> {noformat}
>  
> Impala tried to refresh the table on the first ALTER TABLE event, but since it's been already dropped we get a TableLoadingException (caused by NoSuchObjectException from HMS):
>  
> {noformat}
> I0922 14:32:58.028852 10065 MetastoreEvents.java:234] Total number of events received: 41 Total number of events filtered out: 0
> I0922 14:32:58.028962 10065 CatalogServiceCatalog.java:862] Not a self-event since the given version is -1 and service id is
> I0922 14:32:58.029369 10065 CatalogServiceCatalog.java:2142] Refreshing table metadata: default.insertonly_hiveclient_impalaclient_partitioned_8ff3a1ef_b8a8_4c7a_b1c7_0b8f4c42c61e
> E0922 14:32:58.038627 10065 MetastoreEventsProcessor.java:527] Unexpected exception received while processing event
> Java exception follows:
> org.apache.impala.catalog.events.MetastoreNotificationException: Unable to process event 39949 of type ALTER_PARTITION. Event processing will be stopped.
>         at org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:620)
>         at org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:513)
>         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: Error loading metadata for table: default.insertonly_hiveclient_impalaclient_partitioned_8ff3a1ef_b8a8_4c7a_b1c7_0b8f4c42c61e
>         at org.apache.impala.catalog.CatalogServiceCatalog.reloadTable(CatalogServiceCatalog.java:2160)
>         at org.apache.impala.catalog.CatalogServiceCatalog.reloadTableIfExists(CatalogServiceCatalog.java:2365)
>         at org.apache.impala.catalog.events.MetastoreEvents$MetastoreTableEvent.reloadTableFromCatalog(MetastoreEvents.java:563)
>         at org.apache.impala.catalog.events.MetastoreEvents$AlterPartitionEvent.process(MetastoreEvents.java:1454)
>         at org.apache.impala.catalog.events.MetastoreEvents$MetastoreEvent.processIfEnabled(MetastoreEvents.java:314)
>         at org.apache.impala.catalog.events.MetastoreEventsProcessor.processEvents(MetastoreEventsProcessor.java:615)
>         ... 8 more
> Caused by: NoSuchObjectException(message:hive.default.insertonly_hiveclient_impalaclient_partitioned_8ff3a1ef_b8a8_4c7a_b1c7_0b8f4c42c61e table not found)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$get_table_req_result$get_table_req_resultStandardScheme.read(ThriftHiveMetastore.java)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$get_table_req_result$get_table_req_resultStandardScheme.read(ThriftHiveMetastore.java)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$get_table_req_result.read(ThriftHiveMetastore.java)
>         at org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:86)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Client.recv_get_table_req(ThriftHiveMetastore.java:2350)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Client.get_table_req(ThriftHiveMetastore.java:2337)
>         at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.getTable(HiveMetaStoreClient.java:2030)
>         at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.getTable(HiveMetaStoreClient.java:2013)
>         at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.getTable(HiveMetaStoreClient.java:2003)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:498)
>         at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:208)
>         at com.sun.proxy.$Proxy11.getTable(Unknown Source)
>         at org.apache.impala.catalog.CatalogServiceCatalog.reloadTable(CatalogServiceCatalog.java:2158)
>         ... 13 more
> {noformat}
> But the real problem is that event processing stops because of this error, i.e. no further events can be processed:
> {noformat}
> W0922 14:33:02.039422 10065 MetastoreEventsProcessor.java:506] Event processing is skipped since status is ERROR. Last synced event id is 39948
> W0922 14:33:04.039711 10065 MetastoreEventsProcessor.java:506] Event processing is skipped since status is ERROR. Last synced event id is 39948
> W0922 14:33:06.040015 10065 MetastoreEventsProcessor.java:506] Event processing is skipped since status is ERROR. Last synced event id is 39948
> W0922 14:33:08.045881 10065 MetastoreEventsProcessor.java:506] Event processing is skipped since status is ERROR. Last synced event id is 39948
> ...{noformat}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)