You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hive.apache.org by "Sushanth Sowmyan (JIRA)" <ji...@apache.org> on 2016/05/27 17:43:12 UTC

[jira] [Updated] (HIVE-13869) ObjectStore synchronization issue manifested in db notification listener

     [ https://issues.apache.org/jira/browse/HIVE-13869?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Sushanth Sowmyan updated HIVE-13869:
------------------------------------
    Fix Version/s:     (was: 1.2.2)

> ObjectStore synchronization issue manifested in db notification listener
> ------------------------------------------------------------------------
>
>                 Key: HIVE-13869
>                 URL: https://issues.apache.org/jira/browse/HIVE-13869
>             Project: Hive
>          Issue Type: Bug
>          Components: HCatalog
>    Affects Versions: 1.1.1
>            Reporter: Nachiket Vaidya
>
> I used pyhs2 python client to create tables/partitions in hive. I was working fine until I moved to multithreaded scripts which created 8 connections and ran DDL queries concurrently.
> I got the error as
> {noformat}
> 2016-05-04 17:49:26,226 ERROR org.apache.hadoop.hive.metastore.RetryingHMSHandler: [pool-4-thread-194]: HMSHandler Fatal error: Invalid state. Transaction has already started
> org.datanucleus.transaction.NucleusTransactionException: Invalid state. Transaction has already started
>         at org.datanucleus.transaction.TransactionManager.begin(TransactionManager.java:47)
>         at org.datanucleus.TransactionImpl.begin(TransactionImpl.java:131)
>         at org.datanucleus.api.jdo.JDOTransaction.internalBegin(JDOTransaction.java:88)
>         at org.datanucleus.api.jdo.JDOTransaction.begin(JDOTransaction.java:80)
>         at org.apache.hadoop.hive.metastore.ObjectStore.openTransaction(ObjectStore.java:463)
>         at org.apache.hadoop.hive.metastore.ObjectStore.addNotificationEvent(ObjectStore.java:7522)
>         at sun.reflect.GeneratedMethodAccessor20.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:114)
>         at com.sun.proxy.$Proxy10.addNotificationEvent(Unknown Source)
>         at org.apache.hive.hcatalog.listener.DbNotificationListener.enqueue(DbNotificationListener.java:261)
>         at org.apache.hive.hcatalog.listener.DbNotificationListener.onCreateTable(DbNotificationListener.java:123)
>         at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_table_core(HiveMetaStore.java:1483)
>         at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_table_with_environment_context(HiveMetaStore.java:1502)
>         at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:138)
>         at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:99)
>         at com.sun.proxy.$Proxy14.create_table_with_environment_context(Unknown Source)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_table_with_environment_context.getResult(ThriftHiveMetastore.java:9267)
> {noformat}
> At one point, I got another stack trace as
> {noformat}
> 2016-05-26 12:32:27,904 ERROR org.apache.hadoop.hive.metastore.RetryingHMSHandler: [pool-4-thread-7]: MetaException(message:java.lang.NullPointerException)
>         at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.newMetaException(HiveMetaStore.java:5535)
>         at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.add_partitions_req(HiveMetaStore.java:2308)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:138)
>         at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:99)
>         at com.sun.proxy.$Proxy14.add_partitions_req(Unknown Source)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$add_partitions_req.getResult(ThriftHiveMetastore.java:9723)
>         at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$add_partitions_req.getResult(ThriftHiveMetastore.java:9707)
>         at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
>         at org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:110)
>         at org.apache.hadoop.hive.metastore.TUGIBasedProcessor$1.run(TUGIBasedProcessor.java:106)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at javax.security.auth.Subject.doAs(Subject.java:415)
>         at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1693)
>         at org.apache.hadoop.hive.metastore.TUGIBasedProcessor.process(TUGIBasedProcessor.java:118)
>         at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.NullPointerException
>         at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1245)
>         at com.jolbox.bonecp.StatementHandle.executeBatch(StatementHandle.java:424)
>         at org.datanucleus.store.rdbms.ParamLoggingPreparedStatement.executeBatch(ParamLoggingPreparedStatement.java:372)
>         at org.datanucleus.store.rdbms.SQLController.processConnectionStatement(SQLController.java:628)
>         at org.datanucleus.store.rdbms.SQLController.getStatementForQuery(SQLController.java:324)
>         at org.datanucleus.store.rdbms.query.RDBMSQueryUtils.getPreparedStatementForQuery(RDBMSQueryUtils.java:194)
>         at org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:640)
>         at org.datanucleus.store.query.Query.executeQuery(Query.java:1786)
>         at org.datanucleus.store.query.Query.executeWithArray(Query.java:1672)
>         at org.datanucleus.store.query.Query.execute(Query.java:1654)
>         at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:221)
>         at org.apache.hadoop.hive.metastore.ObjectStore.addNotificationEvent(ObjectStore.java:7534)
>         at sun.reflect.GeneratedMethodAccessor38.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:114)
>         at com.sun.proxy.$Proxy10.addNotificationEvent(Unknown Source)
>         at org.apache.hive.hcatalog.listener.DbNotificationListener.enqueue(DbNotificationListener.java:261)
>         at org.apache.hive.hcatalog.listener.DbNotificationListener.onAddPartition(DbNotificationListener.java:168)
> {noformat}
> It is concurrency issue manifesting in different way.
> We need to revisit ObjectStore and db notification listener's use of ObjectStore to understand the issue.
> The patch for HIVE-13836 avoids concurrent calls to ObjectStore. But we need to find the root cause of the real issue as ObjectStore should handle concurrent calls.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)