hive-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From ekoif...@apache.org
Subject hive git commit: HIVE-11006 improve logging wrt ACID module (Eugene Koifman, reviewed by Alan Gates)
Date Wed, 17 Jun 2015 20:05:18 GMT
Repository: hive
Updated Branches:
  refs/heads/master a3792b7b7 -> 37e82baaf


HIVE-11006 improve logging wrt ACID module (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/37e82baa
Tree: http://git-wip-us.apache.org/repos/asf/hive/tree/37e82baa
Diff: http://git-wip-us.apache.org/repos/asf/hive/diff/37e82baa

Branch: refs/heads/master
Commit: 37e82baafbdf171757cd07939ee9745e4c3b5adb
Parents: a3792b7
Author: Eugene Koifman <ekoifman@hortonworks.com>
Authored: Wed Jun 17 13:05:10 2015 -0700
Committer: Eugene Koifman <ekoifman@hortonworks.com>
Committed: Wed Jun 17 13:05:10 2015 -0700

----------------------------------------------------------------------
 .../hive/metastore/txn/CompactionInfo.java      |  9 +++++
 .../metastore/txn/CompactionTxnHandler.java     | 19 +++++------
 .../hadoop/hive/metastore/txn/TxnHandler.java   | 36 +++++++++++---------
 .../hadoop/hive/ql/lockmgr/DbLockManager.java   |  4 +--
 .../hadoop/hive/ql/lockmgr/DbTxnManager.java    |  2 +-
 5 files changed, 41 insertions(+), 29 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/hive/blob/37e82baa/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionInfo.java
----------------------------------------------------------------------
diff --git a/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionInfo.java b/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionInfo.java
index 939df3f..1dae7b9 100644
--- a/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionInfo.java
+++ b/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionInfo.java
@@ -73,4 +73,13 @@ public class CompactionInfo implements Comparable<CompactionInfo>
{
   public int compareTo(CompactionInfo o) {
     return getFullPartitionName().compareTo(o.getFullPartitionName());
   }
+  public String toString() {
+    return "id:" + id + "," +
+      "dbname:" + dbname + "," +
+      "tableName:" + tableName + "," +
+      "partName:" + partName + "," +
+      "type:" + type + "," +
+      "runAs:" + runAs + "," +
+      "tooManyAborts:" + tooManyAborts;
+  }
 }

http://git-wip-us.apache.org/repos/asf/hive/blob/37e82baa/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionTxnHandler.java
----------------------------------------------------------------------
diff --git a/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionTxnHandler.java
b/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionTxnHandler.java
index 26e72be..328a65c 100644
--- a/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionTxnHandler.java
+++ b/metastore/src/java/org/apache/hadoop/hive/metastore/txn/CompactionTxnHandler.java
@@ -95,7 +95,7 @@ public class CompactionTxnHandler extends TxnHandler {
         dbConn.rollback();
       } catch (SQLException e) {
         LOG.error("Unable to connect to transaction database " + e.getMessage());
-        checkRetryable(dbConn, e, "findPotentialCompactions");
+        checkRetryable(dbConn, e, "findPotentialCompactions(maxAborted:" + maxAborted + ")");
       } finally {
         closeDbConn(dbConn);
         closeStmt(stmt);
@@ -133,7 +133,7 @@ public class CompactionTxnHandler extends TxnHandler {
         LOG.error("Unable to update compaction queue, " + e.getMessage());
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "setRunAs");
+        checkRetryable(dbConn, e, "setRunAs(cq_id:" + cq_id + ",user:" + user +")");
       } finally {
         closeDbConn(dbConn);
         closeStmt(stmt);
@@ -194,7 +194,7 @@ public class CompactionTxnHandler extends TxnHandler {
         LOG.error("Unable to select next element for compaction, " + e.getMessage());
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "findNextToCompact");
+        checkRetryable(dbConn, e, "findNextToCompact(workerId:" + workerId + ")");
         throw new MetaException("Unable to connect to transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -232,7 +232,7 @@ public class CompactionTxnHandler extends TxnHandler {
         LOG.error("Unable to update compaction queue " + e.getMessage());
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "markCompacted");
+        checkRetryable(dbConn, e, "markCompacted(" + info + ")");
         throw new MetaException("Unable to connect to transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -374,7 +374,7 @@ public class CompactionTxnHandler extends TxnHandler {
         LOG.error("Unable to delete from compaction queue " + e.getMessage());
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "markCleaned");
+        checkRetryable(dbConn, e, "markCleaned(" + info + ")");
         throw new MetaException("Unable to connect to transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -465,7 +465,7 @@ public class CompactionTxnHandler extends TxnHandler {
           e.getMessage());
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "revokeFromLocalWorkers");
+        checkRetryable(dbConn, e, "revokeFromLocalWorkers(hostname:" + hostname +")");
         throw new MetaException("Unable to connect to transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -508,7 +508,7 @@ public class CompactionTxnHandler extends TxnHandler {
           e.getMessage());
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "revokeTimedoutWorkers");
+        checkRetryable(dbConn, e, "revokeTimedoutWorkers(timeout:" + timeout + ")");
         throw new MetaException("Unable to connect to transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -565,10 +565,9 @@ public class CompactionTxnHandler extends TxnHandler {
         dbConn.commit();
         return columns;
       } catch (SQLException e) {
-        LOG.error("Failed to find columns to analyze stats on for " + ci.tableName +
-          (ci.partName == null ? "" : "/" + ci.partName), e);
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "findColumnsWithStats");
+        checkRetryable(dbConn, e, "findColumnsWithStats(" + ci.tableName +
+          (ci.partName == null ? "" : "/" + ci.partName) + ")");
         throw new MetaException("Unable to connect to transaction database " +
           StringUtils.stringifyException(e));
       } finally {

http://git-wip-us.apache.org/repos/asf/hive/blob/37e82baa/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 7c3b55c..fd9c275 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
@@ -318,7 +318,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "openTxns");
+        checkRetryable(dbConn, e, "openTxns(" + rqst + ")");
         throw new MetaException("Unable to select from transaction database "
           + StringUtils.stringifyException(e));
       } finally {
@@ -347,7 +347,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "abortTxn");
+        checkRetryable(dbConn, e, "abortTxn(" + rqst + ")");
         throw new MetaException("Unable to update transaction database "
           + StringUtils.stringifyException(e));
       } finally {
@@ -400,7 +400,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "commitTxn");
+        checkRetryable(dbConn, e, "commitTxn(" + rqst + ")");
         throw new MetaException("Unable to update transaction database "
           + StringUtils.stringifyException(e));
       } finally {
@@ -423,7 +423,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "lock");
+        checkRetryable(dbConn, e, "lock(" + rqst + ")");
         throw new MetaException("Unable to update transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -444,7 +444,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "lockNoWait");
+        checkRetryable(dbConn, e, "lockNoWait(" + rqst + ")");
         throw new MetaException("Unable to update transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -475,7 +475,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "checkLock");
+        checkRetryable(dbConn, e, "checkLock(" + rqst + " )");
         throw new MetaException("Unable to update transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -526,7 +526,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "unlock");
+        checkRetryable(dbConn, e, "unlock(" + rqst + ")");
         throw new MetaException("Unable to update transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -593,7 +593,7 @@ public class TxnHandler {
         LOG.debug("Going to rollback");
         dbConn.rollback();
       } catch (SQLException e) {
-        checkRetryable(dbConn, e, "showLocks");
+        checkRetryable(dbConn, e, "showLocks(" + rqst + ")");
         throw new MetaException("Unable to select from transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -624,7 +624,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "heartbeat");
+        checkRetryable(dbConn, e, "heartbeat(" + ids + ")");
         throw new MetaException("Unable to select from transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -661,7 +661,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "heartbeatTxnRange");
+        checkRetryable(dbConn, e, "heartbeatTxnRange(" + rqst + ")");
         throw new MetaException("Unable to select from transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -742,7 +742,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "compact");
+        checkRetryable(dbConn, e, "compact(" + rqst + ")");
         throw new MetaException("Unable to select from transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -792,7 +792,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "showCompact");
+        checkRetryable(dbConn, e, "showCompact(" + rqst + ")");
         throw new MetaException("Unable to select from transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -835,7 +835,7 @@ public class TxnHandler {
       } catch (SQLException e) {
         LOG.debug("Going to rollback");
         rollbackDBConn(dbConn);
-        checkRetryable(dbConn, e, "addDynamicPartitions");
+        checkRetryable(dbConn, e, "addDynamicPartitions(" + rqst + ")");
         throw new MetaException("Unable to insert into from transaction database " +
           StringUtils.stringifyException(e));
       } finally {
@@ -955,6 +955,7 @@ public class TxnHandler {
    * @param caller name of the method calling this
    * @throws org.apache.hadoop.hive.metastore.txn.TxnHandler.RetryException when deadlock
    * detected and retry count has not been exceeded.
+   * TODO: make "caller" more elaborate like include lockId for example
    */
   protected void checkRetryable(Connection conn,
                                 SQLException e,
@@ -977,10 +978,12 @@ public class TxnHandler {
       (dbProduct == DatabaseProduct.ORACLE && (e.getMessage().contains("deadlock
detected")
         || e.getMessage().contains("can't serialize access for this transaction")))) {
       if (deadlockCnt++ < ALLOWED_REPEATED_DEADLOCKS) {
-        LOG.warn("Deadlock detected in " + caller + ", trying again.");
+        long waitInterval = deadlockRetryInterval * deadlockCnt;
+        LOG.warn("Deadlock detected in " + caller + ". Will wait " + waitInterval +
+          "ms try again up to " + (ALLOWED_REPEATED_DEADLOCKS - deadlockCnt + 1) + " times.");
         // Pause for a just a bit for retrying to avoid immediately jumping back into the
deadlock.
         try {
-          Thread.sleep(deadlockRetryInterval * deadlockCnt);
+          Thread.sleep(waitInterval);
         } catch (InterruptedException ie) {
           // NOP
         }
@@ -993,13 +996,14 @@ public class TxnHandler {
     else if(isRetryable(e)) {
       //in MSSQL this means Communication Link Failure
       if(retryNum++ < retryLimit) {
+        LOG.warn("Retryable error detected in " + caller + ".  Will wait " + retryInterval
+
+          "ms and retry up to " + (retryLimit - retryNum + 1) + " times.  Error: " + getMessage(e));
         try {
           Thread.sleep(retryInterval);
         }
         catch(InterruptedException ex) {
           //
         }
-        LOG.warn("Retryable error detected in " + caller + ", trying again: " + getMessage(e));
         throw new RetryException();
       }
       else {

http://git-wip-us.apache.org/repos/asf/hive/blob/37e82baa/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 e8c49ef..aa00573 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
@@ -79,10 +79,10 @@ public class DbLockManager implements HiveLockManager{
    */
   LockState lock(LockRequest lock, String queryId, boolean isBlocking, List<HiveLock>
acquiredLocks) throws LockException {
     try {
-      LOG.debug("Requesting: queryId=" + queryId + " " + lock);
+      LOG.info("Requesting: queryId=" + queryId + " " + lock);
       LockResponse res = client.lock(lock);
       //link lockId to queryId
-      LOG.debug("Response " + res);
+      LOG.info("Response to queryId=" + queryId + " " + res);
       if(!isBlocking) {
         if(res.getState() == LockState.WAITING) {
           return LockState.WAITING;

http://git-wip-us.apache.org/repos/asf/hive/blob/37e82baa/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 ccbac80..f8fff1a 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
@@ -105,7 +105,7 @@ public class DbTxnManager extends HiveTxnManagerImpl {
 
     LockRequestBuilder rqstBuilder = new LockRequestBuilder();
     //link queryId to txnId
-    LOG.debug("Setting lock request transaction to " + txnId + " for queryId=" + plan.getQueryId());
+    LOG.info("Setting lock request transaction to " + txnId + " for queryId=" + plan.getQueryId());
     rqstBuilder.setTransactionId(txnId)
         .setUser(username);
 


Mime
View raw message