[HIVE-28038] Disable fallback to jdo for DeadlineException

• Type: Improvement
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 4.0.0-beta-1
• Fix Version/s: 4.0.0
• Component/s: Hive
• Labels: pull-request-available
• Assignee: Wechar
• Reporter: Wechar
• Created: 26/Jan/24 08:55
• Updated: 29/Mar/24 17:49
• Resolved: 05/Feb/24 07:34

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);
 

Issue Links

• links to: GitHub Pull Request #5040