You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues-all@impala.apache.org by "Quanlong Huang (Jira)" <ji...@apache.org> on 2024/01/04 00:28:00 UTC
[jira] [Commented] (IMPALA-12680) NullPointerException in addHmsPartitions() during MetastoreEventsProcessor switch state from PAUSED to ACTIVE
[ https://issues.apache.org/jira/browse/IMPALA-12680?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17802352#comment-17802352 ]
Quanlong Huang commented on IMPALA-12680:
-----------------------------------------
I found this issue when I loop test_local_catalog_ddls_with_invalidate_metadata till the night. The test fails at the 724-th iteration.
In the catalogd logs, we can see the global IM starts before the AlterTable statement starts:
{noformat}
I0104 02:46:31.896565 1015 CatalogServiceCatalog.java:2043] ec4d75ea341cd523:9cce70ca00000000] Invalidating all metadata. Version: 15058
I0104 02:46:31.897241 1015 MetastoreEventsProcessor.java:735] ec4d75ea341cd523:9cce70ca00000000] Event processing is paused. Last synced event id is 8556195
I0104 02:46:31.897735 1010 JniUtil.java:166] 4a4eae34f60ba947:b6b2bcfc00000000] execDdl request: ALTER_TABLE test_local_catalog_ddls_with_invalidate_metadata_e78f2324.test_12_part issued by quanlong
W0104 02:46:32.066480 1010 CatalogServiceCatalog.java:539] 4a4eae34f60ba947:b6b2bcfc00000000] Write lock for table test_local_catalog_ddls_with_invalidate_metadata_e78f2324.test_12_part was acquired in 169 msec {noformat}
and the global IM finishes before the AlterTable statement finishes:
{noformat}
I0104 02:46:32.067077 1015 MetastoreEventsProcessor.java:821] ec4d75ea341cd523:9cce70ca00000000] Metastore event processing restarted. Last synced event id was updated from 8556195 to 8556207
I0104 02:46:32.067114 1015 CatalogServiceCatalog.java:2147] ec4d75ea341cd523:9cce70ca00000000] Invalidated all metadata.
I0104 02:46:32.073968 1010 CatalogOpExecutor.java:5031] 4a4eae34f60ba947:b6b2bcfc00000000] Added 1/1 partitions in HMS for table test_local_catalog_ddls_with_invalidate_metadata_e78f2324.test_12_part
E0104 02:46:32.075673 1010 JniUtil.java:183] 4a4eae34f60ba947:b6b2bcfc00000000] Error in ALTER_TABLE test_local_catalog_ddls_with_invalidate_metadata_e78f2324.test_12_part issued by quanlong. Time spent: 178ms
I0104 02:46:32.075830 1010 jni-util.cc:302] 4a4eae34f60ba947:b6b2bcfc00000000] java.lang.NullPointerException
at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:889)
at org.apache.impala.service.CatalogOpExecutor.addHmsPartitions(CatalogOpExecutor.java:5051)
at org.apache.impala.service.CatalogOpExecutor.addHmsPartitionsInTransaction(CatalogOpExecutor.java:5082)
at org.apache.impala.service.CatalogOpExecutor.alterTableAddPartitions(CatalogOpExecutor.java:4388)
at org.apache.impala.service.CatalogOpExecutor.alterTable(CatalogOpExecutor.java:1136)
at org.apache.impala.service.CatalogOpExecutor.execDdlRequest(CatalogOpExecutor.java:450)
at org.apache.impala.service.JniCatalog.lambda$execDdl$3(JniCatalog.java:304)
at org.apache.impala.service.JniCatalogOp.lambda$execAndSerialize$1(JniCatalogOp.java:90)
at org.apache.impala.service.JniCatalogOp.execOp(JniCatalogOp.java:58)
at org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:89)
at org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:100)
at org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:233)
at org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:247)
at org.apache.impala.service.JniCatalog.execDdl(JniCatalog.java:303){noformat}
> NullPointerException in addHmsPartitions() during MetastoreEventsProcessor switch state from PAUSED to ACTIVE
> -------------------------------------------------------------------------------------------------------------
>
> Key: IMPALA-12680
> URL: https://issues.apache.org/jira/browse/IMPALA-12680
> Project: IMPALA
> Issue Type: Bug
> Components: Catalog
> Reporter: Quanlong Huang
> Priority: Major
> Attachments: alterTableAddPartitionProfile.txt, catalogd.INFO.gz, impalad.INFO.gz
>
>
> Event processing is paused during a global INVALIDATE METADATA.
> catalog_.isEventProcessingActive() returns false in this state.
>
> If an AlterTableAddPartition statement is running during that time, we could pass in a null value for the 'partitionToEventId' map in here:
> {code:java}
> Map<String, Long> partitionToEventId = catalog_.isEventProcessingActive() ?
> Maps.newHashMap() : null;
> List<Partition> addedHmsPartitions = addHmsPartitionsInTransaction(msClient,
> tbl, allHmsPartitionsToAdd, partitionToEventId, ifNotExists); {code}
> https://github.com/apache/impala/blob/fcda98ad99c13324e3ab09f2e92d331d0304bb8e/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java#L4404-L4407
> If the global INVALIDATE METADATA finishes and event processing is back to the ACTIVE state before the AlterTableAddPartition statement runs into addHmsPartitions(), we will have an non-empty 'partitionToEventSubMap' here:
> {code:java}
> List<NotificationEvent> events = getNextMetastoreEventsIfEnabled(eventId,
> event -> AddPartitionEvent.ADD_PARTITION_EVENT_TYPE
> .equals(event.getEventType())
> && msTbl.getDbName().equalsIgnoreCase(event.getDbName())
> && msTbl.getTableName().equalsIgnoreCase(event.getTableName()));
> Map<Partition, Long> partitionToEventSubMap = Maps.newHashMap();
> getPartitionsFromEvent(events, partitionToEventSubMap);
> // set the eventId to last one which we received so the we fetch the next
> // set of events correctly
> if (!events.isEmpty()) {
> eventId = events.get(events.size() - 1).getEventId();
> }
> if (partitionToEventSubMap.isEmpty()) {
> // if partitions couldn't be fetched from events, use the one returned by
> // add_partitions call above.
> addedHmsPartitions.addAll(addedPartitions);
> } else {
> Preconditions.checkNotNull(partitionToEventId); // <-- This will fail{code}
> https://github.com/apache/impala/blob/fcda98ad99c13324e3ab09f2e92d331d0304bb8e/fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java#L5052-L5069
> Then the AlterTableAddPartition statement fails with NullPointerException:
> {code:java}
> I0104 02:46:32.075830 1010 jni-util.cc:302] 4a4eae34f60ba947:b6b2bcfc00000000] java.lang.NullPointerException
> at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:889)
> at org.apache.impala.service.CatalogOpExecutor.addHmsPartitions(CatalogOpExecutor.java:5051)
> at org.apache.impala.service.CatalogOpExecutor.addHmsPartitionsInTransaction(CatalogOpExecutor.java:5082)
> at org.apache.impala.service.CatalogOpExecutor.alterTableAddPartitions(CatalogOpExecutor.java:4388)
> at org.apache.impala.service.CatalogOpExecutor.alterTable(CatalogOpExecutor.java:1136)
> at org.apache.impala.service.CatalogOpExecutor.execDdlRequest(CatalogOpExecutor.java:450)
> at org.apache.impala.service.JniCatalog.lambda$execDdl$3(JniCatalog.java:304)
> at org.apache.impala.service.JniCatalogOp.lambda$execAndSerialize$1(JniCatalogOp.java:90)
> at org.apache.impala.service.JniCatalogOp.execOp(JniCatalogOp.java:58)
> at org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:89)
> at org.apache.impala.service.JniCatalogOp.execAndSerialize(JniCatalogOp.java:100)
> at org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:233)
> at org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:247)
> at org.apache.impala.service.JniCatalog.execDdl(JniCatalog.java:303){code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscribe@impala.apache.org
For additional commands, e-mail: issues-all-help@impala.apache.org