[
https://issues.apache.org/jira/browse/HIVE-25522?focusedWorklogId=658735&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-658735
]
ASF GitHub Bot logged work on HIVE-25522:
-----------------------------------------
Author: ASF GitHub Bot
Created on: 01/Oct/21 05:27
Start Date: 01/Oct/21 05:27
Worklog Time Spent: 10m
Work Description: szehon-ho edited a comment on pull request #2647:
URL: https://github.com/apache/hive/pull/2647#issuecomment-931909748
Hi guys sorry for delay, I took a little look at it. Seems like test fail
because in test environment TxnHandler is initialized more than once but not
tearing down when shutdown (seems JVM is recycled). So everytime it makes more
connection to database and eventually gets exhausted. Maybe I should just call
TxnUtils.getTxnStore()
Actually found something else, in current version of Hive it is now on
critical path of startup, since AcidMetricService is added to list of services
in https://issues.apache.org/jira/browse/HIVE-24824:
```
setConf:369, TxnHandler (org.apache.hadoop.hive.metastore.txn)
getTxnStore:124, TxnUtils (org.apache.hadoop.hive.metastore.txn)
setConf:314, AcidMetricService (org.apache.hadoop.hive.metastore.metrics)
startAlwaysTaskThreads:525, HMSHandler (org.apache.hadoop.hive.metastore)
init:493, HMSHandler (org.apache.hadoop.hive.metastore)
invoke0:-1, NativeMethodAccessorImpl (sun.reflect)
invoke:62, NativeMethodAccessorImpl (sun.reflect)
invoke:43, DelegatingMethodAccessorImpl (sun.reflect)
invoke:498, Method (java.lang.reflect)
invokeInternal:147, RetryingHMSHandler (org.apache.hadoop.hive.metastore)
invoke:108, RetryingHMSHandler (org.apache.hadoop.hive.metastore)
<init>:80, RetryingHMSHandler (org.apache.hadoop.hive.metastore)
getProxy:93, RetryingHMSHandler (org.apache.hadoop.hive.metastore)
newRetryingHMSHandler:133, HiveMetaStore (org.apache.hadoop.hive.metastore)
invoke0:-1, NativeMethodAccessorImpl (sun.reflect)
invoke:62, NativeMethodAccessorImpl (sun.reflect)
invoke:43, DelegatingMethodAccessorImpl (sun.reflect)
invoke:498, Method (java.lang.reflect)
callEmbeddedMetastore:291, HiveMetaStoreClient
(org.apache.hadoop.hive.metastore)
<init>:205, HiveMetaStoreClient (org.apache.hadoop.hive.metastore)
<init>:113, HiveMetaStoreClientWithLocalCache
(org.apache.hadoop.hive.metastore)
<init>:155, SessionHiveMetaStoreClient (org.apache.hadoop.hive.ql.metadata)
newInstance0:-1, NativeConstructorAccessorImpl (sun.reflect)
newInstance:62, NativeConstructorAccessorImpl (sun.reflect)
newInstance:45, DelegatingConstructorAccessorImpl (sun.reflect)
newInstance:423, Constructor (java.lang.reflect)
newInstance:84, JavaUtils (org.apache.hadoop.hive.metastore.utils)
<init>:101, RetryingMetaStoreClient (org.apache.hadoop.hive.metastore)
getProxy:154, RetryingMetaStoreClient (org.apache.hadoop.hive.metastore)
getProxy:125, RetryingMetaStoreClient (org.apache.hadoop.hive.metastore)
createMetaStoreClient:5444, Hive (org.apache.hadoop.hive.ql.metadata)
getMSC:5522, Hive (org.apache.hadoop.hive.ql.metadata)
getMSC:5502, Hive (org.apache.hadoop.hive.ql.metadata)
getAllFunctions:5810, Hive (org.apache.hadoop.hive.ql.metadata)
reloadFunctions:337, Hive (org.apache.hadoop.hive.ql.metadata)
registerAllFunctionsOnce:316, Hive (org.apache.hadoop.hive.ql.metadata)
<init>:542, Hive (org.apache.hadoop.hive.ql.metadata)
create:434, Hive (org.apache.hadoop.hive.ql.metadata)
getInternal:421, Hive (org.apache.hadoop.hive.ql.metadata)
get:377, Hive (org.apache.hadoop.hive.ql.metadata)
createHiveDB:291, BaseSemanticAnalyzer (org.apache.hadoop.hive.ql.parse)
<init>:269, BaseSemanticAnalyzer (org.apache.hadoop.hive.ql.parse)
<init>:473, SemanticAnalyzer (org.apache.hadoop.hive.ql.parse)
postInit:630, QTestUtil (org.apache.hadoop.hive.ql)
evaluate:88, CliAdapter$1$1 (org.apache.hadoop.hive.cli.control)
evaluate:20, RunRules (org.junit.rules)
evaluate:306, ParentRunner$3 (org.junit.runners)
run:413, ParentRunner (org.junit.runners)
execute:365, JUnit4Provider (org.apache.maven.surefire.junit4)
executeWithRerun:273, JUnit4Provider (org.apache.maven.surefire.junit4)
executeTestSet:238, JUnit4Provider (org.apache.maven.surefire.junit4)
invoke:159, JUnit4Provider (org.apache.maven.surefire.junit4)
runSuitesInProcess:377, ForkedBooter (org.apache.maven.surefire.booter)
execute:138, ForkedBooter (org.apache.maven.surefire.booter)
run:465, ForkedBooter (org.apache.maven.surefire.booter)
main:451, ForkedBooter (org.apache.maven.surefire.booter)
```
So seems it's a Hive 3 only bug?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: gitbox-unsubscr...@hive.apache.org
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
Issue Time Tracking
-------------------
Worklog Id: (was: 658735)
Time Spent: 5.5h (was: 5h 20m)
> NullPointerException in TxnHandler
> ----------------------------------
>
> Key: HIVE-25522
> URL: https://issues.apache.org/jira/browse/HIVE-25522
> Project: Hive
> Issue Type: Improvement
> Components: Standalone Metastore
> Affects Versions: 3.1.2, 4.0.0
> Reporter: Szehon Ho
> Assignee: Szehon Ho
> Priority: Major
> Labels: pull-request-available
> Time Spent: 5.5h
> Remaining Estimate: 0h
>
> Environment: Using Iceberg on Hive 3.1.2 standalone metastore. Iceberg
> issues a lot of lock() calls for commits.
> We hit randomly a strange NPE that fails Iceberg commits.
> {noformat}
> 2021-08-21T11:08:05,665 ERROR [pool-6-thread-195]
> metastore.RetryingHMSHandler: java.lang.NullPointerException
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.enqueueLockWithRetry(TxnHandler.java:1903)
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.lock(TxnHandler.java:1827)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.lock(HiveMetaStore.java:7217)
> at jdk.internal.reflect.GeneratedMethodAccessor52.invoke(Unknown Source)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108)
> at com.sun.proxy.$Proxy27.lock(Unknown Source)
> at
> org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$lock.getResult(ThriftHiveMetastore.java:18111)
> at
> org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$lock.getResult(ThriftHiveMetastore.java:18095)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at
> org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:111)
> at
> org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:107)
> at java.base/java.security.AccessController.doPrivileged(Native Method)
> at java.base/javax.security.auth.Subject.doAs(Subject.java:423)
> at
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1729)
> at
> org.apache.hadoop.hive.metastore.TUGIBasedProcessor.process(TUGIBasedProcessor.java:119)
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at java.base/java.lang.Thread.run(Thread.java:834)
> 2021-08-21T11:08:05,665 ERROR [pool-6-thread-195] server.TThreadPoolServer:
> Error occurred during processing of message.
> java.lang.NullPointerException: null
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.enqueueLockWithRetry(TxnHandler.java:1903)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.lock(TxnHandler.java:1827)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.lock(HiveMetaStore.java:7217)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at jdk.internal.reflect.GeneratedMethodAccessor52.invoke(Unknown
> Source) ~[?:?]
> at
> jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> ~[?:?]
> at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at com.sun.proxy.$Proxy27.lock(Unknown Source) ~[?:?]
> at
> org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$lock.getResult(ThriftHiveMetastore.java:18111)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at
> org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$lock.getResult(ThriftHiveMetastore.java:18095)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at
> org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:111)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at
> org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:107)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
> at javax.security.auth.Subject.doAs(Subject.java:423) ~[?:?]
> at
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1729)
> ~[hadoop-common-3.1.4.jar:?]
> at
> org.apache.hadoop.hive.metastore.TUGIBasedProcessor.process(TUGIBasedProcessor.java:119)
> ~[hive-exec-3.1.2.jar:3.1.2]
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> [hive-exec-3.1.2.jar:3.1.2]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> [?:?]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> [?:?]
> at java.lang.Thread.run(Thread.java:834) [?:?]
> {noformat}
> It seems it's this line, though root cause is not deterined.
> https://github.com/apache/hive/blob/rel/release-3.1.2/standalone-metastore/src/main/java/org/apache/hadoop/hive/metastore/txn/TxnHandler.java#L1903
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
