[
https://issues.apache.org/jira/browse/IMPALA-14062?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Quanlong Huang updated IMPALA-14062:
------------------------------------
Description:
Here is an AlterPartition statement that runs several seconds:
{code:sql}
alter table tbl1 partition(p=0) set tblproperties('key'='myvalue'){code}
The catalog timeline in profile indicates fetching latest event id is the
bottleneck:
{noformat}
Catalog Server Operation: 4s794ms
- Got catalog version read lock: 168.861us (168.861us)
- Got catalog version write lock and table write lock: 312.483us
(143.622us)
- Got Metastore client: 258.655ms (258.342ms)
- Altered 1 partitions in Metastore: 677.772ms (419.117ms)
- Got Metastore client: 678.291ms (519.440us)
- Fetched table from Metastore: 909.802ms (231.510ms)
- Loaded all column stats: 986.145ms (76.343ms)
- Loaded table schema: 993.366ms (7.220ms)
- Got current Metastore event id 48196: 4s579ms (3s585ms) <---
Bottleneck
- Start loading file metadata: 4s579ms (51.936us)
- Loaded file metadata for 1 partitions: 4s582ms (3.417ms)
- Reloaded table metadata: 4s793ms (211.162ms)
- DDL finished: 4s794ms (187.654us){noformat}
However, the actual time is spent in fetching the partition list in the
constructor of PartNameBasedDeltaUpdater, as shown in the jstack:
{noformat}
"Thread-38 [ALTER_TABLE scale_400k_500cols_db.tbl1 issued by
[email protected]] [Reloading metadata for table definition and all
partition(s) of scale_400k_500cols_db.tbl1 (ALTER TABLE SET_TBL_PROPERTIES)]"
#177 prio=5 os_prio=0 tid=0x0000000015a26000 nid=0x2702 runnable
[0x00007fc79e80b000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
- locked <0x00007fc801db9a38> (a java.io.BufferedInputStream)
at
org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:177)
at org.apache.thrift.transport.TTransport.readAll(TTransport.java:109)
at
org.apache.thrift.transport.TSaslTransport.readLength(TSaslTransport.java:338)
at
org.apache.thrift.transport.TSaslTransport.readFrame(TSaslTransport.java:421)
at
org.apache.thrift.transport.TSaslTransport.read(TSaslTransport.java:397)
at
org.apache.thrift.transport.TSaslClientTransport.read(TSaslClientTransport.java:39)
at org.apache.thrift.transport.TTransport.readAll(TTransport.java:109)
at
org.apache.hadoop.hive.metastore.security.TFilterTransport.readAll(TFilterTransport.java:63)
at
org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:464)
at
org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:362)
at
org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:245)
at org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:77)
at
org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Client.recv_get_partition_names(ThriftHiveMetastore.java:3567)
at
org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Client.get_partition_names(ThriftHiveMetastore.java:3552)
at
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.listPartitionNames(HiveMetaStoreClient.java:2550)
at
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.listPartitionNames(HiveMetaStoreClient.java:2526)
at sun.reflect.GeneratedMethodAccessor53.invoke(Unknown Source)
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:209)
at com.sun.proxy.$Proxy31.listPartitionNames(Unknown Source)
at
org.apache.impala.catalog.HdfsTable$PartNameBasedDeltaUpdater.<init>(HdfsTable.java:1749)
at
org.apache.impala.catalog.HdfsTable.updatePartitionsFromHms(HdfsTable.java:1477)
at org.apache.impala.catalog.HdfsTable.load(HdfsTable.java:1318)
at
org.apache.impala.service.CatalogOpExecutor.loadTableMetadata(CatalogOpExecutor.java:1623)
at
org.apache.impala.service.CatalogOpExecutor.loadTableMetadata(CatalogOpExecutor.java:1598)
at
org.apache.impala.service.CatalogOpExecutor.alterTable(CatalogOpExecutor.java:1315)
at
org.apache.impala.service.CatalogOpExecutor.execDdlRequest(CatalogOpExecutor.java:454)
at
org.apache.impala.service.JniCatalog.lambda$execDdl$3(JniCatalog.java:302)
at
org.apache.impala.service.JniCatalog$$Lambda$63/770981675.call(Unknown Source)
at
org.apache.impala.service.JniCatalogOp.lambda$execAndSerialize$1(JniCatalogOp.java:90)
at
org.apache.impala.service.JniCatalogOp$$Lambda$59/837742726.call(Unknown Source)
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:231)
at
org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:245)
at
org.apache.impala.service.JniCatalog.execDdl(JniCatalog.java:301){noformat}
We need timeline item for external RPCs invoked in the constructor of
PartNameBasedDeltaUpdater and PartBasedDeltaUpdater.
was:
IMPALA-11535 introduces a performance regression when HMS event processing is
disabled, i.e. hms_event_polling_interval_s=0, in
[HdfsTable#loadPartitionsFromMetastore()|https://github.com/apache/impala/blob/eb79fbea2b452f09e0e04edc4be274942423d498/fe/src/main/java/org/apache/impala/catalog/HdfsTable.java#L1951].
It always fetch to latest event id to update the lastRefreshEventId of the
partitions. When HMS event processing is disabled, lastRefreshEventId won't be
used so no need to update it actually.
Here is an AlterPartition statement
{code:sql}
alter table tbl1 partition(p=0) set tblproperties('key'='myvalue'){code}
The catalog timeline in profile indicates fetch latest event id is the
bottleneck:
{noformat}
Catalog Server Operation: 4s794ms
- Got catalog version read lock: 168.861us (168.861us)
- Got catalog version write lock and table write lock: 312.483us
(143.622us)
- Got Metastore client: 258.655ms (258.342ms)
- Altered 1 partitions in Metastore: 677.772ms (419.117ms)
- Got Metastore client: 678.291ms (519.440us)
- Fetched table from Metastore: 909.802ms (231.510ms)
- Loaded all column stats: 986.145ms (76.343ms)
- Loaded table schema: 993.366ms (7.220ms)
- Got current Metastore event id 48196: 4s579ms (3s585ms) <---
Bottleneck
- Start loading file metadata: 4s579ms (51.936us)
- Loaded file metadata for 1 partitions: 4s582ms (3.417ms)
- Reloaded table metadata: 4s793ms (211.162ms)
- DDL finished: 4s794ms (187.654us){noformat}
> Missing timeline item in PartNameBasedDeltaUpdater
> --------------------------------------------------
>
> Key: IMPALA-14062
> URL: https://issues.apache.org/jira/browse/IMPALA-14062
> Project: IMPALA
> Issue Type: Bug
> Components: Catalog
> Reporter: Quanlong Huang
> Assignee: Quanlong Huang
> Priority: Major
>
> Here is an AlterPartition statement that runs several seconds:
> {code:sql}
> alter table tbl1 partition(p=0) set tblproperties('key'='myvalue'){code}
> The catalog timeline in profile indicates fetching latest event id is the
> bottleneck:
> {noformat}
> Catalog Server Operation: 4s794ms
> - Got catalog version read lock: 168.861us (168.861us)
> - Got catalog version write lock and table write lock: 312.483us
> (143.622us)
> - Got Metastore client: 258.655ms (258.342ms)
> - Altered 1 partitions in Metastore: 677.772ms (419.117ms)
> - Got Metastore client: 678.291ms (519.440us)
> - Fetched table from Metastore: 909.802ms (231.510ms)
> - Loaded all column stats: 986.145ms (76.343ms)
> - Loaded table schema: 993.366ms (7.220ms)
> - Got current Metastore event id 48196: 4s579ms (3s585ms) <---
> Bottleneck
> - Start loading file metadata: 4s579ms (51.936us)
> - Loaded file metadata for 1 partitions: 4s582ms (3.417ms)
> - Reloaded table metadata: 4s793ms (211.162ms)
> - DDL finished: 4s794ms (187.654us){noformat}
> However, the actual time is spent in fetching the partition list in the
> constructor of PartNameBasedDeltaUpdater, as shown in the jstack:
> {noformat}
> "Thread-38 [ALTER_TABLE scale_400k_500cols_db.tbl1 issued by
> [email protected]] [Reloading metadata for table definition and all
> partition(s) of scale_400k_500cols_db.tbl1 (ALTER TABLE SET_TBL_PROPERTIES)]"
> #177 prio=5 os_prio=0 tid=0x0000000015a26000 nid=0x2702 runnable
> [0x00007fc79e80b000]
> java.lang.Thread.State: RUNNABLE
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
> at java.net.SocketInputStream.read(SocketInputStream.java:171)
> at java.net.SocketInputStream.read(SocketInputStream.java:141)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
> at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
> - locked <0x00007fc801db9a38> (a java.io.BufferedInputStream)
> at
> org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:177)
> at org.apache.thrift.transport.TTransport.readAll(TTransport.java:109)
> at
> org.apache.thrift.transport.TSaslTransport.readLength(TSaslTransport.java:338)
> at
> org.apache.thrift.transport.TSaslTransport.readFrame(TSaslTransport.java:421)
> at
> org.apache.thrift.transport.TSaslTransport.read(TSaslTransport.java:397)
> at
> org.apache.thrift.transport.TSaslClientTransport.read(TSaslClientTransport.java:39)
> at org.apache.thrift.transport.TTransport.readAll(TTransport.java:109)
> at
> org.apache.hadoop.hive.metastore.security.TFilterTransport.readAll(TFilterTransport.java:63)
> at
> org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:464)
> at
> org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:362)
> at
> org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:245)
> at
> org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:77)
> at
> org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Client.recv_get_partition_names(ThriftHiveMetastore.java:3567)
> at
> org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Client.get_partition_names(ThriftHiveMetastore.java:3552)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.listPartitionNames(HiveMetaStoreClient.java:2550)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.listPartitionNames(HiveMetaStoreClient.java:2526)
> at sun.reflect.GeneratedMethodAccessor53.invoke(Unknown Source)
> 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:209)
> at com.sun.proxy.$Proxy31.listPartitionNames(Unknown Source)
> at
> org.apache.impala.catalog.HdfsTable$PartNameBasedDeltaUpdater.<init>(HdfsTable.java:1749)
> at
> org.apache.impala.catalog.HdfsTable.updatePartitionsFromHms(HdfsTable.java:1477)
> at org.apache.impala.catalog.HdfsTable.load(HdfsTable.java:1318)
> at
> org.apache.impala.service.CatalogOpExecutor.loadTableMetadata(CatalogOpExecutor.java:1623)
> at
> org.apache.impala.service.CatalogOpExecutor.loadTableMetadata(CatalogOpExecutor.java:1598)
> at
> org.apache.impala.service.CatalogOpExecutor.alterTable(CatalogOpExecutor.java:1315)
> at
> org.apache.impala.service.CatalogOpExecutor.execDdlRequest(CatalogOpExecutor.java:454)
> at
> org.apache.impala.service.JniCatalog.lambda$execDdl$3(JniCatalog.java:302)
> at
> org.apache.impala.service.JniCatalog$$Lambda$63/770981675.call(Unknown Source)
> at
> org.apache.impala.service.JniCatalogOp.lambda$execAndSerialize$1(JniCatalogOp.java:90)
> at
> org.apache.impala.service.JniCatalogOp$$Lambda$59/837742726.call(Unknown
> Source)
> 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:231)
> at
> org.apache.impala.service.JniCatalog.execAndSerialize(JniCatalog.java:245)
> at
> org.apache.impala.service.JniCatalog.execDdl(JniCatalog.java:301){noformat}
> We need timeline item for external RPCs invoked in the constructor of
> PartNameBasedDeltaUpdater and PartBasedDeltaUpdater.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
