You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@tinkerpop.apache.org by sp...@apache.org on 2016/02/13 13:30:52 UTC
[05/37] incubator-tinkerpop git commit: Improved messaging from
gremlin server around timeouts.
Improved messaging from gremlin server around timeouts.
There are multiple timeouts configurable in gremlin server and it wasn't always clear which was triggering given the error messages that were being generated. Improved the clarity in server-side logging and in the messages returned to the client.
Project: http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/commit/89e159b8
Tree: http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/tree/89e159b8
Diff: http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/diff/89e159b8
Branch: refs/heads/master
Commit: 89e159b8bf9d4d6bcf6fc392dceb6c7eba33cf51
Parents: a3e2a98
Author: Stephen Mallette <sp...@genoprime.com>
Authored: Mon Feb 8 16:09:51 2016 -0500
Committer: Stephen Mallette <sp...@genoprime.com>
Committed: Mon Feb 8 16:09:51 2016 -0500
----------------------------------------------------------------------
.../gremlin/groovy/engine/GremlinExecutor.java | 2 +-
.../TimedInterruptCustomizerProvider.java | 1 +
.../TimedInterruptTimeoutException.java | 34 ++++++++++++
.../groovy/engine/GremlinExecutorTest.java | 3 +-
...linGroovyScriptEngineTimedInterruptTest.java | 7 +--
.../server/op/AbstractEvalOpProcessor.java | 12 +++--
.../server/GremlinServerIntegrateTest.java | 57 ++++++++++++++++----
7 files changed, 99 insertions(+), 17 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/blob/89e159b8/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutor.java
----------------------------------------------------------------------
diff --git a/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutor.java b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutor.java
index 49e2ac7..2e678f8 100644
--- a/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutor.java
+++ b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutor.java
@@ -277,7 +277,7 @@ public class GremlinExecutor implements AutoCloseable {
// check for that situation and convert to TimeoutException
if (root instanceof InterruptedException)
evaluationFuture.completeExceptionally(new TimeoutException(
- String.format("Script evaluation exceeded the configured threshold of %s ms for request [%s]: %s", scriptEvaluationTimeout, script, root.getMessage())));
+ String.format("Script evaluation exceeded the configured 'scriptEvaluationTimeout' threshold of %s ms for request [%s]: %s", scriptEvaluationTimeout, script, root.getMessage())));
else {
lifeCycle.getAfterFailure().orElse(afterFailure).accept(bindings, root);
evaluationFuture.completeExceptionally(root);
http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/blob/89e159b8/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptCustomizerProvider.java
----------------------------------------------------------------------
diff --git a/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptCustomizerProvider.java b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptCustomizerProvider.java
index 1a85b2d..e4bdc62 100644
--- a/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptCustomizerProvider.java
+++ b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptCustomizerProvider.java
@@ -57,6 +57,7 @@ public class TimedInterruptCustomizerProvider implements CompilerCustomizerProvi
timedInterruptAnnotationParams.put("value", interruptionTimeout);
timedInterruptAnnotationParams.put("unit", GeneralUtils.propX(GeneralUtils.classX(TimeUnit.class), TimeUnit.MILLISECONDS.toString()));
timedInterruptAnnotationParams.put("checkOnMethodStart", false);
+ timedInterruptAnnotationParams.put("thrown", GeneralUtils.classX(TimedInterruptTimeoutException.class));
return new ASTTransformationCustomizer(timedInterruptAnnotationParams, TimedInterrupt.class);
}
}
http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/blob/89e159b8/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptTimeoutException.java
----------------------------------------------------------------------
diff --git a/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptTimeoutException.java b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptTimeoutException.java
new file mode 100644
index 0000000..40abd59
--- /dev/null
+++ b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/customizer/TimedInterruptTimeoutException.java
@@ -0,0 +1,34 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.tinkerpop.gremlin.groovy.jsr223.customizer;
+
+import java.util.concurrent.TimeoutException;
+
+/**
+ * An exception thrown from the {@link TimedInterruptCustomizerProvider} when the timeout is exceeded. This exception
+ * allows differentiation from other "timeout exceptions" that might occur.
+ */
+public class TimedInterruptTimeoutException extends TimeoutException {
+ public TimedInterruptTimeoutException() {
+ }
+
+ public TimedInterruptTimeoutException(final String message) {
+ super(message);
+ }
+}
http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/blob/89e159b8/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutorTest.java
----------------------------------------------------------------------
diff --git a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutorTest.java b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutorTest.java
index fcab563..3f346e7 100644
--- a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutorTest.java
+++ b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/engine/GremlinExecutorTest.java
@@ -22,6 +22,7 @@ import org.apache.commons.lang3.concurrent.BasicThreadFactory;
import org.apache.tinkerpop.gremlin.TestHelper;
import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.ThreadInterruptCustomizerProvider;
import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.TimedInterruptCustomizerProvider;
+import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.TimedInterruptTimeoutException;
import org.javatuples.Pair;
import org.javatuples.Triplet;
import org.junit.Test;
@@ -501,7 +502,7 @@ public class GremlinExecutorTest {
gremlinExecutor.eval("s = System.currentTimeMillis();\nwhile((System.currentTimeMillis() - s) < 10000) {}").get();
fail("This should have timed out");
} catch (Exception se) {
- assertEquals(TimeoutException.class, se.getCause().getClass());
+ assertEquals(TimedInterruptTimeoutException.class, se.getCause().getClass());
}
// this script takes significantly less than the interruptionTimeout
http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/blob/89e159b8/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTimedInterruptTest.java
----------------------------------------------------------------------
diff --git a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTimedInterruptTest.java b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTimedInterruptTest.java
index 18fcbd6..c465732 100644
--- a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTimedInterruptTest.java
+++ b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTimedInterruptTest.java
@@ -20,6 +20,7 @@ package org.apache.tinkerpop.gremlin.groovy.jsr223;
import org.apache.tinkerpop.gremlin.groovy.DefaultImportCustomizerProvider;
import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.TimedInterruptCustomizerProvider;
+import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.TimedInterruptTimeoutException;
import org.junit.Test;
import javax.script.ScriptEngine;
@@ -42,7 +43,7 @@ public class GremlinGroovyScriptEngineTimedInterruptTest {
engine.eval("s = System.currentTimeMillis();\nwhile((System.currentTimeMillis() - s) < 10000) {}");
fail("This should have timed out");
} catch (ScriptException se) {
- assertEquals(TimeoutException.class, se.getCause().getCause().getClass());
+ assertEquals(TimedInterruptTimeoutException.class, se.getCause().getCause().getClass());
}
}
@@ -55,7 +56,7 @@ public class GremlinGroovyScriptEngineTimedInterruptTest {
engine.eval("s = System.currentTimeMillis();\nwhile((System.currentTimeMillis() - s) < 10000) {}");
fail("This should have timed out");
} catch (ScriptException se) {
- assertEquals(TimeoutException.class, se.getCause().getCause().getClass());
+ assertEquals(TimedInterruptTimeoutException.class, se.getCause().getCause().getClass());
}
assertEquals(2, engine.eval("1+1"));
@@ -72,7 +73,7 @@ public class GremlinGroovyScriptEngineTimedInterruptTest {
engine.eval("s = System.currentTimeMillis();\nwhile((System.currentTimeMillis() - s) < 2000) {}");
fail("This should have timed out");
} catch (ScriptException se) {
- assertEquals(TimeoutException.class, se.getCause().getCause().getClass());
+ assertEquals(TimedInterruptTimeoutException.class, se.getCause().getCause().getClass());
}
// this script takes 500 ms less than the interruptionTimeout
http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/blob/89e159b8/gremlin-server/src/main/java/org/apache/tinkerpop/gremlin/server/op/AbstractEvalOpProcessor.java
----------------------------------------------------------------------
diff --git a/gremlin-server/src/main/java/org/apache/tinkerpop/gremlin/server/op/AbstractEvalOpProcessor.java b/gremlin-server/src/main/java/org/apache/tinkerpop/gremlin/server/op/AbstractEvalOpProcessor.java
index aab9950..a1d5320 100644
--- a/gremlin-server/src/main/java/org/apache/tinkerpop/gremlin/server/op/AbstractEvalOpProcessor.java
+++ b/gremlin-server/src/main/java/org/apache/tinkerpop/gremlin/server/op/AbstractEvalOpProcessor.java
@@ -27,6 +27,7 @@ import org.apache.tinkerpop.gremlin.driver.message.ResponseMessage;
import org.apache.tinkerpop.gremlin.driver.message.ResponseStatusCode;
import org.apache.tinkerpop.gremlin.driver.ser.MessageTextSerializer;
import org.apache.tinkerpop.gremlin.groovy.engine.GremlinExecutor;
+import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.TimedInterruptTimeoutException;
import org.apache.tinkerpop.gremlin.server.GraphManager;
import org.apache.tinkerpop.gremlin.server.handler.Frame;
import org.apache.tinkerpop.gremlin.server.handler.GremlinResponseFrameEncoder;
@@ -213,9 +214,14 @@ public abstract class AbstractEvalOpProcessor implements OpProcessor {
timerContext.stop();
if (t != null) {
- if (t instanceof TimeoutException) {
- final String errorMessage = String.format("Response evaluation exceeded the configured threshold for request [%s] - %s", msg, t.getMessage());
+ if (t instanceof TimedInterruptTimeoutException) {
+ // occurs when the TimedInterruptCustomizerProvider is in play
+ final String errorMessage = String.format("A timeout occurred within the script during evaluation of [%s] - consider increasing the limit given to TimedInterruptCustomizerProvider", msg);
logger.warn(errorMessage);
+ ctx.writeAndFlush(ResponseMessage.build(msg).code(ResponseStatusCode.SERVER_ERROR_TIMEOUT).statusMessage("Timeout during script evaluation triggered by TimedInterruptCustomizerProvider").create());
+ } else if (t instanceof TimeoutException) {
+ final String errorMessage = String.format("Response evaluation exceeded the configured threshold for request [%s] - %s", msg, t.getMessage());
+ logger.warn(errorMessage, t);
ctx.writeAndFlush(ResponseMessage.build(msg).code(ResponseStatusCode.SERVER_ERROR_TIMEOUT).statusMessage(t.getMessage()).create());
} else {
logger.warn(String.format("Exception processing a script on request [%s].", msg), t);
@@ -328,7 +334,7 @@ public abstract class AbstractEvalOpProcessor implements OpProcessor {
stopWatch.split();
if (stopWatch.getSplitTime() > settings.serializedResponseTimeout) {
- final String timeoutMsg = String.format("Serialization of the entire response exceeded the serializeResponseTimeout setting %s",
+ final String timeoutMsg = String.format("Serialization of the entire response exceeded the 'serializeResponseTimeout' setting %s",
warnOnce ? "[Gremlin Server paused writes to client as messages were not being consumed quickly enough]" : "");
throw new TimeoutException(timeoutMsg.trim());
}
http://git-wip-us.apache.org/repos/asf/incubator-tinkerpop/blob/89e159b8/gremlin-server/src/test/java/org/apache/tinkerpop/gremlin/server/GremlinServerIntegrateTest.java
----------------------------------------------------------------------
diff --git a/gremlin-server/src/test/java/org/apache/tinkerpop/gremlin/server/GremlinServerIntegrateTest.java b/gremlin-server/src/test/java/org/apache/tinkerpop/gremlin/server/GremlinServerIntegrateTest.java
index df515bd..83dfa46 100644
--- a/gremlin-server/src/test/java/org/apache/tinkerpop/gremlin/server/GremlinServerIntegrateTest.java
+++ b/gremlin-server/src/test/java/org/apache/tinkerpop/gremlin/server/GremlinServerIntegrateTest.java
@@ -35,6 +35,7 @@ import org.apache.tinkerpop.gremlin.driver.simple.WebSocketClient;
import org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine;
import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.CompileStaticCustomizerProvider;
import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.SimpleSandboxExtension;
+import org.apache.tinkerpop.gremlin.groovy.jsr223.customizer.TimedInterruptCustomizerProvider;
import org.apache.tinkerpop.gremlin.structure.T;
import org.apache.tinkerpop.gremlin.server.channel.NioChannelizer;
import org.apache.tinkerpop.gremlin.server.op.session.SessionOpProcessor;
@@ -60,6 +61,7 @@ import java.util.stream.IntStream;
import static org.hamcrest.CoreMatchers.containsString;
import static org.hamcrest.CoreMatchers.is;
+import static org.hamcrest.core.StringStartsWith.startsWith;
import static org.junit.Assert.*;
import static org.junit.Assume.assumeThat;
@@ -131,19 +133,36 @@ public class GremlinServerIntegrateTest extends AbstractGremlinServerIntegration
settings.graphs.put("graph", "conf/neo4j-empty.properties");
break;
case "shouldUseSimpleSandbox":
- final Map<String,Object> scriptEngineConf = new HashMap<>();
- final Map<String,Object> compilerCustomizerProviderConf = new HashMap<>();
- final List<String> sandboxes = new ArrayList<>();
- sandboxes.add(SimpleSandboxExtension.class.getName());
- compilerCustomizerProviderConf.put(CompileStaticCustomizerProvider.class.getName(), sandboxes);
- scriptEngineConf.put("compilerCustomizerProviders", compilerCustomizerProviderConf);
- settings.scriptEngines.get("gremlin-groovy").config = scriptEngineConf;
+ settings.scriptEngines.get("gremlin-groovy").config = getScriptEngineConfForSimpleSandbox();
+ break;
+ case "shouldReceiveFailureTimeOutOnScriptEvalOfOutOfControlLoop":
+ settings.scriptEngines.get("gremlin-groovy").config = getScriptEngineConfForTimedInterrupt();
break;
}
return settings;
}
+ private static Map<String, Object> getScriptEngineConfForSimpleSandbox() {
+ final Map<String,Object> scriptEngineConf = new HashMap<>();
+ final Map<String,Object> compilerCustomizerProviderConf = new HashMap<>();
+ final List<String> sandboxes = new ArrayList<>();
+ sandboxes.add(SimpleSandboxExtension.class.getName());
+ compilerCustomizerProviderConf.put(CompileStaticCustomizerProvider.class.getName(), sandboxes);
+ scriptEngineConf.put("compilerCustomizerProviders", compilerCustomizerProviderConf);
+ return scriptEngineConf;
+ }
+
+ private static Map<String, Object> getScriptEngineConfForTimedInterrupt() {
+ final Map<String,Object> scriptEngineConf = new HashMap<>();
+ final Map<String,Object> timedInterruptProviderConf = new HashMap<>();
+ final List<Object> config = new ArrayList<>();
+ config.add(1000);
+ timedInterruptProviderConf.put(TimedInterruptCustomizerProvider.class.getName(), config);
+ scriptEngineConf.put("compilerCustomizerProviders", timedInterruptProviderConf);
+ return scriptEngineConf;
+ }
+
@Test
public void shouldUseSimpleSandbox() throws Exception {
final Cluster cluster = Cluster.open();
@@ -413,7 +432,27 @@ public class GremlinServerIntegrateTest extends AbstractGremlinServerIntegration
client.submit("Thread.sleep(3000);'some-stuff-that-should not return'").all().join();
fail("Should throw an exception.");
} catch (RuntimeException re) {
- assertTrue(ExceptionUtils.getRootCause(re).getMessage().startsWith("Script evaluation exceeded the configured threshold of 200 ms for request"));
+ assertThat(ExceptionUtils.getRootCause(re).getMessage(), startsWith("Script evaluation exceeded the configured 'scriptEvaluationTimeout' threshold of 200 ms for request"));
+
+ // validate that we can still send messages to the server
+ assertEquals(2, client.submit("1+1").all().join().get(0).getInt());
+ } finally {
+ cluster.close();
+ }
+ }
+
+ @Test
+ public void shouldReceiveFailureTimeOutOnScriptEvalOfOutOfControlLoop() throws Exception {
+ final Cluster cluster = Cluster.open();
+ final Client client = cluster.connect();
+
+ try {
+ // timeout configured for 1 second so the timed interrupt should trigger prior to the
+ // scriptEvaluationTimeout which is at 30 seconds by default
+ client.submit("while(true){}").all().join();
+ fail("Should throw an exception.");
+ } catch (RuntimeException re) {
+ assertEquals("Timeout during script evaluation triggered by TimedInterruptCustomizerProvider", ExceptionUtils.getRootCause(re).getMessage());
// validate that we can still send messages to the server
assertEquals(2, client.submit("1+1").all().join().get(0).getInt());
@@ -431,7 +470,7 @@ public class GremlinServerIntegrateTest extends AbstractGremlinServerIntegration
client.submit("(0..<100000)").all().join();
fail("Should throw an exception.");
} catch (RuntimeException re) {
- assertTrue(re.getCause().getMessage().endsWith("Serialization of the entire response exceeded the serializeResponseTimeout setting"));
+ assertTrue(re.getCause().getMessage().endsWith("Serialization of the entire response exceeded the 'serializeResponseTimeout' setting"));
// validate that we can still send messages to the server
assertEquals(2, client.submit("1+1").all().join().get(0).getInt());