[
https://issues.apache.org/jira/browse/HIVE-13836?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15302875#comment-15302875
]
Nachiket Vaidya commented on HIVE-13836:
----------------------------------------
[~sushanth] Thank you for reply.
I agree with you that the issue is deep inside.
The issue is easy to reproduce. I tried that and I got different stack trace.
{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 of course concurrency issue manifesting in different way.
It looks like db notification is using ObjectStore differently. Adding
synchronization at db notification solves this issue.
Given that there is not much performance implication for using synchronization,
it should be ok to fix it in db notification and then file separate jira to
track ObjectStore issue.
Please let me know what do you think.
> DbNotifications giving an error = Invalid state. Transaction has already
> started
> --------------------------------------------------------------------------------
>
> Key: HIVE-13836
> URL: https://issues.apache.org/jira/browse/HIVE-13836
> Project: Hive
> Issue Type: Bug
> Reporter: Nachiket Vaidya
> Priority: Critical
> Attachments: HIVE-13836.patch
>
>
> 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}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
