Permalink
Browse files

Less verbose logging in the face of expected exceptions and error log…

…ging in the face of a slop not being written.

src/java/voldemort/cluster/failuredetector/AbstractFailureDetector.java
- less verbose logging when a node is unavailable

src/java/voldemort/store/routed/action/AbstractAction.java
- less verbose logging in the face of expected "exceptional" responses.

src/java/voldemort/store/slop/HintedHandoff.java
- ensure that an error message is logged if a slop is not written (we can grep for "Slop write of key.*was not written" in logs)
- added TODO because ObsoleteVersionExceptiosn are neither treated as failures or successes in the callback to sendHintParallel.

test/integration/voldemort/nonblocking/E2ENonblockingCheckoutTest.java
- minor fix

test/unit/voldemort/server/socket/ClientRequestExecutorPoolTest.java
- from junit3 to junit4
  • Loading branch information...
1 parent e365419 commit 3aaabcc7595bb2b68b85fb2df4f5c4f2c6041eac @jayjwylie jayjwylie committed Nov 28, 2012
@@ -186,11 +186,11 @@ protected void setAvailable(Node node) {
protected void setUnavailable(Node node, UnreachableStoreException e) {
NodeStatus nodeStatus = getNodeStatus(node);
- if(logger.isEnabledFor(Level.WARN)) {
+ if(logger.isDebugEnabled()) {
if(e != null)
- logger.warn("Node " + node.getId() + " set as unavailable", e);
+ logger.debug("Node " + node.getId() + " set as unavailable", e);
else
- logger.warn("Node " + node.getId() + " set as unavailable");
+ logger.debug("Node " + node.getId() + " set as unavailable");
}
// We need to distinguish the case where we're newly unavailable and the
@@ -29,6 +29,7 @@
import voldemort.store.routed.PipelineData;
import voldemort.store.routed.Response;
import voldemort.utils.Utils;
+import voldemort.versioning.ObsoleteVersionException;
public abstract class AbstractAction<K, V, PD extends PipelineData<K, V>> implements Action {
@@ -58,13 +59,18 @@ protected boolean handleResponseError(Exception e,
long requestTime,
Pipeline pipeline,
FailureDetector failureDetector) {
- if(logger.isEnabledFor(Level.WARN)) {
- if(e instanceof StoreTimeoutException)
- logger.warn("Error in " + pipeline.getOperation().getSimpleName() + " on node "
- + node.getId() + "(" + node.getHost() + ") : " + e.getMessage());
- else
+ if(e instanceof StoreTimeoutException || e instanceof ObsoleteVersionException
+ || e instanceof UnreachableStoreException) {
+ // Quietly mask all errors that are "expected" regularly.
+ if(logger.isEnabledFor(Level.DEBUG)) {
+ logger.debug("Error in " + pipeline.getOperation().getSimpleName() + " on node "
+ + node.getId() + " (" + node.getHost() + ") : " + e.getMessage());
+ }
+ } else {
+ if(logger.isEnabledFor(Level.WARN)) {
logger.warn("Error in " + pipeline.getOperation().getSimpleName() + " on node "
- + node.getId() + "(" + node.getHost() + ")", e);
+ + node.getId() + " (" + node.getHost() + ")", e);
+ }
}
if(e instanceof UnreachableStoreException) {
@@ -27,10 +27,10 @@
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.Time;
import voldemort.utils.Utils;
@@ -67,7 +67,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 +90,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();
@@ -115,6 +119,7 @@ public void sendHintParallel(final Node failedNode, final Version version, final
+ " to node " + node);
NonblockingStoreCallback callback = new NonblockingStoreCallback() {
+
public void requestComplete(Object result, long requestTime) {
Response<ByteArray, Object> response = new Response<ByteArray, Object>(node,
slopKey,
@@ -123,22 +128,28 @@ public void requestComplete(Object result, long requestTime) {
if(response.getValue() instanceof Exception) {
if(response.getValue() instanceof ObsoleteVersionException) {
// Ignore
+
+ // TODO: Treating ObsoleteVersionException as
+ // "success", but there is no logger.debug to
+ // note that the slop was written, nor is there
+ // a failureDetector.recordSuccess invocation.
} else {
// Use the blocking approach
if(!failedNodes.contains(node))
failedNodes.add(node);
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 " + slop.getKey() + " 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);
@@ -157,16 +168,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}
@@ -215,12 +222,17 @@ 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
+ + System.identityHashCode(slop.getKey()) + ") for " + failedNode
+ " to node " + node + " succeeded in "
+ (System.nanoTime() - startNs) + " ns");
}
}
+ if(!persisted) {
+ logger.error("Slop write of key " + slop.getKey() + " (keyRef: "
+ + System.identityHashCode(slop.getKey()) + ") for " + failedNode
+ + " was not written.");
+ }
return persisted;
}
}
@@ -154,7 +154,7 @@ public void setUp() throws Exception {
+ InMemoryStorageConfiguration.class.getName() + ","
+ SlowStorageConfiguration.class.getName();
p.setProperty("storage.configs", storageConfigs);
- p.setProperty("slow.queueing.put.ms", Long.toString(SLOW_PUT_MS));
+ p.setProperty("testing.slow.queueing.put.ms", Long.toString(SLOW_PUT_MS));
p.setProperty("client.connection.timeout.ms", Integer.toString(CONNECTION_TIMEOUT_MS));
p.setProperty("client.routing.timeout.ms", Integer.toString(ROUTING_TIMEOUT_MS));
@@ -16,13 +16,14 @@
package voldemort.server.socket;
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
+
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
import java.util.List;
-import junit.framework.TestCase;
-
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
@@ -45,7 +46,7 @@
*
*/
@RunWith(Parameterized.class)
-public class ClientRequestExecutorPoolTest extends TestCase {
+public class ClientRequestExecutorPoolTest {
private int port;
private int maxConnectionsPerNode = 3;
@@ -64,7 +65,6 @@ public ClientRequestExecutorPoolTest(boolean useNio) {
return Arrays.asList(new Object[][] { { true }, { false } });
}
- @Override
@Before
public void setUp() {
this.port = ServerTestUtils.findFreePort();
@@ -88,7 +88,6 @@ public void setUp() {
this.server.start();
}
- @Override
@After
public void tearDown() {
this.pool.close();

0 comments on commit 3aaabcc

Please sign in to comment.