commit af5edf6047f2a730c5a9fbc6b08dad6edba21dab
author Hugo Arès <hugo.ares@ericsson.com> Tue Oct 13 14:48:27 2015 -0400
committer David Pursehouse <david.pursehouse@sonymobile.com> Wed Oct 14 12:24:36 2015 +0900
tree 15c5628c0c139d8e795136d1e07e6265fea62c06
parent 7a5a9f88dc3d63d28627ae98a316761466aaa27f

Add waiting time and number of retries to replication log

Only replication execution time was printed in the replication completed
log statement. Add the waiting time and retry count to help debug
replication delays.

Change-Id: I2a7ba5daaa9bd790c28d7d7e1da06f4d5841c686

src/main/java/com/googlesource/gerrit/plugins/replication/PushOne.java

diff --git a/src/main/java/com/googlesource/gerrit/plugins/replication/PushOne.java b/src/main/java/com/googlesource/gerrit/plugins/replication/PushOne.java
index 0614959..255c51b 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/replication/PushOne.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/replication/PushOne.java
@@ -14,13 +14,13 @@
 
 package com.googlesource.gerrit.plugins.replication;
 
-import com.google.common.base.Stopwatch;
 import com.google.common.base.Throwables;
 import com.google.common.collect.LinkedListMultimap;
 import com.google.common.collect.Lists;
 import com.google.common.collect.Maps;
 import com.google.common.collect.Multimap;
 import com.google.common.collect.Sets;
+import com.google.gerrit.common.TimeUtil;
 import com.google.gerrit.extensions.events.GitReferenceUpdatedListener;
 import com.google.gerrit.reviewdb.client.Project;
 import com.google.gerrit.reviewdb.client.RefNames;
@@ -70,7 +70,6 @@
 import java.util.Map;
 import java.util.Set;
 import java.util.concurrent.Callable;
-import java.util.concurrent.TimeUnit;
 
 /**
  * A push to remote operation started by {@link GitReferenceUpdatedListener}.
@@ -112,6 +111,7 @@
   private final int maxLockRetries;
   private int lockRetryCount;
   private final int id;
+  private final long createdAt;
 
   @Inject
   PushOne(final GitRepositoryManager grm,
@@ -140,6 +140,7 @@
     lockRetryCount = 0;
     maxLockRetries = pool.getLockErrorMaxRetries();
     id = ig.next();
+    createdAt = TimeUtil.nowMs();
   }
 
   @Override
@@ -279,13 +280,15 @@
       return;
     }
 
-    Stopwatch stopwatch = Stopwatch.createStarted();
+    long startedAt = TimeUtil.nowMs();
     repLog.info("Replication to " + uri + " started...");
     try {
       git = gitManager.openRepository(projectName);
       runImpl();
+      long finishedAt = TimeUtil.nowMs();
       repLog.info("Replication to " + uri + " completed in "
-          + stopwatch.elapsed(TimeUnit.MILLISECONDS) + " ms");
+          + (finishedAt - startedAt) + "ms, "
+          + (startedAt - createdAt) + "ms delay, " + retryCount + " retries");
     } catch (RepositoryNotFoundException e) {
       stateLog.error("Cannot replicate " + projectName
           + "; Local repository error: "