From 7ef135d27254e9db8616c25539675768ec17b660 Mon Sep 17 00:00:00 2001 From: Zhongjie Wu Date: Mon, 22 Apr 2013 16:52:35 -0700 Subject: [PATCH] additional logging --- .../UpdateSlopEntriesRequestHandler.java | 3 +- .../slop/StreamingSlopPusherJob.java | 3 +- .../action/PerformParallelPutRequests.java | 12 +++++++ .../voldemort/store/slop/HintedHandoff.java | 34 +++++++++++++++---- 4 files changed, 43 insertions(+), 9 deletions(-) diff --git a/src/java/voldemort/server/protocol/admin/UpdateSlopEntriesRequestHandler.java b/src/java/voldemort/server/protocol/admin/UpdateSlopEntriesRequestHandler.java index fc7fa45ba6..3b07d265c8 100644 --- a/src/java/voldemort/server/protocol/admin/UpdateSlopEntriesRequestHandler.java +++ b/src/java/voldemort/server/protocol/admin/UpdateSlopEntriesRequestHandler.java @@ -145,7 +145,8 @@ public StreamRequestHandlerState handleRequest(DataInputStream inputStream, streamStats.reportStorageTime(Operation.SLOP_UPDATE, System.nanoTime() - startNs); if(logger.isTraceEnabled()) - logger.trace("updateSlopEntries (Streaming put) successful"); + logger.trace("updateSlopEntries (Streaming put) successful on key:" + key + + " of store: " + request.getStore()); } catch(ObsoleteVersionException e) { // log and ignore if(logger.isDebugEnabled()) diff --git a/src/java/voldemort/server/scheduler/slop/StreamingSlopPusherJob.java b/src/java/voldemort/server/scheduler/slop/StreamingSlopPusherJob.java index b8cbd1804a..885d75fa97 100644 --- a/src/java/voldemort/server/scheduler/slop/StreamingSlopPusherJob.java +++ b/src/java/voldemort/server/scheduler/slop/StreamingSlopPusherJob.java @@ -196,7 +196,8 @@ public void run() { if(logger.isTraceEnabled()) logger.trace("Pushing slop for " + versioned.getValue().getNodeId() - + " and store " + versioned.getValue().getStoreName()); + + " and store " + versioned.getValue().getStoreName() + + " of key: " + versioned.getValue().getKey()); if(failureDetector.isAvailable(node)) { SynchronousQueue> slopQueue = slopQueues.get(nodeId); diff --git a/src/java/voldemort/store/routed/action/PerformParallelPutRequests.java b/src/java/voldemort/store/routed/action/PerformParallelPutRequests.java index 28711e84e6..07ee73f589 100644 --- a/src/java/voldemort/store/routed/action/PerformParallelPutRequests.java +++ b/src/java/voldemort/store/routed/action/PerformParallelPutRequests.java @@ -174,6 +174,18 @@ public void requestComplete(Object result, long requestTime) { + ")"); } } + } else { + if(logger.isDebugEnabled()) { + if(result instanceof Exception) { + logger.debug("PUT {key:" + + key + + "} will not send hint. Response is ignorable exception: " + + result.getClass().toString()); + } else { + logger.debug("PUT {key:" + key + + "} will not send hint. Response is normal"); + } + } } if(result instanceof Exception diff --git a/src/java/voldemort/store/slop/HintedHandoff.java b/src/java/voldemort/store/slop/HintedHandoff.java index d12a9a7556..12b477486c 100644 --- a/src/java/voldemort/store/slop/HintedHandoff.java +++ b/src/java/voldemort/store/slop/HintedHandoff.java @@ -16,6 +16,7 @@ package voldemort.store.slop; +import java.util.ArrayList; import java.util.List; import java.util.Map; @@ -99,17 +100,24 @@ public HintedHandoff(FailureDetector failureDetector, * voldemort.versioning.Version, Slop) */ public void sendHintParallel(final Node failedNode, final Version version, final Slop slop) { + boolean slopAsyncSent = false; final ByteArray slopKey = slop.makeKey(); Versioned slopVersioned = new Versioned(slopSerializer.toBytes(slop), version); - - for(final Node node: handoffStrategy.routeHint(failedNode)) { + List nodes = handoffStrategy.routeHint(failedNode); + if(logger.isTraceEnabled()) { + List nodeIds = new ArrayList(); + for(Node node: nodes) { + nodeIds.add(node.getId()); + } + logger.debug("Hint preference list: " + nodeIds.toString()); + } + for(final Node node: nodes) { int nodeId = node.getId(); - if(logger.isDebugEnabled()) - logger.debug("Sending an async hint to " + nodeId); - if(!failedNodes.contains(node) && failureDetector.isAvailable(node)) { + if(logger.isDebugEnabled()) + logger.debug("Sending an async hint to " + nodeId); NonblockingStore nonblockingStore = nonblockingSlopStores.get(nodeId); Utils.notNull(nonblockingStore); final long startNs = System.nanoTime(); @@ -170,9 +178,17 @@ public void requestComplete(Object result, long requestTime) { }; nonblockingStore.submitPutRequest(slopKey, slopVersioned, null, callback, timeoutMs); + slopAsyncSent = true; break; + } else { + if(logger.isDebugEnabled()) { + logger.debug("Skipping node " + nodeId); + } } } + if(logger.isDebugEnabled() && !slopAsyncSent) { + logger.warn("Skipped all nodes. Did not send hint for key: " + slop.getKey()); + } } /** @@ -189,10 +205,10 @@ public boolean sendHintSerial(Node failedNode, Version version, Slop slop) { boolean persisted = false; for(Node node: handoffStrategy.routeHint(failedNode)) { int nodeId = node.getId(); - if(logger.isDebugEnabled()) - logger.debug("Trying to send hint to " + nodeId + " for key " + slop.getKey()); if(!failedNodes.contains(node) && failureDetector.isAvailable(node)) { + if(logger.isDebugEnabled()) + logger.debug("Trying to send hint to " + nodeId + " for key " + slop.getKey()); Store slopStore = slopStores.get(nodeId); Utils.notNull(slopStore); long startNs = System.nanoTime(); @@ -230,6 +246,10 @@ public boolean sendHintSerial(Node failedNode, Version version, Slop slop) { + System.identityHashCode(slop.getKey()) + ") for " + failedNode + " to node " + node + (persisted ? " succeeded" : " failed") + " in " + (System.nanoTime() - startNs) + " ns"); + } else { + if(logger.isDebugEnabled()) { + logger.debug("Skipping node " + nodeId); + } } }