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