[
https://issues.apache.org/jira/browse/HIVE-7249?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Alan Gates updated HIVE-7249:
-----------------------------
Attachment: HIVE-7249.patch
Eugene, please apply this patch and see if it fixes your issue.
> HiveTxnManager.closeTxnManger() throws if called after commitTxn()
> ------------------------------------------------------------------
>
> Key: HIVE-7249
> URL: https://issues.apache.org/jira/browse/HIVE-7249
> Project: Hive
> Issue Type: Bug
> Components: Locking
> Affects Versions: 0.13.1
> Reporter: Eugene Koifman
> Assignee: Alan Gates
> Attachments: HIVE-7249.patch
>
>
> I openTxn() and acquireLocks() for a query that looks like "INSERT INTO T
> PARTITION(p) SELECT * FROM T".
> Then I call commitTxn(). Then I call closeTxnManger() I get an exception
> saying lock not found (the only lock in this txn). So it seems TxnMgr
> doesn't know that commit released the locks.
> Here is the stack trace and some log output which maybe useful:
> {noformat}
> 2014-06-17 15:54:40,771 DEBUG mapreduce.TransactionContext
> (TransactionContext.java:onCommitJob(128)) -
> onCommitJob(job_local557130041_0001). this=46719652
> 2014-06-17 15:54:40,771 DEBUG lockmgr.DbTxnManager
> (DbTxnManager.java:commitTxn(205)) - Committing txn 1
> 2014-06-17 15:54:40,771 DEBUG txn.TxnHandler (TxnHandler.java:getDbTime(872))
> - Going to execute query <values current_timestamp>
> 2014-06-17 15:54:40,772 DEBUG txn.TxnHandler
> (TxnHandler.java:heartbeatTxn(1423)) - Going to execute query <select
> txn_state from TXNS where txn_id = 1 for\
> update>
> 2014-06-17 15:54:40,773 DEBUG txn.TxnHandler
> (TxnHandler.java:heartbeatTxn(1438)) - Going to execute update <update TXNS
> set txn_last_heartbeat = 140304568\
> 0772 where txn_id = 1>
> 2014-06-17 15:54:40,778 DEBUG txn.TxnHandler
> (TxnHandler.java:heartbeatTxn(1440)) - Going to commit
> 2014-06-17 15:54:40,779 DEBUG txn.TxnHandler (TxnHandler.java:commitTxn(344))
> - Going to execute insert <insert into COMPLETED_TXN_COMPONENTS select tc_txn\
> id, tc_database, tc_table, tc_partition from TXN_COMPONENTS where tc_txnid =
> 1>
> 2014-06-17 15:54:40,784 DEBUG txn.TxnHandler (TxnHandler.java:commitTxn(352))
> - Going to execute update <delete from TXN_COMPONENTS where tc_txnid = 1>
> 2014-06-17 15:54:40,788 DEBUG txn.TxnHandler (TxnHandler.java:commitTxn(356))
> - Going to execute update <delete from HIVE_LOCKS where hl_txnid = 1>
> 2014-06-17 15:54:40,791 DEBUG txn.TxnHandler (TxnHandler.java:commitTxn(359))
> - Going to execute update <delete from TXNS where txn_id = 1>
> 2014-06-17 15:54:40,794 DEBUG txn.TxnHandler (TxnHandler.java:commitTxn(361))
> - Going to commit
> 2014-06-17 15:54:40,795 WARN mapreduce.TransactionContext
> (TransactionContext.java:cleanup(317)) -
> cleanupJob(JobID=job_local557130041_0001)this=46719652
> 2014-06-17 15:54:40,795 DEBUG lockmgr.DbLockManager
> (DbLockManager.java:unlock(109)) - Unlocking id:1
> 2014-06-17 15:54:40,796 DEBUG txn.TxnHandler (TxnHandler.java:getDbTime(872))
> - Going to execute query <values current_timestamp>
> 2014-06-17 15:54:40,796 DEBUG txn.TxnHandler
> (TxnHandler.java:heartbeatLock(1402)) - Going to execute update <update
> HIVE_LOCKS set hl_last_heartbeat = 140\
> 3045680796 where hl_lock_ext_id = 1>
> 2014-06-17 15:54:40,800 DEBUG txn.TxnHandler
> (TxnHandler.java:heartbeatLock(1405)) - Going to rollback
> 2014-06-17 15:54:40,804 ERROR metastore.RetryingHMSHandler
> (RetryingHMSHandler.java:invoke(143)) - NoSuchLockException(message:No such
> lock: 1)
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.heartbeatLock(TxnHandler.java:1407)
> at
> org.apache.hadoop.hive.metastore.txn.TxnHandler.unlock(TxnHandler.java:477)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.unlock(HiveMetaStore.java:4817)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:105)
> at com.sun.proxy.$Proxy14.unlock(Unknown Source)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.unlock(HiveMetaStoreClient.java:1598)
> at
> org.apache.hadoop.hive.ql.lockmgr.DbLockManager.unlock(DbLockManager.java:110)
> at
> org.apache.hadoop.hive.ql.lockmgr.DbLockManager.close(DbLockManager.java:162)
> at
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager.destruct(DbTxnManager.java:300)
> at
> org.apache.hadoop.hive.ql.lockmgr.HiveTxnManagerImpl.closeTxnManager(HiveTxnManagerImpl.java:39)
> at
> org.apache.hadoop.hive.ql.lockmgr.DbTxnManager.closeTxnManager(DbTxnManager.java:43)
> at
> org.apache.hive.hcatalog.mapreduce.TransactionContext.cleanup(TransactionContext.java:327)
> at
> org.apache.hive.hcatalog.mapreduce.TransactionContext.onCommitJob(TransactionContext.java:142)
> at
> org.apache.hive.hcatalog.mapreduce.OutputCommitterContainer.commitJob(OutputCommitterContainer.java:61)
> at
> org.apache.hive.hcatalog.mapreduce.FileOutputCommitterContainer.commitJob(FileOutputCommitterContainer.java:251)
> at
> org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:537)
> 2014-06-17 15:54:40,804 ERROR lockmgr.DbLockManager
> (DbLockManager.java:unlock(114)) - Metastore could find no record of lock 1
> 2014-06-17 15:54:40,810 INFO mapreduce.FileOutputCommitterContainer
> (FileOutputCommitterContainer.java:cancelDelegationTokens(976)) - Cancelling
> delegation token for the job.
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
