Skip to content
Browse files

Improving debug messages in request tracing

  • Loading branch information...
1 parent 2c6b61f commit 98643ea18481ebfbb0fe1a7575ae6157f84f939e @pbailis pbailis committed
View
11 src/java/voldemort/server/niosocket/AsyncRequestHandler.java
@@ -127,13 +127,16 @@ protected void read(SelectionKey selectionKey) throws IOException {
if(logger.isTraceEnabled())
logger.trace("Starting execution for " + socketChannel.socket());
- streamRequestHandler = requestHandler.handleRequest(new DataInputStream(inputStream),
- new DataOutputStream(outputStream));
+ DataInputStream dataInputStream = new DataInputStream(inputStream);
+ DataOutputStream dataOutputStream = new DataOutputStream(outputStream);
+
+ streamRequestHandler = requestHandler.handleRequest(dataInputStream,
+ dataOutputStream);
if(logger.isDebugEnabled()) {
logger.debug("AsyncRequestHandler:read finished request from "
+ socketChannel.socket().getRemoteSocketAddress() + " handlerRef: "
- + System.identityHashCode(streamRequestHandler) + " at time: "
+ + System.identityHashCode(dataInputStream) + " at time: "
+ System.currentTimeMillis() + " elapsed time: "
+ (System.nanoTime() - startNs) + " ns");
}
@@ -307,7 +310,7 @@ private StreamRequestHandlerState handleStreamRequestInternal(SelectionKey selec
if(logger.isDebugEnabled()) {
logger.debug("Handled request from "
+ socketChannel.socket().getRemoteSocketAddress() + " handlerRef: "
- + System.identityHashCode(streamRequestHandler) + " at time: "
+ + System.identityHashCode(dataInputStream) + " at time: "
+ System.currentTimeMillis() + " elapsed time: "
+ (System.nanoTime() - startNs) + " ns");
}
View
34 src/java/voldemort/server/protocol/vold/VoldemortNativeRequestHandler.java
@@ -135,7 +135,8 @@ private void handleGetVersion(DataInputStream inputStream,
if(logger.isDebugEnabled()) {
logger.debug("GETVERSIONS started at: " + startTimeMs + " handlerRef: "
- + System.identityHashCode(this) + " key: " + key + " "
+ + System.identityHashCode(inputStream) + " key: "
+ + ByteUtils.toHexString(key.get()) + " "
+ (System.nanoTime() - startTimeNs) + " ns, keySize: " + key.length()
+ "clocks: " + clockStr);
}
@@ -317,7 +318,7 @@ private void handleGet(DataInputStream inputStream,
}
writeResults(outputStream, results);
if(logger.isDebugEnabled()) {
- debugLogReturnValue(key, results, startTimeMs, startTimeNs, "GET");
+ debugLogReturnValue(inputStream, key, results, startTimeMs, startTimeNs, "GET");
}
}
@@ -374,7 +375,8 @@ private void handleGetAll(DataInputStream inputStream,
writeResults(outputStream, entry.getValue());
if(logger.isDebugEnabled()) {
- debugLogReturnValue(entry.getKey(),
+ debugLogReturnValue(inputStream,
+ entry.getKey(),
entry.getValue(),
startTimeMs,
startTimeNs,
@@ -386,7 +388,8 @@ private void handleGetAll(DataInputStream inputStream,
logger.debug("GETALL end");
}
- private void debugLogReturnValue(ByteArray key,
+ private void debugLogReturnValue(DataInputStream input,
+ ByteArray key,
List<Versioned<byte[]>> values,
long startTimeMs,
long startTimeNs,
@@ -406,12 +409,13 @@ private void debugLogReturnValue(ByteArray key,
valueHashStr += "]";
versionsStr += "]";
- logger.debug(getType + " handlerRef: " + System.identityHashCode(this) + " start time: "
- + startTimeMs + " key: " + key + " elapsed time: "
- + (System.nanoTime() - startTimeNs) + " ns, keySize: " + key.length()
- + " numResults: " + values.size() + " totalResultSize: " + totalValueSize
- + " resultSizes: " + valueSizeStr + " resultHashes: " + valueHashStr
- + " versions: " + versionsStr + " current time: " + System.currentTimeMillis());
+ logger.debug(getType + " handlerRef: " + System.identityHashCode(input) + " start time: "
+ + startTimeMs + " key: " + ByteUtils.toHexString(key.get())
+ + " elapsed time: " + (System.nanoTime() - startTimeNs) + " ns, keySize: "
+ + key.length() + " numResults: " + values.size() + " totalResultSize: "
+ + totalValueSize + " resultSizes: " + valueSizeStr + " resultHashes: "
+ + valueHashStr + " versions: " + versionsStr + " current time: "
+ + System.currentTimeMillis());
}
private void handlePut(DataInputStream inputStream,
@@ -447,9 +451,10 @@ private void handlePut(DataInputStream inputStream,
if(logger.isDebugEnabled()) {
logger.debug("PUT started at: " + startTimeMs + " handlerRef: "
- + System.identityHashCode(this) + " key: " + key + " "
+ + System.identityHashCode(inputStream) + " key: "
+ + ByteUtils.toHexString(key.get()) + " "
+ (System.nanoTime() - startTimeNs) + " ns, keySize: " + key.length()
- + " valueHash: " + value.hashCode() + " valueSize: " + valueSize
+ + " valueHash: " + value.hashCode() + " valueSize: " + value.length
+ " clockSize: " + clock.sizeInBytes() + " time: "
+ System.currentTimeMillis());
}
@@ -480,8 +485,9 @@ private void handleDelete(DataInputStream inputStream,
}
if(logger.isDebugEnabled()) {
- logger.debug("DELETE started at: " + startTimeMs + " key: " + key + " handlerRef: "
- + System.identityHashCode(this) + " time: "
+ logger.debug("DELETE started at: " + startTimeMs + " key: "
+ + ByteUtils.toHexString(key.get()) + " handlerRef: "
+ + System.identityHashCode(inputStream) + " time: "
+ (System.nanoTime() - startTimeNs) + " ns, keySize: " + key.length()
+ " clockSize: " + version.sizeInBytes());
}
View
10 src/java/voldemort/store/bdb/BdbStorageEngine.java
@@ -281,7 +281,7 @@ private Database getBdbDatabase() {
for(ByteArray key: keys) {
if(logger.isTraceEnabled())
- keyStr += key + " ";
+ keyStr += ByteUtils.toHexString(key.get()) + " ";
List<Versioned<byte[]>> values = get(cursor, key, readLockMode, versionedSerializer);
if(!values.isEmpty())
@@ -324,7 +324,7 @@ private Database getBdbDatabase() {
}
if(logger.isTraceEnabled()) {
- logger.trace("Completed GET from key " + key + " in "
+ logger.trace("Completed GET from key " + ByteUtils.toHexString(key.get()) + " in "
+ (System.nanoTime() - startTimeNs) + " ns at "
+ System.currentTimeMillis());
}
@@ -390,7 +390,7 @@ else if(occurred == Occurred.AFTER)
}
if(logger.isTraceEnabled()) {
- logger.trace("Completed PUT to key " + key + " (keyRef: "
+ logger.trace("Completed PUT to key " + ByteUtils.toHexString(key.get()) + " (keyRef: "
+ System.identityHashCode(key) + " value " + value + " in "
+ (System.nanoTime() - startTimeNs) + " ns at "
+ System.currentTimeMillis());
@@ -431,8 +431,8 @@ public boolean delete(ByteArray key, Version version) throws PersistenceFailureE
} finally {
if(logger.isTraceEnabled()) {
- logger.trace("Completed DELETE of key " + key + " (keyRef: "
- + System.identityHashCode(key) + ") in "
+ logger.trace("Completed DELETE of key " + ByteUtils.toHexString(key.get())
+ + " (keyRef: " + System.identityHashCode(key) + ") in "
+ (System.nanoTime() - startTimeNs) + " ns at "
+ System.currentTimeMillis());
}
View
45 src/java/voldemort/store/routed/PipelineRoutedStore.java
@@ -251,9 +251,10 @@ public PipelineRoutedStore(String name,
}
if(logger.isDebugEnabled()) {
- logger.debug("Finished " + pipeline.getOperation().getSimpleName() + " for key " + key
- + " keyRef: " + System.identityHashCode(key) + "; started at "
- + startTimeMs + " took " + (System.nanoTime() - startTimeNs) + " values: "
+ logger.debug("Finished " + pipeline.getOperation().getSimpleName() + " for key "
+ + ByteUtils.toHexString(key.get()) + " keyRef: "
+ + System.identityHashCode(key) + "; started at " + startTimeMs + " took "
+ + (System.nanoTime() - startTimeNs) + " values: "
+ formatNodeValuesFromGet(pipelineData.getResponses()));
}
@@ -355,9 +356,10 @@ private String formatNodeValuesFromGet(List<Response<ByteArray, List<Versioned<b
throw pipelineData.getFatalError();
if(logger.isDebugEnabled()) {
- logger.debug("Finished " + pipeline.getOperation().getSimpleName() + "for keys " + keys
- + " keyRef: " + System.identityHashCode(keys) + "; started at "
- + startTimeMs + " took " + (System.nanoTime() - startTimeNs) + " values: "
+ logger.debug("Finished " + pipeline.getOperation().getSimpleName() + "for keys "
+ + ByteArray.toHexStrings(keys) + " keyRef: "
+ + System.identityHashCode(keys) + "; started at " + startTimeMs + " took "
+ + (System.nanoTime() - startTimeNs) + " values: "
+ formatNodeValuesFromGetAll(pipelineData.getResponses()));
}
@@ -369,8 +371,9 @@ private String formatNodeValuesFromGetAll(List<Response<Iterable<ByteArray>, Map
StringBuilder builder = new StringBuilder();
builder.append("{");
for(Response<Iterable<ByteArray>, Map<ByteArray, List<Versioned<byte[]>>>> r: list) {
- builder.append("(nodeId=" + r.getNode().getId() + ", key=" + r.getKey()
- + ", retrieved= " + r.getValue() + ")");
+ builder.append("(nodeId=" + r.getNode().getId() + ", keys="
+ + ByteArray.toHexStrings(r.getKey()) + ", retrieved= " + r.getValue()
+ + ")");
builder.append(", ");
}
builder.append("}");
@@ -469,9 +472,10 @@ private String formatNodeValuesFromGetAll(List<Response<Iterable<ByteArray>, Map
results.addAll(response.getValue());
if(logger.isDebugEnabled()) {
- logger.debug("Finished " + pipeline.getOperation().getSimpleName() + " for key " + key
- + " keyRef: " + System.identityHashCode(key) + "; started at "
- + startTimeMs + " took " + (System.nanoTime() - startTimeNs) + " values: "
+ logger.debug("Finished " + pipeline.getOperation().getSimpleName() + " for key "
+ + ByteUtils.toHexString(key.get()) + " keyRef: "
+ + System.identityHashCode(key) + "; started at " + startTimeMs + " took "
+ + (System.nanoTime() - startTimeNs) + " values: "
+ formatNodeValuesFromGetVersions(pipelineData.getResponses()));
}
@@ -483,8 +487,9 @@ private String formatNodeValuesFromGetAll(List<Response<Iterable<ByteArray>, Map
StringBuilder builder = new StringBuilder();
builder.append("{");
for(Response<ByteArray, List<Version>> r: results) {
- builder.append("(nodeId=" + r.getNode().getId() + ", key=" + r.getKey()
- + ", retrieved= " + r.getValue() + "), ");
+ builder.append("(nodeId=" + r.getNode().getId() + ", key="
+ + ByteUtils.toHexString(r.getKey().get()) + ", retrieved= "
+ + r.getValue() + "), ");
}
builder.append("}");
@@ -575,8 +580,9 @@ public boolean delete(final ByteArray key, final Version version) throws Voldemo
if(logger.isDebugEnabled()) {
logger.debug("Finished " + pipeline.getOperation().getSimpleName() + " for key "
- + key.get() + " keyRef: " + System.identityHashCode(key) + "; started at "
- + startTimeMs + " took " + (System.nanoTime() - startTimeNs));
+ + ByteUtils.toHexString(key.get()) + " keyRef: "
+ + System.identityHashCode(key) + "; started at " + startTimeMs + " took "
+ + (System.nanoTime() - startTimeNs));
}
if(pipelineData.getFatalError() != null)
@@ -700,10 +706,11 @@ public void put(ByteArray key, Versioned<byte[]> versioned, byte[] transforms)
}
if(logger.isDebugEnabled()) {
- logger.debug("Finished " + pipeline.getOperation().getSimpleName() + " for key " + key
- + " keyRef: " + System.identityHashCode(key) + "; started at "
- + startTimeMs + " took " + (System.nanoTime() - startTimeNs) + " value: "
- + versioned.getValue() + " (size: " + versioned.getValue().length + ")");
+ logger.debug("Finished " + pipeline.getOperation().getSimpleName() + " for key "
+ + ByteUtils.toHexString(key.get()) + " keyRef: "
+ + System.identityHashCode(key) + "; started at " + startTimeMs + " took "
+ + (System.nanoTime() - startTimeNs) + " value: " + versioned.getValue()
+ + " (size: " + versioned.getValue().length + ")");
}
if(pipelineData.getFatalError() != null)
View
11 src/java/voldemort/store/routed/action/AbstractReadRepair.java
@@ -24,10 +24,11 @@
import voldemort.store.nonblockingstore.NonblockingStore;
import voldemort.store.routed.NodeValue;
import voldemort.store.routed.Pipeline;
+import voldemort.store.routed.Pipeline.Event;
import voldemort.store.routed.PipelineData;
import voldemort.store.routed.ReadRepairer;
-import voldemort.store.routed.Pipeline.Event;
import voldemort.utils.ByteArray;
+import voldemort.utils.ByteUtils;
import voldemort.versioning.VectorClock;
import voldemort.versioning.Versioned;
@@ -101,7 +102,8 @@ public void execute(Pipeline pipeline) {
try {
if(logger.isDebugEnabled())
logger.debug("Doing read repair on node " + v.getNodeId() + " for key '"
- + v.getKey() + "' with version " + v.getVersion() + ".");
+ + ByteUtils.toHexString(v.getKey().get()) + "' with version "
+ + v.getVersion() + ".");
NonblockingStore store = nonblockingStores.get(v.getNodeId());
store.submitPutRequest(v.getKey(), v.getVersioned(), null, null, timeoutMs);
@@ -110,8 +112,9 @@ public void execute(Pipeline pipeline) {
logger.debug("Read repair cancelled due to application level exception on node "
+ v.getNodeId()
+ " for key '"
- + v.getKey()
- + "' with version " + v.getVersion() + ": " + e.getMessage());
+ + ByteUtils.toHexString(v.getKey().get())
+ + "' with version "
+ + v.getVersion() + ": " + e.getMessage());
} catch(Exception e) {
logger.debug("Read repair failed: ", e);
}
View
6 src/java/voldemort/store/routed/action/PerformParallelDeleteRequests.java
@@ -93,9 +93,9 @@ public void execute(final Pipeline pipeline) {
public void requestComplete(Object result, long requestTime) {
if(logger.isTraceEnabled())
- logger.info(pipeline.getOperation().getSimpleName()
- + " response received (" + requestTime + " ms.) from node "
- + node.getId());
+ logger.trace(pipeline.getOperation().getSimpleName()
+ + " response received (" + requestTime + " ms.) from node "
+ + node.getId());
Response<ByteArray, Object> response = new Response<ByteArray, Object>(node,
key,
View
4 src/java/voldemort/store/routed/action/PerformParallelPutRequests.java
@@ -42,6 +42,7 @@
import voldemort.store.slop.HintedHandoff;
import voldemort.store.slop.Slop;
import voldemort.utils.ByteArray;
+import voldemort.utils.ByteUtils;
import voldemort.utils.Time;
import voldemort.versioning.ObsoleteVersionException;
import voldemort.versioning.Versioned;
@@ -130,7 +131,8 @@ public void requestComplete(Object result, long requestTime) {
responses.put(node.getId(), response);
if(logger.isDebugEnabled())
- logger.debug("Finished secondary PUT for key " + key + " (keyRef: "
+ logger.debug("Finished secondary PUT for key "
+ + ByteUtils.toHexString(key.get()) + " (keyRef: "
+ System.identityHashCode(key) + "); took " + requestTime
+ " ms on node " + node.getId() + "(" + node.getHost() + ")");
View
16 src/java/voldemort/store/routed/action/PerformParallelRequests.java
@@ -38,6 +38,7 @@
import voldemort.store.routed.Pipeline.Operation;
import voldemort.store.routed.Response;
import voldemort.utils.ByteArray;
+import voldemort.utils.ByteUtils;
import voldemort.utils.Utils;
public class PerformParallelRequests<V, PD extends BasicPipelineData<V>> extends
@@ -111,10 +112,10 @@ public void requestComplete(Object result, long requestTime) {
requestTime);
if(logger.isDebugEnabled())
logger.debug("Finished " + pipeline.getOperation().getSimpleName()
- + " for key " + key + " (keyRef: "
- + System.identityHashCode(key) + "); started at " + startMs
- + " took " + requestTime + " ms on node " + node.getId() + "("
- + node.getHost() + ")");
+ + " for key " + ByteUtils.toHexString(key.get())
+ + " (keyRef: " + System.identityHashCode(key)
+ + "); started at " + startMs + " took " + requestTime
+ + " ms on node " + node.getId() + "(" + node.getHost() + ")");
responses.put(node.getId(), response);
latch.countDown();
@@ -174,9 +175,10 @@ else if(pipeline.getOperation() == Operation.GET_VERSIONS)
}
if(logger.isDebugEnabled())
- logger.debug("GET for key " + key + " (keyRef: " + System.identityHashCode(key)
- + "); successes: " + pipelineData.getSuccesses() + " preferred: "
- + preferred + " required: " + required);
+ logger.debug("GET for key " + ByteUtils.toHexString(key.get()) + " (keyRef: "
+ + System.identityHashCode(key) + "); successes: "
+ + pipelineData.getSuccesses() + " preferred: " + preferred + " required: "
+ + required);
if(pipelineData.getSuccesses() < required) {
if(insufficientSuccessesEvent != null) {
View
19 src/java/voldemort/store/routed/action/PerformSerialGetAllRequests.java
@@ -79,10 +79,11 @@ public void execute(Pipeline pipeline) {
boolean zoneRequirement = false;
MutableInt successCount = pipelineData.getSuccessCount(key);
- if(logger.isDebugEnabled())
- logger.debug("GETALL for key " + key + " (keyRef: " + System.identityHashCode(key)
- + ") successes: " + successCount.intValue() + " preferred: " + preferred
- + " required: " + required);
+ if(logger.isDebugEnabled())
+ logger.debug("GETALL for key " + ByteUtils.toHexString(key.get()) + " (keyRef: "
+ + System.identityHashCode(key) + ") successes: "
+ + successCount.intValue() + " preferred: " + preferred + " required: "
+ + required);
if(successCount.intValue() >= preferred) {
if(pipelineData.getZonesRequired() != null) {
@@ -138,11 +139,11 @@ public void execute(Pipeline pipeline) {
failureDetector.recordSuccess(response.getNode(), response.getRequestTime());
if(logger.isDebugEnabled())
- logger.debug("GET for key " + key + " (keyRef: "
- + System.identityHashCode(key) + ") successes: "
- + successCount.intValue() + " preferred: " + preferred
- + " required: " + required + " new GET success on node "
- + node.getId());
+ logger.debug("GET for key " + ByteUtils.toHexString(key.get())
+ + " (keyRef: " + System.identityHashCode(key)
+ + ") successes: " + successCount.intValue() + " preferred: "
+ + preferred + " required: " + required
+ + " new GET success on node " + node.getId());
HashSet<Integer> zoneResponses = null;
if(pipelineData.getKeyToZoneResponse().containsKey(key)) {
View
12 src/java/voldemort/store/routed/action/PerformSerialPutRequests.java
@@ -29,6 +29,7 @@
import voldemort.store.routed.Pipeline.Event;
import voldemort.store.routed.PutPipelineData;
import voldemort.utils.ByteArray;
+import voldemort.utils.ByteUtils;
import voldemort.utils.Time;
import voldemort.versioning.VectorClock;
import voldemort.versioning.Versioned;
@@ -173,7 +174,8 @@ public void execute(Pipeline pipeline) {
} else {
if(logger.isDebugEnabled())
- logger.debug("Finished master PUT for key " + key + " (keyRef: "
+ logger.debug("Finished master PUT for key "
+ + ByteUtils.toHexString(key.get()) + " (keyRef: "
+ System.identityHashCode(key) + "); started at "
+ startMasterMs + " took "
+ (System.nanoTime() - startMasterNs) + " ns on node "
@@ -185,10 +187,10 @@ public void execute(Pipeline pipeline) {
}
} else {
if(logger.isDebugEnabled())
- logger.debug("Finished master PUT for key " + key + " (keyRef: "
- + System.identityHashCode(key) + "); started at " + startMasterMs
- + " took " + (System.nanoTime() - startMasterNs) + " ns on node "
- + (node == null ? "NULL" : node.getId()) + "("
+ logger.debug("Finished master PUT for key " + ByteUtils.toHexString(key.get())
+ + " (keyRef: " + System.identityHashCode(key) + "); started at "
+ + startMasterMs + " took " + (System.nanoTime() - startMasterNs)
+ + " ns on node " + (node == null ? "NULL" : node.getId()) + "("
+ (node == null ? "NULL" : node.getHost()) + ")");
pipeline.addEvent(masterDeterminedEvent);
View
8 src/java/voldemort/store/routed/action/PerformSerialRequests.java
@@ -31,6 +31,7 @@
import voldemort.store.routed.Pipeline.Event;
import voldemort.store.routed.Response;
import voldemort.utils.ByteArray;
+import voldemort.utils.ByteUtils;
import voldemort.utils.Time;
public class PerformSerialRequests<V, PD extends BasicPipelineData<V>> extends
@@ -99,9 +100,10 @@ public void execute(Pipeline pipeline) {
((System.nanoTime() - start) / Time.NS_PER_MS));
if(logger.isDebugEnabled())
- logger.debug(pipeline.getOperation().getSimpleName() + " for key " + key
- + " successes: " + pipelineData.getSuccesses() + " preferred: "
- + preferred + " required: " + required + " new "
+ logger.debug(pipeline.getOperation().getSimpleName() + " for key "
+ + ByteUtils.toHexString(key.get()) + " successes: "
+ + pipelineData.getSuccesses() + " preferred: " + preferred
+ + " required: " + required + " new "
+ pipeline.getOperation().getSimpleName() + " success on node "
+ node.getId());
View
60 src/java/voldemort/store/slop/HintedHandoff.java
@@ -27,11 +27,12 @@
import voldemort.serialization.SlopSerializer;
import voldemort.store.Store;
import voldemort.store.UnreachableStoreException;
-import voldemort.store.slop.strategy.HintedHandoffStrategy;
import voldemort.store.nonblockingstore.NonblockingStore;
import voldemort.store.nonblockingstore.NonblockingStoreCallback;
import voldemort.store.routed.Response;
+import voldemort.store.slop.strategy.HintedHandoffStrategy;
import voldemort.utils.ByteArray;
+import voldemort.utils.ByteUtils;
import voldemort.utils.Time;
import voldemort.utils.Utils;
import voldemort.versioning.ObsoleteVersionException;
@@ -67,7 +68,8 @@
* Create a Hinted Handoff object
*
* @param failureDetector The failure detector
- * @param nonblockingSlopStores A map of node ids to nonb-locking slop stores
+ * @param nonblockingSlopStores A map of node ids to nonb-locking slop
+ * stores
* @param slopStores A map of node ids to blocking slop stores
* @param handoffStrategy The {@link HintedHandoffStrategy} implementation
* @param failedNodes A list of nodes in the original preflist for the
@@ -89,15 +91,18 @@ public HintedHandoff(FailureDetector failureDetector,
}
/**
- * Like {@link #sendHintSerial(voldemort.cluster.Node, voldemort.versioning.Version, Slop)},
- * but doesn't block the pipeline. Intended for handling prolonged failures without
- * incurring a performance cost.
- *
- * @see #sendHintSerial(voldemort.cluster.Node, voldemort.versioning.Version, Slop)
+ * Like
+ * {@link #sendHintSerial(voldemort.cluster.Node, voldemort.versioning.Version, Slop)}
+ * , but doesn't block the pipeline. Intended for handling prolonged
+ * failures without incurring a performance cost.
+ *
+ * @see #sendHintSerial(voldemort.cluster.Node,
+ * voldemort.versioning.Version, Slop)
*/
public void sendHintParallel(final Node failedNode, final Version version, final Slop slop) {
final ByteArray slopKey = slop.makeKey();
- Versioned<byte[]> slopVersioned = new Versioned<byte[]>(slopSerializer.toBytes(slop), version);
+ Versioned<byte[]> slopVersioned = new Versioned<byte[]>(slopSerializer.toBytes(slop),
+ version);
for(final Node node: handoffStrategy.routeHint(failedNode)) {
int nodeId = node.getId();
@@ -111,10 +116,12 @@ public void sendHintParallel(final Node failedNode, final Version version, final
final long startNs = System.nanoTime();
if(logger.isDebugEnabled())
- logger.debug("Slop attempt to write " + slop.getKey() + " for " + failedNode
- + " to node " + node);
+ logger.debug("Slop attempt to write "
+ + ByteUtils.toHexString(slop.getKey().get()) + " for "
+ + failedNode + " to node " + node);
NonblockingStoreCallback callback = new NonblockingStoreCallback() {
+
public void requestComplete(Object result, long requestTime) {
Response<ByteArray, Object> response = new Response<ByteArray, Object>(node,
slopKey,
@@ -130,15 +137,16 @@ public void requestComplete(Object result, long requestTime) {
if(response.getValue() instanceof UnreachableStoreException) {
UnreachableStoreException use = (UnreachableStoreException) response.getValue();
- if(logger.isDebugEnabled())
- logger.debug("Write of key " + slop.getKey() + " for "
- + failedNode + " to node " + node
- + " failed due to unreachable: "
- + use.getMessage());
+ if(logger.isDebugEnabled())
+ logger.debug("Write of key "
+ + ByteUtils.toHexString(slop.getKey().get())
+ + " for " + failedNode + " to node " + node
+ + " failed due to unreachable: "
+ + use.getMessage());
failureDetector.recordException(node,
(System.nanoTime() - startNs)
- / Time.NS_PER_MS,
+ / Time.NS_PER_MS,
use);
}
sendHintSerial(failedNode, version, slop);
@@ -147,7 +155,8 @@ public void requestComplete(Object result, long requestTime) {
}
if(logger.isDebugEnabled())
- logger.debug("Slop write of key " + slop.getKey() + " for "
+ logger.debug("Slop write of key "
+ + ByteUtils.toHexString(slop.getKey().get()) + " for "
+ failedNode + " to node " + node + " succeeded in "
+ (System.nanoTime() - startNs) + " ns");
@@ -157,16 +166,12 @@ public void requestComplete(Object result, long requestTime) {
}
};
- nonblockingStore.submitPutRequest(slopKey,
- slopVersioned,
- null,
- callback,
- timeoutMs);
+ nonblockingStore.submitPutRequest(slopKey, slopVersioned, null, callback, timeoutMs);
break;
}
}
}
-
+
/**
* Send a hint of a request originally meant for the failed node to another
* node in the ring, as selected by the {@link HintedHandoffStrategy}
@@ -191,7 +196,8 @@ public boolean sendHintSerial(Node failedNode, Version version, Slop slop) {
try {
if(logger.isDebugEnabled())
- logger.debug("Slop attempt to write " + slop.getKey() + " (keyRef: "
+ logger.debug("Slop attempt to write "
+ + ByteUtils.toHexString(slop.getKey().get()) + " (keyRef: "
+ System.identityHashCode(slop.getKey()) + ") for "
+ failedNode + " to node " + node);
@@ -214,9 +220,9 @@ public boolean sendHintSerial(Node failedNode, Version version, Slop slop) {
}
if(logger.isDebugEnabled())
- logger.debug("Slop write of key " + slop.getKey() + " (keyRef: "
- + System.identityHashCode(slop.getKey()) + " for " + failedNode
- + " to node " + node + " succeeded in "
+ logger.debug("Slop write of key " + ByteUtils.toHexString(slop.getKey().get())
+ + " (keyRef: " + System.identityHashCode(slop.getKey()) + " for "
+ + failedNode + " to node " + node + " succeeded in "
+ (System.nanoTime() - startNs) + " ns");
}
}
View
14 src/java/voldemort/utils/ByteArray.java
@@ -1,6 +1,7 @@
package voldemort.utils;
import java.io.Serializable;
+import java.util.ArrayList;
import java.util.Arrays;
/**
@@ -43,6 +44,19 @@ public String toString() {
return Arrays.toString(underlying);
}
+ /**
+ * Translate the each ByteArray in an iterable into a hexidecimal string
+ *
+ * @param arrays The array of bytes to translate
+ * @return An iterable of converted strings
+ */
+ public static Iterable<String> toHexStrings(Iterable<ByteArray> arrays) {
+ ArrayList<String> ret = new ArrayList<String>();
+ for(ByteArray array: arrays)
+ ret.add(ByteUtils.toHexString(array.get()));
+ return ret;
+ }
+
public int length() {
return underlying.length;
}

0 comments on commit 98643ea

Please sign in to comment.
Something went wrong with that request. Please try again.