Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-10187

Event processing fails on multiple events + DROP TABLE

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • None
    • Impala 4.1.0
    • Catalog
    • None
    • ghx-label-4

    Description

      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:

      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
      

       

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

       

      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
      

      But the real problem is that event processing stops because of this error, i.e. no further events can be processed:

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

      Attachments

        Activity

          People

            vihangk1 Vihang Karajgaonkar
            boroknagyz Zoltán Borók-Nagy
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: