[
https://issues.apache.org/jira/browse/HIVE-24320?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17222124#comment-17222124
]
Zoltan Haindrich commented on HIVE-24320:
-----------------------------------------
attached last 1000 lines of hive log and full jstack trace
there seems to be some derby issues prior to this state - not sure if those are
only caused by the issue or they are part of the root cause
issues seems to start with:
{code}
2020-10-28T01:24:33,767 WARN [Heartbeater-3] pool.ProxyConnection:
HikariPool-3 - Connection org.apache.derby.impl.jdbc.EmbedConnection@1913174287
(XID = null), (SESSIONID = 68), (DATABASE =
/home/jenkins/agent/workspace/internal-hive-precommit_PR-2/itests/qtest/target/tmp/junit_metastore_db),
(DRDAID = null) marked as broken because of SQLSTATE(08003), ErrorCode(40000)
java.sql.SQLNonTransientConnectionException: No current connection.
at
org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
~[derby-10.14.2.0.jar:?]
at
org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
~[derby-10.14.2.0.jar:?]
at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown
Source) ~[derby-10.14.2.0.jar:?]
at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown
Source) ~[derby-10.14.2.0.jar:?]
at org.apache.derby.impl.jdbc.Util.noCurrentConnection(Unknown Source)
~[derby-10.14.2.0.jar:?]
at org.apache.derby.impl.jdbc.EmbedConnection.checkIfClosed(Unknown
Source) ~[derby-10.14.2.0.jar:?]
at org.apache.derby.impl.jdbc.EmbedConnection.setupContextStack(Unknown
Source) ~[derby-10.14.2.0.jar:?]
at org.apache.derby.impl.jdbc.EmbedConnection.rollback(Unknown Source)
~[derby-10.14.2.0.jar:?]
at
com.zaxxer.hikari.pool.ProxyConnection.rollback(ProxyConnection.java:362)
~[HikariCP-2.6.1.jar:?]
at
com.zaxxer.hikari.pool.HikariProxyConnection.rollback(HikariProxyConnection.java)
~[HikariCP-2.6.1.jar:?]
at
org.apache.hadoop.hive.metastore.txn.TxnHandler.rollbackDBConn(TxnHandler.java:3787)
~[hive-standalone-metastore-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at
org.apache.hadoop.hive.metastore.txn.TxnHandler.heartbeat(TxnHandler.java:2912)
~[hive-standalone-metastore-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at
org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.heartbeat(HiveMetaStore.java:8440)
~[hive-standalone-metastore-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[?:1.8.0_262]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[?:1.8.0_262]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[?:1.8.0_262]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_262]
at
org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
~[hive-standalone-metastore-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at
org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108)
~[hive-standalone-metastore-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at com.sun.proxy.$Proxy58.heartbeat(Unknown Source) ~[?:?]
at
org.apache.hadoop.hive.metastore.HiveMetaStoreClient.heartbeat(HiveMetaStoreClient.java:3250)
~[hive-standalone-metastore-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[?:1.8.0_262]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[?:1.8.0_262]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[?:1.8.0_262]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_262]
at
org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:212)
~[hive-standalone-metastore-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at com.sun.proxy.$Proxy59.heartbeat(Unknown Source) ~[?:?]
at
org.apache.hadoop.hive.ql.lockmgr.DbTxnManager.heartbeat(DbTxnManager.java:665)
~[hive-exec-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at
org.apache.hadoop.hive.ql.lockmgr.DbTxnManager$Heartbeater.lambda$run$0(DbTxnManager.java:1085)
~[hive-exec-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at java.security.AccessController.doPrivileged(Native Method)
[?:1.8.0_262]
at javax.security.auth.Subject.doAs(Subject.java:422) [?:1.8.0_262]
at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1898)
[hadoop-common-3.1.1.7.2.3.0-212.jar:?]
at
org.apache.hadoop.hive.ql.lockmgr.DbTxnManager$Heartbeater.run(DbTxnManager.java:1084)
[hive-exec-3.1.3000.7.2.3.0-212.jar:3.1.3000.7.2.3.0-212]
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[?:1.8.0_262]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
[?:1.8.0_262]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
[?:1.8.0_262]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
[?:1.8.0_262]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[?:1.8.0_262]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[?:1.8.0_262]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_262]
Caused by: org.apache.derby.iapi.error.StandardException: No current connection.
at org.apache.derby.iapi.error.StandardException.newException(Unknown
Source) ~[derby-10.14.2.0.jar:?]
at
org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(Unknown
Source) ~[derby-10.14.2.0.jar:?]
... 40 more
2020-10-28T01:24:33,768 WARN [Heartbeater-3] txn.TxnHandler: Failed to
rollback db connection No current connection. (SQLState=08003, ErrorCode=40000)
2020-10-28T01:24:33,770 INFO [Heartbeater-3] txn.TxnHandler: Non-retryable
error in heartbeat(HeartbeatRequest(lockid:0, txnid:55)) : Derby thread
received an interrupt during a disk I/O operation, please check your
application for the source of the interrupt. (SQLState=XSDG9, ErrorCode=45000)
{code}
it's interesting to see the message "Derby thread received an interrupt during
a disk I/O operation, please check your application for the source of the
interrupt. (SQLState=XSDG9, ErrorCode=45000)"
> TestMiniLlapLocal sometimes hangs because of some derby issues
> --------------------------------------------------------------
>
> Key: HIVE-24320
> URL: https://issues.apache.org/jira/browse/HIVE-24320
> Project: Hive
> Issue Type: Bug
> Reporter: Zoltan Haindrich
> Assignee: Zoltan Haindrich
> Priority: Major
> Attachments: 3hr.hive.log, 3hr.jstack
>
>
> code in question is a slightly modified version of branch-3
> opening ticket to make notes about the investigation
> {code}
> "dcce5fec-2365-4697-8a8f-04a4dfa5d9f5 main" #1 prio=5 os_prio=0
> tid=0x00007fd7c000a800 nid=0x1de23 waiting on condition [0x00007fd7c4b70000]
> java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000000c61635f0> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitUninterruptibly(AbstractQueuedSynchronizer.java:1981)
> at
> org.apache.derby.impl.services.cache.CacheEntry.waitUntilIdentityIsSet(Unknown
> Source)
> at
> org.apache.derby.impl.services.cache.ConcurrentCache.getEntry(Unknown Source)
> at org.apache.derby.impl.services.cache.ConcurrentCache.find(Unknown
> Source)
> at
> org.apache.derby.impl.store.raw.data.BaseDataFileFactory.openContainer(Unknown
> Source)
> at
> org.apache.derby.impl.store.raw.data.BaseDataFileFactory.openContainer(Unknown
> Source)
> at org.apache.derby.impl.store.raw.xact.Xact.openContainer(Unknown
> Source)
> at
> org.apache.derby.impl.store.access.conglomerate.OpenConglomerate.init(Unknown
> Source)
> at org.apache.derby.impl.store.access.heap.Heap.open(Unknown Source)
> at
> org.apache.derby.impl.store.access.RAMTransaction.openConglomerate(Unknown
> Source)
> at
> org.apache.derby.impl.store.access.RAMTransaction.openConglomerate(Unknown
> Source)
> at
> org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getDescriptorViaIndexMinion(Unknown
> Source)
> at
> org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getDescriptorViaIndex(Unknown
> Source)
> at
> org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getSubKeyConstraint(Unknown
> Source)
> at
> org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getConstraintDescriptorViaIndex(Unknown
> Source)
> at
> org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getConstraintDescriptorsScan(Unknown
> Source)
> at
> org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getConstraintDescriptors(Unknown
> Source)
> - locked <0x00000000c615c9a8> (a
> org.apache.derby.iapi.sql.dictionary.ConstraintDescriptorList)
> at
> org.apache.derby.iapi.sql.dictionary.TableDescriptor.getAllRelevantConstraints(Unknown
> Source)
> at
> org.apache.derby.impl.sql.compile.DMLModStatementNode.getAllRelevantConstraints(Unknown
> Source)
> at
> org.apache.derby.impl.sql.compile.DMLModStatementNode.bindConstraints(Unknown
> Source)
> at org.apache.derby.impl.sql.compile.DeleteNode.bindStatement(Unknown
> Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown
> Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at
> org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepareInternalStatement(Unknown
> Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.execute(Unknown Source)
> - locked <0x00000000c4bb5fd0> (a
> org.apache.derby.impl.jdbc.EmbedConnection)
> at
> org.apache.derby.impl.jdbc.EmbedStatement.executeBatchElement(Unknown Source)
> at
> org.apache.derby.impl.jdbc.EmbedStatement.executeLargeBatch(Unknown Source)
> - locked <0x00000000c4bb5fd0> (a
> org.apache.derby.impl.jdbc.EmbedConnection)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeBatch(Unknown
> Source)
> at
> com.zaxxer.hikari.pool.ProxyStatement.executeBatch(ProxyStatement.java:125)
> at
> com.zaxxer.hikari.pool.HikariProxyStatement.executeBatch(HikariProxyStatement.java)
> at
> org.apache.hadoop.hive.metastore.txn.TxnDbUtil.executeQueriesInBatch(TxnDbUtil.java:658)
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.updateCommitIdAndCleanUpMetadata(TxnHandler.java:1338)
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.commitTxn(TxnHandler.java:1236)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.commit_txn(HiveMetaStore.java:8315)
> at sun.reflect.GeneratedMethodAccessor252.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.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108)
> at com.sun.proxy.$Proxy58.commit_txn(Unknown Source)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.commitTxn(HiveMetaStoreClient.java:3127)
> at sun.reflect.GeneratedMethodAccessor251.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:212)
> at com.sun.proxy.$Proxy59.commitTxn(Unknown Source)
> at
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager.commitTxn(DbTxnManager.java:553)
> at
> org.apache.hadoop.hive.ql.Driver.releaseLocksAndCommitOrRollback(Driver.java:448)
> at
> org.apache.hadoop.hive.ql.Driver.releaseLocksAndCommitOrRollback(Driver.java:412)
> at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:741)
> at org.apache.hadoop.hive.ql.Driver.run(Driver.java:490)
> {code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
