[HIVE-15377] Driver::acquireWriteIds can be expensive trying to get details from MS

• Type: Sub-task
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: hive-14535
• Fix Version/s: hive-14535
• Assignee: Wei Zheng
• Reporter: Rajesh Balamohan
• Created: 07/Dec/16 01:17
• Updated: 22/May/17 18:10
• Resolved: 22/May/17 18:01

Description

Branch: hive-14535

Populated data in tpc-ds web_returns table. Select queries take longer time trying to acquire writeIds from MS.

hive> select * from web_returns_hive_commit limit 10;
select * from web_returns_hive_commit limit 10
...
....
Time taken: 52.494 seconds, Fetched: 10 row(s)

Without commit feature, same query would execute in ~6 seconds.

Attaching the stacktrace for reference:

at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:152)
	at java.net.SocketInputStream.read(SocketInputStream.java:122)
	at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)
	at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)
	at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:70)
	at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:283)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1799)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:200)
	- locked <0x0000000223192988> (a org.postgresql.core.v3.QueryExecutorImpl)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:424)
	at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:161)
	at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:114)
	at com.jolbox.bonecp.PreparedStatementHandle.executeQuery(PreparedStatementHandle.java:174)
	at org.datanucleus.store.rdbms.ParamLoggingPreparedStatement.executeQuery(ParamLoggingPreparedStatement.java:375)
	at org.datanucleus.store.rdbms.SQLController.executeStatementQuery(SQLController.java:552)
	at org.datanucleus.store.rdbms.scostore.ElementContainerStore.getSize(ElementContainerStore.java:660)
	at org.datanucleus.store.rdbms.scostore.ElementContainerStore.size(ElementContainerStore.java:606)
	at org.datanucleus.store.types.wrappers.backed.List.size(List.java:542)
	- locked <0x000000078e8b4f60> (a org.datanucleus.store.types.wrappers.backed.List)
	at org.apache.hadoop.hive.metastore.ObjectStore.convertToOrders(ObjectStore.java:1665)
	at org.apache.hadoop.hive.metastore.ObjectStore.convertToStorageDescriptor(ObjectStore.java:1710)
	at org.apache.hadoop.hive.metastore.ObjectStore.convertToStorageDescriptor(ObjectStore.java:1725)
	at org.apache.hadoop.hive.metastore.ObjectStore.convertToTable(ObjectStore.java:1578)
	at org.apache.hadoop.hive.metastore.ObjectStore.getTable(ObjectStore.java:1274)
	at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:101)
	at com.sun.proxy.$Proxy47.getTable(Unknown Source)
	at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.get_valid_write_ids(HiveMetaStore.java:6874)
	at sun.reflect.GeneratedMethodAccessor82.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:140)
	at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:99)
	at com.sun.proxy.$Proxy50.get_valid_write_ids(Unknown Source)
	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.getValidWriteIds(HiveMetaStoreClient.java:2480)
	at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:162)
	at com.sun.proxy.$Proxy51.getValidWriteIds(Unknown Source)
	at org.apache.hadoop.hive.ql.metadata.Hive.getValidWriteIdsForTable(Hive.java:4173)
	at org.apache.hadoop.hive.ql.Driver.acquireWriteIds(Driver.java:1592)
	at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1517)
	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1226)
	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1216)
	at org.apache.hadoop.hive.cli.CliDriver.processLocalCmd(CliDriver.java:233)
	at org.apache.hadoop.hive.cli.CliDriver.processCmd(CliDriver.java:184)
	at org.apache.hadoop.hive.cli.CliDriver.processLine(CliDriver.java:400)
	at org.apache.hadoop.hive.cli.CliDriver.executeDriver(CliDriver.java:777)
	at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:715)
	at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:642)