hive-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Nachiket Vaidya (JIRA)" <j...@apache.org>
Subject [jira] [Created] (HIVE-13869) ObjectStore synchronization issue manifested in db notification listener
Date Thu, 26 May 2016 22:58:12 GMT
Nachiket Vaidya created HIVE-13869:
--------------------------------------

             Summary: 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
             Fix For: 1.2.2


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)

Mime
View raw message