accumulo-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From ibe...@apache.org
Subject [accumulo] branch 1.7 updated: Fixes ACCUMULO-4832 WAL warnings
Date Tue, 27 Feb 2018 16:57:21 GMT
This is an automated email from the ASF dual-hosted git repository.

ibella pushed a commit to branch 1.7
in repository https://gitbox.apache.org/repos/asf/accumulo.git


The following commit(s) were added to refs/heads/1.7 by this push:
     new e0cf7cd  Fixes ACCUMULO-4832 WAL warnings
e0cf7cd is described below

commit e0cf7cd489c069d6b9fd4918ecc84d751b0b3cf8
Author: Ivan Bella <ivan@bella.name>
AuthorDate: Mon Feb 26 14:44:26 2018 -0500

    Fixes ACCUMULO-4832 WAL warnings
    
    Change initial WAL retry message to debug, and subsequent messages to warnings.
    Also added trace messages inbetween if desired.  Only the warning message will show the
full stack trace.
    Updated Retry to use System.nanoTime() instead of System.currentTimeMillis().
---
 .../org/apache/accumulo/fate/zookeeper/Retry.java  | 47 +++++++++++++++++-----
 .../apache/accumulo/fate/zookeeper/RetryTest.java  |  8 +++-
 .../accumulo/tserver/log/TabletServerLogger.java   |  5 +--
 3 files changed, 45 insertions(+), 15 deletions(-)

diff --git a/fate/src/main/java/org/apache/accumulo/fate/zookeeper/Retry.java b/fate/src/main/java/org/apache/accumulo/fate/zookeeper/Retry.java
index d710e2c..73d5227 100644
--- a/fate/src/main/java/org/apache/accumulo/fate/zookeeper/Retry.java
+++ b/fate/src/main/java/org/apache/accumulo/fate/zookeeper/Retry.java
@@ -32,7 +32,8 @@ public class Retry {
   private long maxRetries, maxWait, waitIncrement;
   private long retriesDone, currentWait;
 
-  private long logInterval;
+  private static long NANO_SEC_PER_MILLI_SEC = 1000000L;
+  private long logIntervalNanoSec;
   private long lastRetryLog;
 
   /**
@@ -54,7 +55,7 @@ public class Retry {
     this.waitIncrement = waitIncrement;
     this.retriesDone = 0l;
     this.currentWait = startWait;
-    this.logInterval = logInterval;
+    this.logIntervalNanoSec = (logInterval * NANO_SEC_PER_MILLI_SEC);
     this.lastRetryLog = -1;
   }
 
@@ -126,11 +127,11 @@ public class Retry {
 
   // Visible for testing
   void setLogInterval(long logInterval) {
-    this.logInterval = logInterval;
+    this.logIntervalNanoSec = logInterval * NANO_SEC_PER_MILLI_SEC;
   }
 
   public long getLogInterval() {
-    return logInterval;
+    return logIntervalNanoSec / NANO_SEC_PER_MILLI_SEC;
   }
 
   public boolean canRetry() {
@@ -166,23 +167,47 @@ public class Retry {
   }
 
   public void logRetry(Logger log, String message, Throwable t) {
-    // log the first time, and then after every logInterval
-    if (lastRetryLog < 0 || (System.currentTimeMillis() - lastRetryLog) > logInterval)
{
+    // log the first time as debug, and then after every logInterval as a warning
+    long now = System.nanoTime();
+    if (lastRetryLog < 0) {
+      if (log.isDebugEnabled()) {
+        log.debug(getMessage(message, t));
+      }
+      lastRetryLog = now;
+    } else if ((now - lastRetryLog) > logIntervalNanoSec) {
       log.warn(getMessage(message), t);
-      lastRetryLog = System.currentTimeMillis();
+      lastRetryLog = now;
+    } else {
+      if (log.isTraceEnabled()) {
+        log.trace(getMessage(message, t));
+      }
     }
   }
 
   public void logRetry(Logger log, String message) {
-    // log the first time, and then after every logInterval
-    if (lastRetryLog < 0 || (System.currentTimeMillis() - lastRetryLog) > logInterval)
{
+    // log the first time as debug, and then after every logInterval as a warning
+    long now = System.nanoTime();
+    if (lastRetryLog < 0) {
+      if (log.isDebugEnabled()) {
+        log.debug(getMessage(message));
+      }
+      lastRetryLog = now;
+    } else if ((now - lastRetryLog) > logIntervalNanoSec) {
       log.warn(getMessage(message));
-      lastRetryLog = System.currentTimeMillis();
+      lastRetryLog = now;
+    } else {
+      if (log.isTraceEnabled()) {
+        log.trace(getMessage(message));
+      }
     }
   }
 
   private String getMessage(String message) {
-    return message + ", retrying attempt " + (retriesDone + 1) + " (suppressing retry messages
for " + logInterval + "ms)";
+    return message + ", retrying attempt " + (retriesDone + 1) + " (suppressing retry messages
for " + getLogInterval() + "ms)";
+  }
+
+  private String getMessage(String message, Throwable t) {
+    return message + ":" + t + ", retrying attempt " + (retriesDone + 1) + " (suppressing
retry messages for " + getLogInterval() + "ms)";
   }
 
 }
diff --git a/fate/src/test/java/org/apache/accumulo/fate/zookeeper/RetryTest.java b/fate/src/test/java/org/apache/accumulo/fate/zookeeper/RetryTest.java
index fddef47..bca4e97 100644
--- a/fate/src/test/java/org/apache/accumulo/fate/zookeeper/RetryTest.java
+++ b/fate/src/test/java/org/apache/accumulo/fate/zookeeper/RetryTest.java
@@ -152,8 +152,14 @@ public class RetryTest {
   @Test
   public void testLogging() {
     Logger testLogger = EasyMock.createMock(Logger.class);
+    EasyMock.expect(testLogger.isDebugEnabled()).andReturn(true);
+    testLogger.debug(EasyMock.anyObject(String.class));
+    EasyMock.expectLastCall().times(1);
+    EasyMock.expect(testLogger.isTraceEnabled()).andReturn(true).anyTimes();
+    testLogger.trace(EasyMock.anyObject(String.class));
+    EasyMock.expectLastCall().anyTimes();
     testLogger.warn(EasyMock.anyObject(String.class));
-    EasyMock.expectLastCall().times(4, 6);
+    EasyMock.expectLastCall().times(3, 5);
     EasyMock.replay(testLogger);
 
     // we want to do this for 5 second and observe the log messages
diff --git a/server/tserver/src/main/java/org/apache/accumulo/tserver/log/TabletServerLogger.java
b/server/tserver/src/main/java/org/apache/accumulo/tserver/log/TabletServerLogger.java
index 3843210..1b180a2 100644
--- a/server/tserver/src/main/java/org/apache/accumulo/tserver/log/TabletServerLogger.java
+++ b/server/tserver/src/main/java/org/apache/accumulo/tserver/log/TabletServerLogger.java
@@ -338,10 +338,9 @@ public class TabletServerLogger {
           success = (currentLogSet == logSetId.get());
         }
       } catch (DfsLogger.LogClosedException ex) {
-        writeRetry.logRetry(log, "Logs closed while writing");
+        writeRetry.logRetry(log, "Logs closed while writing", ex);
       } catch (Exception t) {
-        if (writeRetry.retriesCompleted() != 0)
-          writeRetry.logRetry(log, "Failed to write to WAL", t);
+        writeRetry.logRetry(log, "Failed to write to WAL", t);
 
         try {
           // Backoff

-- 
To stop receiving notification emails like this one, please contact
ibella@apache.org.

Mime
View raw message