[
https://issues.apache.org/jira/browse/IMPALA-13993?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Quanlong Huang resolved IMPALA-13993.
-------------------------------------
Fix Version/s: Impala 5.0.0
Resolution: Fixed
> TestEventSyncWaiting.test_hms_event_sync_basic failed in DropTable
> -------------------------------------------------------------------
>
> Key: IMPALA-13993
> URL: https://issues.apache.org/jira/browse/IMPALA-13993
> Project: IMPALA
> Issue Type: Bug
> Components: Catalog
> Reporter: Quanlong Huang
> Assignee: Quanlong Huang
> Priority: Critical
> Fix For: Impala 5.0.0
>
>
> Saw TestEventSyncWaiting.test_hms_event_sync_basic failed after IMPALA-13684
> {code:python}
> TestEventSyncWaiting.test_hms_event_sync_basic[protocol: beeswax |
> table_format: text/none | exec_option: {'test_replan': 1,
> 'sync_hms_events_wait_time_s': 10, 'batch_size': 0, 'num_nodes': 0,
> 'disable_codegen_rows_threshold': 5000, 'disable_codegen': False,
> 'abort_on_error': 1, 'exec_single_node_rows_threshold': 0,
> 'sync_hms_events_strict_mode': True}]
> [gw0] linux2 -- Python 2.7.16
> /home/quanlong/workspace/Impala/infra/python/env-gcc10.4.0/bin/python
> tests/metadata/test_event_processing.py:369: in test_hms_event_sync_basic
> client, "drop table {0}_2.tbl".format(unique_database))
> tests/common/impala_test_suite.py:1134: in wrapper
> return function(*args, **kwargs)
> tests/common/impala_test_suite.py:1144: in execute_query_expect_success
> result = cls.__execute_query(impalad_client, query, query_options, user)
> tests/common/impala_test_suite.py:1312: in __execute_query
> return impalad_client.execute(query, user=user)
> tests/common/impala_connection.py:505: in execute
> fetch_exec_summary=fetch_exec_summary)
> tests/beeswax/impala_beeswax.py:195: in execute
> handle = self.__execute_query(query_string.strip(), user=user)
> tests/beeswax/impala_beeswax.py:291: in __execute_query
> handle = self.execute_query_async(query_string, user=user)
> tests/beeswax/impala_beeswax.py:285: in execute_query_async
> handle = self.__do_rpc(lambda: self.imp_service.query(query,))
> tests/beeswax/impala_beeswax.py:470: in __do_rpc
> raise ImpalaBeeswaxException(self.__build_error_message(b), b)
> E ImpalaBeeswaxException: Query 7d4b01c2fb5fb3c8:adb779d900000000 failed:
> E AnalysisException: Table does not exist:
> test_hms_event_sync_basic_7d94d913_2.tbl{code}
> stderr
> {noformat}
> -- 2025-04-25 14:16:22,621 INFO MainThread: -- executing in HiveServer2
> create database test_hms_event_sync_basic_7d94d913_2;
> create table test_hms_event_sync_basic_7d94d913_2.tbl(i int);
> create table test_hms_event_sync_basic_7d94d913_2.tbl_2(i int);
> -- 2025-04-25 14:16:24,307 INFO MainThread: beeswax: executing against
> localhost:21000
> drop table test_hms_event_sync_basic_7d94d913_2.tbl;{noformat}
> The test creates a db and two tables under it in Hive. Then drop the table in
> Impala but it fails. Checking the catalogd logs, it waits for the
> CREATE_DATABASE event to be processed.
> {noformat}I0425 14:16:24.308948 109426 JniUtil.java:167]
> 7d4b01c2fb5fb3c8:adb779d900000000] waitForHmsEvent request: waitForHmsEvent
> 7d4b01c2fb5fb3c8:adb779d900000000
> I0425 14:16:24.309022 109426 CatalogServiceCatalog.java:4341]
> 7d4b01c2fb5fb3c8:adb779d900000000] waitForHmsEvent request:
> want_minimal_response=false, coordinator=quanlong-Precision-3680,
> timeout_s=10, want_db_list=false, want_table_list=false,
> objects=[TABLE:test_hms_event_sync_basic_7d94d913_2.tbl,
> DATABASE:test_hms_event_sync_basic_7d94d913_2], should_expand_views=false
> I0425 14:16:24.309767 109426 MetastoreEventsProcessor.java:408]
> 7d4b01c2fb5fb3c8:adb779d900000000] Fetching
> ALTER_DATABASE,CREATE_DATABASE,DROP_DATABASE events started from id 123366 to
> 123377. Gap: 11
> I0425 14:16:24.310648 113084 MetaStoreUtil.java:223] Fetched 1/1 partitions
> for table test_hms_event_sync_compute_stats_3d662792.foo
> I0425 14:16:24.310675 113084 HdfsTable.java:1306] Fetched partition metadata
> from the Metastore: test_hms_event_sync_compute_stats_3d662792.foo
> I0425 14:16:24.310709 109426 MetastoreEventsProcessor.java:1855]
> 7d4b01c2fb5fb3c8:adb779d900000000] Found db
> test_hms_event_sync_basic_7d94d913_2 has pending event. EventId:123368
> EventType:CREATE_DATABASE
> I0425 14:16:24.310739 109426 MetastoreEventsProcessor.java:1631]
> 7d4b01c2fb5fb3c8:adb779d900000000] Waiting for last synced event id (123366)
> to reach 123368
> I0425 14:16:24.312629 113084 HdfsTable.java:781] Loaded file and block
> metadata for test_hms_event_sync_compute_stats_3d662792.foo partitions: p=0.
> Time taken: 844.104us
> I0425 14:16:24.312776 113084 Table.java:1121] last refreshed event id for
> table: test_hms_event_sync_compute_stats_3d662792.foo set to: -1
> I0425 14:16:24.312800 113084 TableLoader.java:187] Loaded metadata for:
> test_hms_event_sync_compute_stats_3d662792.foo (14ms)
> I0425 14:16:24.609163 109031 MetastoreEventsProcessor.java:1195] Latest event
> in HMS: id=123378, time=1745561784. Last synced event: id=123366,
> time=1745561783.
> W0425 14:16:24.609205 109031 MetastoreEventsProcessor.java:1198] Lag: 1s. 12
> events pending to be processed.
> I0425 14:16:24.610044 109030 MetastoreEventsProcessor.java:1057] Received 8
> events. First event id: 123368.
> I0425 14:16:24.610121 109030 MetastoreEvents.java:853] EventId: 123368
> EventType: CREATE_DATABASE Target: test_hms_event_sync_basic_7d94d913_2.
> Creating event 123368 of type CREATE_DATABASE on database
> test_hms_event_sync_basic_7d94d913_2
> I0425 14:16:24.610263 109030 MetastoreShim.java:857] EventId: 123369
> EventType: COMMIT_TXN transaction id: 6213
> I0425 14:16:24.610435 109030 MetastoreShim.java:857] EventId: 123372
> EventType: COMMIT_TXN transaction id: 6207
> I0425 14:16:24.610527 109030 MetastoreShim.java:857] EventId: 123374
> EventType: COMMIT_TXN transaction id: 6214
> I0425 14:16:24.610601 109030 MetastoreShim.java:857] EventId: 123377
> EventType: COMMIT_TXN transaction id: 6215
> I0425 14:16:24.610620 109030 MetastoreEvents.java:304] Total number of events
> received: 8 Total number of events filtered out: 0
> I0425 14:16:24.610684 109030 Db.java:143] createEventId_ for db:
> test_hms_event_sync_basic_7d94d913_2 set to: 123368
> I0425 14:16:24.610697 109030 Db.java:155] lastSyncedEventId_ for db:
> test_hms_event_sync_basic_7d94d913_2 set from -1 to 123368
> I0425 14:16:24.610713 109030 MetastoreEvents.java:842] EventId: 123368
> EventType: CREATE_DATABASE Target: test_hms_event_sync_basic_7d94d913_2.
> Successfully added database test_hms_event_sync_basic_7d94d913_2
> I0425 14:16:24.611009 109426 MetastoreEventsProcessor.java:1651]
> 7d4b01c2fb5fb3c8:adb779d900000000] Last synced event id (123368) reached
> 123368
> I0425 14:16:24.611114 109426 CatalogServiceCatalog.java:4418]
> 7d4b01c2fb5fb3c8:adb779d900000000] waitForHmsEvent succeeds.
> updated_objects=[DATABASE:test_hms_event_sync_basic_7d94d913_2(2383)],
> removed_objects=[TABLE:test_hms_event_sync_basic_7d94d913_2.tbl(2247)]
> I0425 14:16:24.611183 109426 JniUtil.java:178]
> 7d4b01c2fb5fb3c8:adb779d900000000] Finished waitForHmsEvent request:
> waitForHmsEvent 7d4b01c2fb5fb3c8:adb779d900000000. Time spent: 303ms{noformat}
> The target event id in the log "Waiting for last synced event id (123366) to
> reach 123368" is the CREATE_DATABASE event id, indicating by the log "Found
> db test_hms_event_sync_basic_7d94d913_2 has pending event. EventId:123368
> EventType:CREATE_DATABASE".
> However, processing the CREATE_DATABASE event just adds an empty Db object
> without any tables in it.
> https://github.com/apache/impala/blob/ef8f8ca27b52f7fd842a7a887d5c9a8db9831f79/fe/src/main/java/org/apache/impala/catalog/events/MetastoreEvents.java#L2252
> https://github.com/apache/impala/blob/ef8f8ca27b52f7fd842a7a887d5c9a8db9831f79/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java#L980
> https://github.com/apache/impala/blob/ef8f8ca27b52f7fd842a7a887d5c9a8db9831f79/fe/src/main/java/org/apache/impala/catalog/CatalogServiceCatalog.java#L2384
> This breaks out assumption in
> MetastoreEventsProcessor#getMinEventIdToWaitFor() to skip checking table
> events under missing dbs:
> https://github.com/apache/impala/blob/ef8f8ca27b52f7fd842a7a887d5c9a8db9831f79/fe/src/main/java/org/apache/impala/catalog/events/MetastoreEventsProcessor.java#L1682-L1685
> We do need to check all table events even if their dbs are missing in the
> cache.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
