Repository: hive Updated Branches: refs/heads/branch-1 a59e81c31 -> b8418b861
HIVE-11087 - DbTxnManager exceptions should include txnid (Eugene Koifman, reviewed by Alan Gates) Project: http://git-wip-us.apache.org/repos/asf/hive/repo Commit: http://git-wip-us.apache.org/repos/asf/hive/commit/b8418b86 Tree: http://git-wip-us.apache.org/repos/asf/hive/tree/b8418b86 Diff: http://git-wip-us.apache.org/repos/asf/hive/diff/b8418b86 Branch: refs/heads/branch-1 Commit: b8418b861250972c1de09236f64f1fef1628edc0 Parents: a59e81c Author: Eugene Koifman <ekoif...@hortonworks.com> Authored: Thu Aug 6 11:22:15 2015 -0700 Committer: Eugene Koifman <ekoif...@hortonworks.com> Committed: Thu Aug 6 11:22:15 2015 -0700 ---------------------------------------------------------------------- .../apache/hadoop/hive/common/JavaUtils.java | 11 +++- .../hadoop/hive/metastore/txn/TxnHandler.java | 25 ++++----- .../org/apache/hadoop/hive/ql/ErrorMsg.java | 10 ++-- .../hadoop/hive/ql/lockmgr/DbLockManager.java | 12 ++--- .../hadoop/hive/ql/lockmgr/DbTxnManager.java | 37 ++++++------- .../hive/ql/lockmgr/TestDbTxnManager.java | 55 ++++++++++++++++++-- .../hive/ql/lockmgr/TestDbTxnManager2.java | 2 +- 7 files changed, 105 insertions(+), 47 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/hive/blob/b8418b86/common/src/java/org/apache/hadoop/hive/common/JavaUtils.java ---------------------------------------------------------------------- diff --git a/common/src/java/org/apache/hadoop/hive/common/JavaUtils.java b/common/src/java/org/apache/hadoop/hive/common/JavaUtils.java index 3dd8f75..dc3a4ae 100644 --- a/common/src/java/org/apache/hadoop/hive/common/JavaUtils.java +++ b/common/src/java/org/apache/hadoop/hive/common/JavaUtils.java @@ -137,12 +137,19 @@ public final class JavaUtils { } /** - * Utility method for ACID to normalize logging info - * @param extLockId LockResponse.lockid + * Utility method for ACID to normalize logging info. Matches + * {@link org.apache.hadoop.hive.metastore.api.LockRequest#toString()} */ public static String lockIdToString(long extLockId) { return "lockid:" + extLockId; } + /** + * Utility method for ACID to normalize logging info. Matches + * {@link org.apache.hadoop.hive.metastore.api.LockResponse#toString()} + */ + public static String txnIdToString(long txnId) { + return "txnid:" + txnId; + } private JavaUtils() { // prevent instantiation http://git-wip-us.apache.org/repos/asf/hive/blob/b8418b86/metastore/src/java/org/apache/hadoop/hive/metastore/txn/TxnHandler.java ---------------------------------------------------------------------- diff --git a/metastore/src/java/org/apache/hadoop/hive/metastore/txn/TxnHandler.java b/metastore/src/java/org/apache/hadoop/hive/metastore/txn/TxnHandler.java index c0e83c6..88e007c 100644 --- a/metastore/src/java/org/apache/hadoop/hive/metastore/txn/TxnHandler.java +++ b/metastore/src/java/org/apache/hadoop/hive/metastore/txn/TxnHandler.java @@ -339,7 +339,7 @@ public class TxnHandler { if (abortTxns(dbConn, Collections.singletonList(txnid)) != 1) { LOG.debug("Going to rollback"); dbConn.rollback(); - throw new NoSuchTxnException("No such transaction: " + txnid); + throw new NoSuchTxnException("No such transaction " + JavaUtils.txnIdToString(txnid)); } LOG.debug("Going to commit"); @@ -382,7 +382,7 @@ public class TxnHandler { if (stmt.executeUpdate(s) < 1) { //this can be reasonable for an empty txn START/COMMIT LOG.info("Expected to move at least one record from txn_components to " + - "completed_txn_components when committing txn! txnid:" + txnid); + "completed_txn_components when committing txn! " + JavaUtils.txnIdToString(txnid)); } // Always access TXN_COMPONENTS before HIVE_LOCKS; @@ -508,8 +508,8 @@ public class TxnHandler { LOG.debug("Going to rollback"); dbConn.rollback(); String msg = "Unlocking locks associated with transaction" + - " not permitted. Lockid " + extLockId + " is associated with " + - "transaction " + txnid; + " not permitted. Lockid " + JavaUtils.lockIdToString(extLockId) + " is associated with " + + "transaction " + JavaUtils.txnIdToString(txnid); LOG.error(msg); throw new TxnOpenException(msg); } @@ -520,7 +520,7 @@ public class TxnHandler { if (rc < 1) { LOG.debug("Going to rollback"); dbConn.rollback(); - throw new NoSuchLockException("No such lock: " + extLockId); + throw new NoSuchLockException("No such lock " + JavaUtils.lockIdToString(extLockId)); } LOG.debug("Going to commit"); dbConn.commit(); @@ -1175,8 +1175,8 @@ public class TxnHandler { @Override public String toString() { return JavaUtils.lockIdToString(extLockId) + " intLockId:" + - intLockId + " txnId:" + Long.toString - (txnId) + " db:" + db + " table:" + table + " partition:" + + intLockId + " " + JavaUtils.txnIdToString(txnId) + + " db:" + db + " table:" + table + " partition:" + partition + " state:" + (state == null ? "null" : state.toString()) + " type:" + (type == null ? "null" : type.toString()); } @@ -1315,7 +1315,8 @@ public class TxnHandler { LOG.debug("Going to execute update <" + buf.toString() + ">"); stmt.executeUpdate(buf.toString()); - buf = new StringBuilder("update TXNS set txn_state = '" + TXN_ABORTED + "' where txn_id in ("); + buf = new StringBuilder("update TXNS set txn_state = '" + TXN_ABORTED + + "' where txn_state = '" + TXN_OPEN + "' and txn_id in ("); first = true; for (Long id : txnids) { if (first) first = false; @@ -1344,7 +1345,7 @@ public class TxnHandler { * of NOT_ACQUIRED. The caller will need to call * {@link #lockNoWait(org.apache.hadoop.hive.metastore.api.LockRequest)} again to * attempt another lock. - * @return informatino on whether the lock was acquired. + * @return information on whether the lock was acquired. * @throws NoSuchTxnException * @throws TxnAbortedException */ @@ -1733,12 +1734,12 @@ public class TxnHandler { if (!rs.next()) { LOG.debug("Going to rollback"); dbConn.rollback(); - throw new NoSuchTxnException("No such transaction: " + txnid); + throw new NoSuchTxnException("No such transaction " + JavaUtils.txnIdToString(txnid)); } if (rs.getString(1).charAt(0) == TXN_ABORTED) { LOG.debug("Going to rollback"); dbConn.rollback(); - throw new TxnAbortedException("Transaction " + txnid + + throw new TxnAbortedException("Transaction " + JavaUtils.txnIdToString(txnid) + " already aborted"); } s = "update TXNS set txn_last_heartbeat = " + now + @@ -1767,7 +1768,7 @@ public class TxnHandler { "checked the lock existed but now we can't find it!"); } long txnid = rs.getLong(1); - LOG.debug("Return txnid " + (rs.wasNull() ? -1 : txnid)); + LOG.debug("Return " + JavaUtils.txnIdToString(rs.wasNull() ? -1 : txnid)); return (rs.wasNull() ? -1 : txnid); } finally { closeStmt(stmt); http://git-wip-us.apache.org/repos/asf/hive/blob/b8418b86/ql/src/java/org/apache/hadoop/hive/ql/ErrorMsg.java ---------------------------------------------------------------------- diff --git a/ql/src/java/org/apache/hadoop/hive/ql/ErrorMsg.java b/ql/src/java/org/apache/hadoop/hive/ql/ErrorMsg.java index cef72b4..c2c99c5 100644 --- a/ql/src/java/org/apache/hadoop/hive/ql/ErrorMsg.java +++ b/ql/src/java/org/apache/hadoop/hive/ql/ErrorMsg.java @@ -385,14 +385,14 @@ public enum ErrorMsg { "set hive.txn.manager"), TXNMGR_NOT_INSTANTIATED(10261, "Transaction manager could not be " + "instantiated, check hive.txn.manager"), - TXN_NO_SUCH_TRANSACTION(10262, "No record of transaction could be found, " + - "may have timed out"), - TXN_ABORTED(10263, "Transaction manager has aborted the transaction."), + TXN_NO_SUCH_TRANSACTION(10262, "No record of transaction {0} could be found, " + + "may have timed out", true), + TXN_ABORTED(10263, "Transaction manager has aborted the transaction {0}.", true), DBTXNMGR_REQUIRES_CONCURRENCY(10264, "To use DbTxnManager you must set hive.support.concurrency=true"), - LOCK_NO_SUCH_LOCK(10270, "No record of lock could be found, " + - "may have timed out"), + LOCK_NO_SUCH_LOCK(10270, "No record of lock {0} could be found, " + + "may have timed out", true), LOCK_REQUEST_UNSUPPORTED(10271, "Current transaction manager does not " + "support explicit lock requests. Transaction manager: "), http://git-wip-us.apache.org/repos/asf/hive/blob/b8418b86/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbLockManager.java ---------------------------------------------------------------------- diff --git a/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbLockManager.java b/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbLockManager.java index aa00573..82e227f 100644 --- a/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbLockManager.java +++ b/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbLockManager.java @@ -48,7 +48,7 @@ public class DbLockManager implements HiveLockManager{ private long nextSleep = 50; DbLockManager(IMetaStoreClient client) { - locks = new HashSet<DbHiveLock>(); + locks = new HashSet<>(); this.client = client; } @@ -104,8 +104,8 @@ public class DbLockManager implements HiveLockManager{ LOG.error("Metastore could not find txnid " + lock.getTxnid()); throw new LockException(ErrorMsg.TXNMGR_NOT_INSTANTIATED.getMsg(), e); } catch (TxnAbortedException e) { - LOG.error("Transaction " + lock.getTxnid() + " already aborted."); - throw new LockException(ErrorMsg.TXN_ABORTED.getMsg(), e); + LOG.error("Transaction " + JavaUtils.txnIdToString(lock.getTxnid()) + " already aborted."); + throw new LockException(e, ErrorMsg.TXN_ABORTED, JavaUtils.txnIdToString(lock.getTxnid())); } catch (TException e) { throw new LockException(ErrorMsg.METASTORE_COMMUNICATION_FAILED.getMsg(), e); @@ -135,10 +135,10 @@ public class DbLockManager implements HiveLockManager{ boolean removed = locks.remove(hiveLock); LOG.debug("Removed a lock " + removed); } catch (NoSuchLockException e) { - LOG.error("Metastore could find no record of lock " + lockId); - throw new LockException(ErrorMsg.LOCK_NO_SUCH_LOCK.getMsg(), e); + LOG.error("Metastore could find no record of lock " + JavaUtils.lockIdToString(lockId)); + throw new LockException(e, ErrorMsg.LOCK_NO_SUCH_LOCK, JavaUtils.lockIdToString(lockId)); } catch (TxnOpenException e) { - throw new RuntimeException("Attempt to unlock lock " + lockId + + throw new RuntimeException("Attempt to unlock lock " + JavaUtils.lockIdToString(lockId) + "associated with an open transaction, " + e.getMessage(), e); } catch (TException e) { throw new LockException(ErrorMsg.METASTORE_COMMUNICATION_FAILED.getMsg(), http://git-wip-us.apache.org/repos/asf/hive/blob/b8418b86/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbTxnManager.java ---------------------------------------------------------------------- diff --git a/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbTxnManager.java b/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbTxnManager.java index 4813d5b..39b44e8 100644 --- a/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbTxnManager.java +++ b/ql/src/java/org/apache/hadoop/hive/ql/lockmgr/DbTxnManager.java @@ -19,6 +19,7 @@ package org.apache.hadoop.hive.ql.lockmgr; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; +import org.apache.hadoop.hive.common.JavaUtils; import org.apache.hadoop.hive.common.ValidTxnList; import org.apache.hadoop.hive.conf.HiveConf; import org.apache.hadoop.hive.metastore.IMetaStoreClient; @@ -79,12 +80,12 @@ public class DbTxnManager extends HiveTxnManagerImpl { public long openTxn(String user) throws LockException { init(); if(isTxnOpen()) { - throw new LockException("Transaction already opened. txnId=" + txnId);//ToDo: ErrorMsg + throw new LockException("Transaction already opened. " + JavaUtils.txnIdToString(txnId)); } try { txnId = client.openTxn(user); statementId = 0; - LOG.debug("Opened txn " + txnId); + LOG.debug("Opened " + JavaUtils.txnIdToString(txnId)); return txnId; } catch (TException e) { throw new LockException(e, ErrorMsg.METASTORE_COMMUNICATION_FAILED); @@ -119,7 +120,7 @@ public class DbTxnManager extends HiveTxnManagerImpl { LockRequestBuilder rqstBuilder = new LockRequestBuilder(); //link queryId to txnId - LOG.info("Setting lock request transaction to " + txnId + " for queryId=" + plan.getQueryId()); + LOG.info("Setting lock request transaction to " + JavaUtils.txnIdToString(txnId) + " for queryId=" + plan.getQueryId()); rqstBuilder.setTransactionId(txnId) .setUser(username); @@ -252,14 +253,14 @@ public class DbTxnManager extends HiveTxnManagerImpl { } try { lockMgr.clearLocalLockRecords(); - LOG.debug("Committing txn " + txnId); + LOG.debug("Committing txn " + JavaUtils.txnIdToString(txnId)); client.commitTxn(txnId); } catch (NoSuchTxnException e) { - LOG.error("Metastore could not find txn " + txnId); - throw new LockException(ErrorMsg.TXN_NO_SUCH_TRANSACTION.getMsg() , e); + LOG.error("Metastore could not find " + JavaUtils.txnIdToString(txnId)); + throw new LockException(e, ErrorMsg.TXN_NO_SUCH_TRANSACTION, JavaUtils.txnIdToString(txnId)); } catch (TxnAbortedException e) { - LOG.error("Transaction " + txnId + " aborted"); - throw new LockException(ErrorMsg.TXN_ABORTED.getMsg(), e); + LOG.error("Transaction " + JavaUtils.txnIdToString(txnId) + " aborted"); + throw new LockException(e, ErrorMsg.TXN_ABORTED, JavaUtils.txnIdToString(txnId)); } catch (TException e) { throw new LockException(ErrorMsg.METASTORE_COMMUNICATION_FAILED.getMsg(), e); @@ -276,11 +277,11 @@ public class DbTxnManager extends HiveTxnManagerImpl { } try { lockMgr.clearLocalLockRecords(); - LOG.debug("Rolling back txn " + txnId); + LOG.debug("Rolling back " + JavaUtils.txnIdToString(txnId)); client.rollbackTxn(txnId); } catch (NoSuchTxnException e) { - LOG.error("Metastore could not find txn " + txnId); - throw new LockException(ErrorMsg.TXN_NO_SUCH_TRANSACTION.getMsg() , e); + LOG.error("Metastore could not find " + JavaUtils.txnIdToString(txnId)); + throw new LockException(e, ErrorMsg.TXN_NO_SUCH_TRANSACTION, JavaUtils.txnIdToString(txnId)); } catch (TException e) { throw new LockException(ErrorMsg.METASTORE_COMMUNICATION_FAILED.getMsg(), e); @@ -292,7 +293,7 @@ public class DbTxnManager extends HiveTxnManagerImpl { @Override public void heartbeat() throws LockException { - LOG.debug("Heartbeating lock and transaction " + txnId); + LOG.debug("Heartbeating lock and transaction " + JavaUtils.txnIdToString(txnId)); List<HiveLock> locks = lockMgr.getLocks(false, false); if (locks.size() == 0) { if (!isTxnOpen()) { @@ -309,14 +310,14 @@ public class DbTxnManager extends HiveTxnManagerImpl { try { client.heartbeat(txnId, lockId); } catch (NoSuchLockException e) { - LOG.error("Unable to find lock " + lockId); - throw new LockException(ErrorMsg.LOCK_NO_SUCH_LOCK.getMsg(), e); + LOG.error("Unable to find lock " + JavaUtils.lockIdToString(lockId)); + throw new LockException(e, ErrorMsg.LOCK_NO_SUCH_LOCK, JavaUtils.lockIdToString(lockId)); } catch (NoSuchTxnException e) { - LOG.error("Unable to find transaction " + txnId); - throw new LockException(ErrorMsg.TXN_NO_SUCH_TRANSACTION.getMsg(), e); + LOG.error("Unable to find transaction " + JavaUtils.txnIdToString(txnId)); + throw new LockException(e, ErrorMsg.TXN_NO_SUCH_TRANSACTION, JavaUtils.txnIdToString(txnId)); } catch (TxnAbortedException e) { - LOG.error("Transaction aborted " + txnId); - throw new LockException(ErrorMsg.TXN_ABORTED.getMsg(), e); + LOG.error("Transaction aborted " + JavaUtils.txnIdToString(txnId)); + throw new LockException(e, ErrorMsg.TXN_ABORTED, JavaUtils.txnIdToString(txnId)); } catch (TException e) { throw new LockException( ErrorMsg.METASTORE_COMMUNICATION_FAILED.getMsg(), e); http://git-wip-us.apache.org/repos/asf/hive/blob/b8418b86/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager.java ---------------------------------------------------------------------- diff --git a/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager.java b/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager.java index 2fb78fd..f57350d 100644 --- a/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager.java +++ b/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager.java @@ -17,12 +17,12 @@ */ package org.apache.hadoop.hive.ql.lockmgr; -import junit.framework.Assert; import org.apache.hadoop.fs.Path; import org.apache.hadoop.hive.conf.HiveConf; import org.apache.hadoop.hive.metastore.api.FieldSchema; import org.apache.hadoop.hive.metastore.api.ShowLocksResponse;import org.apache.hadoop.hive.metastore.api.ShowLocksResponseElement;import org.apache.hadoop.hive.metastore.txn.TxnDbUtil; import org.apache.hadoop.hive.ql.Context; +import org.apache.hadoop.hive.ql.ErrorMsg; import org.apache.hadoop.hive.ql.QueryPlan; import org.apache.hadoop.hive.ql.hooks.ReadEntity; import org.apache.hadoop.hive.ql.hooks.WriteEntity; @@ -31,16 +31,19 @@ import org.apache.hadoop.hive.ql.metadata.Table; import org.apache.hadoop.hive.ql.session.SessionState; import org.apache.log4j.Level; import org.apache.log4j.LogManager; +import static org.hamcrest.CoreMatchers.is; +import static org.hamcrest.CoreMatchers.not; import org.junit.After; -import org.junit.AfterClass; +import org.junit.Assert; import org.junit.Before; import org.junit.Test; import java.util.*; +import java.util.concurrent.TimeUnit; /** * Unit tests for {@link DbTxnManager}. - * See additional tests in {@link org.apache.hadoop.hive.ql.lockmgr.TestDbTxnManager} + * See additional tests in {@link org.apache.hadoop.hive.ql.lockmgr.TestDbTxnManager2} */ public class TestDbTxnManager { @@ -53,6 +56,7 @@ public class TestDbTxnManager { HashSet<WriteEntity> writeEntities; public TestDbTxnManager() throws Exception { + conf.setTimeVar(HiveConf.ConfVars.HIVE_TXN_TIMEOUT, 500, TimeUnit.MILLISECONDS); TxnDbUtil.setConfValues(conf); SessionState.start(conf); ctx = new Context(conf); @@ -175,6 +179,51 @@ public class TestDbTxnManager { locks = txnMgr.getLockManager().getLocks(false, false); Assert.assertEquals(0, locks.size()); } + @Test + public void testExceptions() throws Exception { + WriteEntity we = addPartitionOutput(newTable(true), WriteEntity.WriteType.INSERT); + QueryPlan qp = new MockQueryPlan(this); + txnMgr.acquireLocks(qp, ctx, "PeterI"); + txnMgr.openTxn("NicholasII"); + Thread.sleep(1000);//let txn timeout + txnMgr.getValidTxns(); + LockException exception = null; + try { + txnMgr.commitTxn(); + } + catch(LockException ex) { + exception = ex; + } + Assert.assertNotNull("Expected exception1", exception); + Assert.assertEquals("Wrong Exception1", ErrorMsg.TXN_ABORTED, exception.getCanonicalErrorMsg()); + exception = null; + txnMgr.openTxn("AlexanderIII"); + Thread.sleep(1000); + txnMgr.getValidTxns(); + try { + txnMgr.rollbackTxn(); + } + catch (LockException ex) { + exception = ex; + } + Assert.assertNotNull("Expected exception2", exception); + Assert.assertEquals("Wrong Exception2", ErrorMsg.TXN_NO_SUCH_TRANSACTION, exception.getCanonicalErrorMsg()); + exception = null; + txnMgr.openTxn("PeterI"); + txnMgr.acquireLocks(qp, ctx, "PeterI"); + List<HiveLock> locks = ctx.getHiveLocks(); + Assert.assertThat("Unexpected lock count", locks.size(), is(1)); + Thread.sleep(1000); + txnMgr.getValidTxns(); + try { + txnMgr.heartbeat(); + } + catch(LockException ex) { + exception = ex; + } + Assert.assertNotNull("Expected exception3", exception); + Assert.assertEquals("Wrong Exception3", ErrorMsg.LOCK_NO_SUCH_LOCK, exception.getCanonicalErrorMsg()); + } @Test public void testReadWrite() throws Exception { http://git-wip-us.apache.org/repos/asf/hive/blob/b8418b86/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager2.java ---------------------------------------------------------------------- diff --git a/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager2.java b/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager2.java index 6a69641..44ad8b0 100644 --- a/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager2.java +++ b/ql/src/test/org/apache/hadoop/hive/ql/lockmgr/TestDbTxnManager2.java @@ -39,7 +39,7 @@ import java.util.List; /** * See additional tests in {@link org.apache.hadoop.hive.ql.lockmgr.TestDbTxnManager} - * Tests here + * Tests here are "end-to-end"ish and simulate concurrent queries. */ public class TestDbTxnManager2 { private static HiveConf conf = new HiveConf(Driver.class);