[ 
https://issues.apache.org/jira/browse/HIVE-20753?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16652021#comment-16652021
 ] 

Eugene Koifman commented on HIVE-20753:
---------------------------------------

derby can't handle concurrent threads.   In the past I've mostly seen it get 
wedged.
The hearbeater thread is normally started automatically by the client 
(DbTxnManager) to let the system know the txn is alive.
By default, the txn timeout is 5min and the 1st hearbeat for a given query 
should happen after 2.5 minutes.
So if your query is running longer than that (which is unusual in UTs), it's 
possible that the heartbeater is the 2nd thread...

> Derby thread interrupt during ptest
> -----------------------------------
>
>                 Key: HIVE-20753
>                 URL: https://issues.apache.org/jira/browse/HIVE-20753
>             Project: Hive
>          Issue Type: Bug
>            Reporter: Zoltan Haindrich
>            Priority: Major
>         Attachments: derby.log
>
>
> I've had another failed ptest execution....it seems like derby have caught an 
> unexpected interrupt call ; which have hanged the execution; after that 
> nothing happend for about half an hour - after which batch timeout have 
> happened...
> {code}
> Caused by: ERROR XSDG9: Derby thread received an interrupt during a disk I/O 
> operation, please check your application for the source of the interrupt.
>       at org.apache.derby.iapi.error.StandardException.newException(Unknown 
> Source)
>       at 
> org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(Unknown
>  Source)
>       ... 42 more
> {code}
> full stacktrack:
> {code}
> 2018-10-16T06:47:29,355 ERROR [Heartbeater-3] lockmgr.DbTxnManager: Failed 
> trying to heartbeat queryId=null, currentUser: hiveptest (auth:SIMPLE): null
> java.lang.reflect.UndeclaredThrowableException: null
>       at 
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1700)
>  ~[hadoop-common-3.1.0.jar:?]
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager$Heartbeater.run(DbTxnManager.java:955)
>  [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at 
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) 
> [?:1.8.0_102]
>       at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) 
> [?:1.8.0_102]
>       at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
>  [?:1.8.0_102]
>       at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
>  [?:1.8.0_102]
>       at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>  [?:1.8.0_102]
>       at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>  [?:1.8.0_102]
>       at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
> Caused by: org.apache.hadoop.hive.ql.lockmgr.LockException: Error 
> communicating with the metastore(txnid:15,lockid:0 queryId=null txnid:0)
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager.heartbeat(DbTxnManager.java:590)
>  ~[hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager$Heartbeater.lambda$run$0(DbTxnManager.java:956)
>  ~[hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at java.security.AccessController.doPrivileged(Native Method) 
> ~[?:1.8.0_102]
>       at javax.security.auth.Subject.doAs(Subject.java:422) ~[?:1.8.0_102]
>       at 
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1682)
>  ~[hadoop-common-3.1.0.jar:?]
>       ... 8 more
> Caused by: org.apache.hadoop.hive.metastore.api.MetaException: Unable to 
> select from transaction database java.sql.SQLException: Derby thread received 
> an interrupt during a disk I/O operation, please check your application for 
> the source of the interrupt.
>       at 
> org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
>       at 
> org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
>       at org.apache.derby.impl.jdbc.Util.seeNextException(Unknown Source)
>       at 
> org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown 
> Source)
>       at 
> org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown 
> Source)
>       at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown 
> Source)
>       at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown 
> Source)
>       at org.apache.derby.impl.jdbc.EmbedStatement.execute(Unknown Source)
>       at org.apache.derby.impl.jdbc.EmbedStatement.executeLargeUpdate(Unknown 
> Source)
>       at org.apache.derby.impl.jdbc.EmbedStatement.executeUpdate(Unknown 
> Source)
>       at 
> com.zaxxer.hikari.pool.ProxyStatement.executeUpdate(ProxyStatement.java:117)
>       at 
> com.zaxxer.hikari.pool.HikariProxyStatement.executeUpdate(HikariProxyStatement.java)
>       at 
> org.apache.hadoop.hive.metastore.txn.TxnHandler.heartbeatTxn(TxnHandler.java:4405)
>       at 
> org.apache.hadoop.hive.metastore.txn.TxnHandler.heartbeat(TxnHandler.java:2659)
>       at 
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.heartbeat(HiveMetaStore.java:7430)
>       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>       at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>       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.$Proxy128.heartbeat(Unknown Source)
>       at 
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.heartbeat(HiveMetaStoreClient.java:2953)
>       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>       at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>       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.$Proxy129.heartbeat(Unknown Source)
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager.heartbeat(DbTxnManager.java:576)
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager$Heartbeater.lambda$run$0(DbTxnManager.java:956)
>       at java.security.AccessController.doPrivileged(Native Method)
>       at javax.security.auth.Subject.doAs(Subject.java:422)
>       at 
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1682)
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager$Heartbeater.run(DbTxnManager.java:955)
>       at 
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>       at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
>       at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
>       at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
>       at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>       at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>       at java.lang.Thread.run(Thread.java:745)
> Caused by: ERROR XSDG9: Derby thread received an interrupt during a disk I/O 
> operation, please check your application for the source of the interrupt.
>       at org.apache.derby.iapi.error.StandardException.newException(Unknown 
> Source)
>       at 
> org.apache.derby.impl.jdbc.SQLExceptionFactory.wrapArgsForTransportAcrossDRDA(Unknown
>  Source)
>       ... 42 more
> Caused by: ERROR intrp: intrp.U
>       at 
> org.apache.derby.impl.store.raw.data.RAFContainer4.awaitRestoreChannel(Unknown
>  Source)
>       at 
> org.apache.derby.impl.store.raw.data.RAFContainer4.handleClosedChannel(Unknown
>  Source)
>       at org.apache.derby.impl.store.raw.data.RAFContainer4.readPage(Unknown 
> Source)
>       at 
> org.apache.derby.impl.store.raw.data.RAFContainer4.getEmbryonicPage(Unknown 
> Source)
>       at 
> org.apache.derby.impl.store.raw.data.RAFContainer.writeRAFHeader(Unknown 
> Source)
>       at org.apache.derby.impl.store.raw.data.RAFContainer.clean(Unknown 
> Source)
>       at 
> org.apache.derby.impl.services.cache.ConcurrentCache.cleanAndUnkeepEntry(Unknown
>  Source)
>       at org.apache.derby.impl.services.cache.ClockPolicy.rotateClock(Unknown 
> Source)
>       at org.apache.derby.impl.services.cache.ClockPolicy.insertEntry(Unknown 
> Source)
>       at 
> org.apache.derby.impl.services.cache.ConcurrentCache.insertIntoFreeSlot(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.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)
>       at 
> org.apache.derby.iapi.sql.dictionary.TableDescriptor.getAllRelevantConstraints(Unknown
>  Source)
>       at 
> org.apache.derby.impl.sql.compile.UpdateNode.getUpdateReadMap(Unknown Source)
>       at org.apache.derby.impl.sql.compile.UpdateNode.getReadMap(Unknown 
> Source)
>       at org.apache.derby.impl.sql.compile.UpdateNode.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)
>       ... 35 more
>       at 
> org.apache.hadoop.hive.metastore.txn.TxnHandler.heartbeat(TxnHandler.java:2665)
>  ~[hive-standalone-metastore-server-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at 
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.heartbeat(HiveMetaStore.java:7430)
>  ~[hive-standalone-metastore-server-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 
> ~[?:1.8.0_102]
>       at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) 
> ~[?:1.8.0_102]
>       at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>  ~[?:1.8.0_102]
>       at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_102]
>       at 
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
>  ~[hive-standalone-metastore-server-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at 
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:108)
>  ~[hive-standalone-metastore-server-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at com.sun.proxy.$Proxy128.heartbeat(Unknown Source) ~[?:?]
>       at 
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.heartbeat(HiveMetaStoreClient.java:2953)
>  ~[hive-standalone-metastore-common-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 
> ~[?:1.8.0_102]
>       at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) 
> ~[?:1.8.0_102]
>       at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>  ~[?:1.8.0_102]
>       at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_102]
>       at 
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:212)
>  ~[hive-standalone-metastore-common-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at com.sun.proxy.$Proxy129.heartbeat(Unknown Source) ~[?:?]
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager.heartbeat(DbTxnManager.java:576)
>  ~[hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at 
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager$Heartbeater.lambda$run$0(DbTxnManager.java:956)
>  ~[hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
>       at java.security.AccessController.doPrivileged(Native Method) 
> ~[?:1.8.0_102]
>       at javax.security.auth.Subject.doAs(Subject.java:422) ~[?:1.8.0_102]
>       at 
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1682)
>  ~[hadoop-common-3.1.0.jar:?]
>       ... 8 more
> {code}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to