Details
-
Improvement
-
Status: Closed
-
Major
-
Resolution: Fixed
-
4.0.0-beta-1
Description
When DeadlineException occurs, the call should be terminated immediately instead of falling back to jdo query, because some jdo query does not take use of Deadline.checkTimeout().
How to Reproduce:
Step 1: start a metastore server with metastore config:
<!-- hivemetastore-site.xml --> <property> <name>hive.metastore.client.socket.timeout</name> <value>60s</value> </property>
Step 2: Create a table with large partitions
Step 3: set hive client socket timeout same as server, and call drop_table to drop this table
conf.set("hive.metastore.client.socket.timeout", "60s");
conf.set("hive.metastore.failure.retries", "0");
The direct sql query would throw DeadlineException while dropping partitions in batch, but it would fall back to jdo query to drop partitions for each batch, we can find clues from the server log:
2024-01-26T08:52:14,877 INFO [Metastore-Handler-Pool: Thread-54]: HiveMetaStore.audit (HMSHandler.java:logAuditEvent(207)) - ugi=root ip=10.89.0.1 cmd=source:10.89.0.1 get_all_functions 2024-01-26T08:52:14,879 INFO [Metastore-Handler-Pool: Thread-54]: metastore.HMSHandler (HMSHandler.java:newRawStoreForConf(600)) - Opening raw store with implementation class: org.apache.hadoop.hive.metastore.ObjectStore 2024-01-26T08:52:14,879 INFO [Metastore-Handler-Pool: Thread-54]: metastore.PersistenceManagerProvider (PersistenceManagerProvider.java:correctAutoStartMechanism(577)) - Configuration datanucleus.autoStartMechanismMode is not set . Defaulting to 'ignored' 2024-01-26T08:52:14,879 INFO [Metastore-Handler-Pool: Thread-54]: metastore.ObjectStore (ObjectStore.java:shutdown(568)) - RawStore: org.apache.hadoop.hive.metastore.ObjectStore@53c9fbcd, with PersistenceManager: null will be shu tdown 2024-01-26T08:52:14,881 INFO [Metastore-Handler-Pool: Thread-54]: metastore.ObjectStore (ObjectStore.java:initialize(430)) - RawStore: org.apache.hadoop.hive.metastore.ObjectStore@53c9fbcd, with PersistenceManager: org.datanucleu s.api.jdo.JDOPersistenceManager@586cd877 created in the thread with id: 54 2024-01-26T08:52:14,890 INFO [Metastore-Handler-Pool: Thread-54]: metastore.HMSHandler (HMSHandler.java:getMSForConf(587)) - Created RawStore: org.apache.hadoop.hive.metastore.ObjectStore@53c9fbcd 2024-01-26T08:52:14,913 INFO [Metastore-Handler-Pool: Thread-54]: HiveMetaStore.audit (HMSHandler.java:logAuditEvent(207)) - ugi=root ip=10.89.0.1 cmd=source:10.89.0.1 get_table : tbl=hive.default.test_tbl 2024-01-26T08:52:15,069 INFO [Metastore-Handler-Pool: Thread-54]: metastore.HMSHandler (HMSHandler.java:getTableInternal(3582)) - Skipping translation for processor with null 2024-01-26T08:52:15,094 INFO [Metastore-Handler-Pool: Thread-54]: HiveMetaStore.audit (HMSHandler.java:logAuditEvent(207)) - ugi=root ip=10.89.0.1 cmd=source:10.89.0.1 drop_table : tbl=hive.default.test_tbl 2024-01-26T08:52:54,593 INFO [Metastore Scheduled Worker 1]: metastore.HMSHandler (HMSHandler.java:newRawStoreForConf(600)) - Opening raw store with implementation class: org.apache.hadoop.hive.metastore.ObjectStore 2024-01-26T08:52:54,594 INFO [Metastore Scheduled Worker 1]: metastore.PersistenceManagerProvider (PersistenceManagerProvider.java:correctAutoStartMechanism(577)) - Configuration datanucleus.autoStartMechanismMode is not set. Def aulting to 'ignored' 2024-01-26T08:52:54,594 INFO [Metastore Scheduled Worker 1]: metastore.ObjectStore (ObjectStore.java:shutdown(568)) - RawStore: org.apache.hadoop.hive.metastore.ObjectStore@63e26ab7, with PersistenceManager: null will be shutdown 2024-01-26T08:52:54,595 INFO [Metastore Scheduled Worker 1]: metastore.ObjectStore (ObjectStore.java:initialize(430)) - RawStore: org.apache.hadoop.hive.metastore.ObjectStore@63e26ab7, with PersistenceManager: org.datanucleus.api .jdo.JDOPersistenceManager@19d73712 created in the thread with id: 48 2024-01-26T08:52:54,601 INFO [Metastore Scheduled Worker 1]: metastore.HMSHandler (HMSHandler.java:getMSForConf(587)) - Created RawStore: org.apache.hadoop.hive.metastore.ObjectStore@63e26ab7 2024-01-26T08:53:15,125 WARN [Metastore-Handler-Pool: Thread-54]: metastore.ObjectStore (ObjectStore.java:handleDirectSqlError(4455)) - Falling back to ORM path due to direct SQL failure (this is not an error): Timeout when execu ting method: drop_table_with_environment_context; 60021ms exceeds 60000ms at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils.newMetaException(MetaStoreUtils.java:218) at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils. newMetaException(MetaStoreUtils.java:208) at org.apache.hadoop.hive.metastore.Deadline.check(Deadline.java:169) at org.apache.hadoop.hive.metastore.Deadline.checkTimeout(Deadline.java:148) at org.apache.hadoop.hive.metastore.MetaS toreDirectSql.dropPartitionsByPartitionIds(MetaStoreDirectSql.java:2857) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.access$1900(MetaStoreDirectSql.java:136) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql$10.run (MetaStoreDirectSql.java:2780) at org.apache.hadoop.hive.metastore.Batchable.runBatched(Batchable.java:79) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.dropPartitionsViaSqlFilter(MetaStoreDirectSql.java:2770) at org.apac he.hadoop.hive.metastore.ObjectStore$7.getSqlResult(ObjectStore.java:3146); Caused by: Timeout when executing method: drop_table_with_environment_context; 60021ms exceeds 60000ms at org.apache.hadoop.hive.metastore.Deadline.check(Deadline.java:165) 2024-01-26T08:53:22,011 WARN [Metastore-Handler-Pool: Thread-54]: metastore.ObjectStore (ObjectStore.java:handleDirectSqlError(4455)) - Falling back to ORM path due to direct SQL failure (this is not an error): Timeout when execu ting method: drop_table_with_environment_context; 66916ms exceeds 60000ms at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils.newMetaException(MetaStoreUtils.java:218) at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils. newMetaException(MetaStoreUtils.java:208) at org.apache.hadoop.hive.metastore.Deadline.check(Deadline.java:169) at org.apache.hadoop.hive.metastore.Deadline.checkTimeout(Deadline.java:148) at org.apache.hadoop.hive.metastore.MetaS toreDirectSql.dropPartitionsByPartitionIds(MetaStoreDirectSql.java:2830) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.access$1900(MetaStoreDirectSql.java:136) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql$10.run (MetaStoreDirectSql.java:2780) at org.apache.hadoop.hive.metastore.Batchable.runBatched(Batchable.java:79) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.dropPartitionsViaSqlFilter(MetaStoreDirectSql.java:2770) at org.apac he.hadoop.hive.metastore.ObjectStore$7.getSqlResult(ObjectStore.java:3146); Caused by: Timeout when executing method: drop_table_with_environment_context; 66916ms exceeds 60000ms at org.apache.hadoop.hive.metastore.Deadline.check(Deadline.java:165) 2024-01-26T08:53:28,238 WARN [Metastore-Handler-Pool: Thread-54]: metastore.ObjectStore (ObjectStore.java:handleDirectSqlError(4455)) - Falling back to ORM path due to direct SQL failure (this is not an error): Timeout when execu ting method: drop_table_with_environment_context; 73143ms exceeds 60000ms at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils.newMetaException(MetaStoreUtils.java:218) at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils. newMetaException(MetaStoreUtils.java:208) at org.apache.hadoop.hive.metastore.Deadline.check(Deadline.java:169) at org.apache.hadoop.hive.metastore.Deadline.checkTimeout(Deadline.java:148) at org.apache.hadoop.hive.metastore.MetaS toreDirectSql.dropPartitionsByPartitionIds(MetaStoreDirectSql.java:2830) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.access$1900(MetaStoreDirectSql.java:136) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql$10.run (MetaStoreDirectSql.java:2780) at org.apache.hadoop.hive.metastore.Batchable.runBatched(Batchable.java:79) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.dropPartitionsViaSqlFilter(MetaStoreDirectSql.java:2770) at org.apac he.hadoop.hive.metastore.ObjectStore$7.getSqlResult(ObjectStore.java:3146); Caused by: Timeout when executing method: drop_table_with_environment_context; 73143ms exceeds 60000ms at org.apache.hadoop.hive.metastore.Deadline.check(Deadline.java:165) 2024-01-26T08:53:34,714 WARN [Metastore-Handler-Pool: Thread-54]: metastore.ObjectStore (ObjectStore.java:handleDirectSqlError(4455)) - Falling back to ORM path due to direct SQL failure (this is not an error): Timeout when executing method: drop_table_with_environment_context; 79619ms exceeds 60000ms at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils.newMetaException(MetaStoreUtils.java:218) at org.apache.hadoop.hive.metastore.utils.MetaStoreUtils.newMetaException(MetaStoreUtils.java:208) at org.apache.hadoop.hive.metastore.Deadline.check(Deadline.java:169) at org.apache.hadoop.hive.metastore.Deadline.checkTimeout(Deadline.java:148) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.dropPartitionsByPartitionIds(MetaStoreDirectSql.java:2830) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.access$1900(MetaStoreDirectSql.java:136) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql$10.run(MetaStoreDirectSql.java:2780) at org.apache.hadoop.hive.metastore.Batchable.runBatched(Batchable.java:79) at org.apache.hadoop.hive.metastore.MetaStoreDirectSql.dropPartitionsViaSqlFilter(MetaStoreDirectSql.java:2770) at org.apache.hadoop.hive.metastore.ObjectStore$7.getSqlResult(ObjectStore.java:3146);
Attachments
Issue Links
- links to