Added INFO level messages to better understand the performance of per…

…-request instrumentation. Expect to remove most of this after debugging.
ankurbaidya · Jan 15, 2013 · e29b222 · e29b222
1 parent 7b8d30c
commit e29b222
Show file tree

Hide file tree

Showing 2 changed files with 23 additions and 12 deletions.
diff --git a/src/java/voldemort/store/stats/RequestCounter.java b/src/java/voldemort/store/stats/RequestCounter.java
@@ -180,6 +180,10 @@ public void addRequest(long timeNS,
                            long numEmptyResponses,
                            long bytes,
                            long getAllAggregatedCount) {
+        // TODO: Remove this instrumentation
+        final long infoCutoffNs = 100 * 1000; // 100 us cut off for INFO display
+        long startTimeNs = System.nanoTime();
+
         long timeMs = timeNS / Time.NS_PER_MS;
         if(this.useHistogram) {
             histogram.insert(timeMs);
@@ -198,8 +202,15 @@ public void addRequest(long timeNS,
                                                oldv.getAllAggregatedCount + getAllAggregatedCount,
                                                getAllAggregatedCount > oldv.getAllMaxCount ? getAllAggregatedCount
                                                                                           : oldv.getAllMaxCount);
-            if(values.compareAndSet(oldv, newv))
+            if(values.compareAndSet(oldv, newv)) {
+                long durationNs = System.nanoTime() - startTimeNs;
+                if(durationNs > infoCutoffNs) {
+                    logger.info("addRequest (histogram.insert and accumulator update) took more than "
+                                + infoCutoffNs + " ns: " + durationNs + " ns.");
+                }
+
                 return;
+            }
         }
         // TODO: Make this DEBUG level
         logger.info("addRequest lost data because three retries was insufficient.");

diff --git a/src/java/voldemort/utils/pool/KeyedResourcePool.java b/src/java/voldemort/utils/pool/KeyedResourcePool.java
@@ -448,20 +448,20 @@ public <K> boolean attemptGrow(K key, ResourceFactory<K, V> objectFactory) throw
                         if(!nonBlockingPut(resource)) {
                             this.size.decrementAndGet();
                             objectFactory.destroy(key, resource);
-                            if (currentCreatesInFlight>0) {
-                            logger.info("attemptGrow established new connection for key "
-                                        + key.toString() + " with " + currentCreatesInFlight
-                                        + " other connection establishments in flight."
-                                        + " And then promptly destroyed the new connection.");
+                            if(currentCreatesInFlight > 0) {
+                                logger.info("attemptGrow established new connection for key "
+                                            + key.toString() + " with " + currentCreatesInFlight
+                                            + " other connection establishments in flight."
+                                            + " And then promptly destroyed the new connection.");
                             }
                             return false;
                         }
-                        if (currentCreatesInFlight>0) {
-                        logger.info("attemptGrow established new connection for key "
-                                    + key.toString() + " with " + currentCreatesInFlight
-                                    + " other connection establishments in flight."
-                                    + " After checking in to KeyedResourcePool, there are "
-                                    + queue.size() + " destinations checked in.");
+                        if(currentCreatesInFlight > 0) {
+                            logger.info("attemptGrow established new connection for key "
+                                        + key.toString() + " with " + currentCreatesInFlight
+                                        + " other connection establishments in flight."
+                                        + " After checking in to KeyedResourcePool, there are "
+                                        + queue.size() + " destinations checked in.");
                         }
                     }
                 } catch(Exception e) {