TINKERPOP-1644 Added metrics to GremlinGroovyScriptEngine
Project: http://git-wip-us.apache.org/repos/asf/tinkerpop/repo Commit: http://git-wip-us.apache.org/repos/asf/tinkerpop/commit/8ffa5af6 Tree: http://git-wip-us.apache.org/repos/asf/tinkerpop/tree/8ffa5af6 Diff: http://git-wip-us.apache.org/repos/asf/tinkerpop/diff/8ffa5af6 Branch: refs/heads/TINKERPOP-1642 Commit: 8ffa5af6ff56933c1955e88e8aa42c06cb69162b Parents: a06072b Author: Stephen Mallette <sp...@genoprime.com> Authored: Thu Mar 9 10:30:17 2017 -0500 Committer: Stephen Mallette <sp...@genoprime.com> Committed: Fri Mar 10 11:13:03 2017 -0500 ---------------------------------------------------------------------- CHANGELOG.asciidoc | 2 + .../jsr223/GremlinGroovyScriptEngine.java | 122 ++++++++++++++++++- ...roovyScriptEngineCompilationOptionsTest.java | 8 +- .../jsr223/GremlinGroovyScriptEngineTest.java | 70 ++++++++++- 4 files changed, 193 insertions(+), 9 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/tinkerpop/blob/8ffa5af6/CHANGELOG.asciidoc ---------------------------------------------------------------------- diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index 9c3313e..3729271 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -26,7 +26,9 @@ image::https://raw.githubusercontent.com/apache/tinkerpop/master/docs/static/ima TinkerPop 3.2.5 (Release Date: NOT OFFICIALLY RELEASED YET) ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ +* Added various metrics to the `GremlinGroovyScriptEngine` around script compilation. * Moved the `caffeine` dependency down to `gremlin-groovy` and out of `gremlin-server`. +* Improved script compilation in `GremlinGroovyScriptEngine to use better caching, log long compile times and prevent failed compilations from recompiling on future requests. * Script compilation is synchronised. * Script compilation times are placed in to logs. * Failed scripts will not be recompiled. http://git-wip-us.apache.org/repos/asf/tinkerpop/blob/8ffa5af6/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngine.java ---------------------------------------------------------------------- diff --git a/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngine.java b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngine.java index 3bcb06c..0ed8d84 100644 --- a/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngine.java +++ b/gremlin-groovy/src/main/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngine.java @@ -164,7 +164,10 @@ public class GremlinGroovyScriptEngine extends GroovyScriptEngineImpl /** * Script to generated Class map. */ - private final LoadingCache<String, Future<Class>> classMap = Caffeine.newBuilder().softValues().build(new CacheLoader<String, Future<Class>>() { + private final LoadingCache<String, Future<Class>> classMap = Caffeine.newBuilder(). + softValues(). + recordStats(). + build(new CacheLoader<String, Future<Class>>() { @Override public Future<Class> load(final String script) throws Exception { final long start = System.currentTimeMillis(); @@ -175,6 +178,7 @@ public class GremlinGroovyScriptEngine extends GroovyScriptEngineImpl } catch (CompilationFailedException e) { final long finish = System.currentTimeMillis(); log.error("Script compilation FAILED {} took {}ms {}", script, finish - start, e); + failedCompilationCount.incrementAndGet(); throw e; } finally { final long time = System.currentTimeMillis() - start; @@ -208,6 +212,13 @@ public class GremlinGroovyScriptEngine extends GroovyScriptEngineImpl private final AtomicLong longRunCompilationCount = new AtomicLong(0L); /** + * A counter for the instance that tracks the number of failed compilations. Note that the failures need to be + * tracked outside of cache failure load stats because the loading mechanism will always successfully return + * a future and won't trigger a failure. + */ + private final AtomicLong failedCompilationCount = new AtomicLong(0L); + + /** * The list of loaded plugins for the console. */ private final Set<String> loadedPlugins = new HashSet<>(); @@ -589,10 +600,117 @@ public class GremlinGroovyScriptEngine extends GroovyScriptEngineImpl /** * Gets the number of compilations that extended beyond the {@link #expectedCompilationTime}. */ - public long getLongRunCompilationCount() { + public long getClassCacheLongRunCompilationCount() { return longRunCompilationCount.longValue(); } + /** + * Gets the estimated size of the class cache for compiled scripts. + */ + public long getClassCacheEstimatedSize() { + return classMap.estimatedSize(); + } + + /** + * Gets the average time spent compiling new scripts. + */ + public double getClassCacheAverageLoadPenalty() { + return classMap.stats().averageLoadPenalty(); + } + + /** + * Gets the number of times a script compiled to a class has been evicted from the cache. + */ + public long getClassCacheEvictionCount() { + return classMap.stats().evictionCount(); + } + + /** + * Gets the sum of the weights of evicted entries from the class cache. + */ + public long getClassCacheEvictionWeight() { + return classMap.stats().evictionWeight(); + } + + /** + * Gets the number of times cache look up for a compiled script returned a cached value. + */ + public long getClassCacheHitCount() { + return classMap.stats().hitCount(); + } + + /** + * Gets the hit rate of the class cache. + */ + public double getClassCacheHitRate() { + return classMap.stats().hitRate(); + } + + /** + * Gets the total number of times the cache lookup method attempted to compile new scripts. + */ + public long getClassCacheLoadCount() { + return classMap.stats().loadCount(); + } + + /** + * Gets the total number of times the cache lookup method failed to compile a new script. + */ + public long getClassCacheLoadFailureCount() { + // don't use classMap.stats().loadFailureCount() because the load mechanism always succeeds with a future + // that will in turn contain the success or failure + return failedCompilationCount.longValue(); + } + + /** + * Gets the ratio of script compilation attempts that failed. + */ + public double getClassCacheLoadFailureRate() { + // don't use classMap.stats().loadFailureRate() because the load mechanism always succeeds with a future + // that will in turn contain the success or failure + long totalLoadCount = classMap.stats().loadCount(); + return (totalLoadCount == 0) + ? 0.0 + : (double) failedCompilationCount.longValue() / totalLoadCount; + } + + /** + * Gets the total number of times the cache lookup method succeeded to compile a new script. + */ + public long getClassCacheLoadSuccessCount() { + // don't use classMap.stats().loadSuccessCount() because the load mechanism always succeeds with a future + // that will in turn contain the success or failure + return classMap.stats().loadCount() - failedCompilationCount.longValue(); + } + + /** + * Gets the total number of times the cache lookup method returned a newly compiled script. + */ + public long getClassCacheMissCount() { + return classMap.stats().missCount(); + } + + /** + * Gets the ratio of script compilation attempts that were misses. + */ + public double getClassCacheMissRate() { + return classMap.stats().missRate(); + } + + /** + * Gets the total number of times the cache lookup method returned a cached or uncached value. + */ + public long getClassCacheRequestCount() { + return classMap.stats().missCount(); + } + + /** + * Gets the total number of nanoseconds that the cache spent compiling scripts. + */ + public long getClassCacheTotalLoadTime() { + return classMap.stats().totalLoadTime(); + } + Class getScriptClass(final String script) throws CompilationFailedException { try { return classMap.get(script).get(); http://git-wip-us.apache.org/repos/asf/tinkerpop/blob/8ffa5af6/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineCompilationOptionsTest.java ---------------------------------------------------------------------- diff --git a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineCompilationOptionsTest.java b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineCompilationOptionsTest.java index f5dd9c5..b87d0ac 100644 --- a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineCompilationOptionsTest.java +++ b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineCompilationOptionsTest.java @@ -47,11 +47,11 @@ public class GremlinGroovyScriptEngineCompilationOptionsTest { b.put("x" + ix, ix); } - assertEquals(0, engine.getLongRunCompilationCount()); + assertEquals(0, engine.getClassCacheLongRunCompilationCount()); engine.eval(script, b); - assertEquals(1, engine.getLongRunCompilationCount()); + assertEquals(1, engine.getClassCacheLongRunCompilationCount()); } @Test @@ -71,10 +71,10 @@ public class GremlinGroovyScriptEngineCompilationOptionsTest { b.put("x" + ix, ix); } - assertEquals(0, engine.getLongRunCompilationCount()); + assertEquals(0, engine.getClassCacheLongRunCompilationCount()); engine.eval(script, b); - assertEquals(1, engine.getLongRunCompilationCount()); + assertEquals(1, engine.getClassCacheLongRunCompilationCount()); } } http://git-wip-us.apache.org/repos/asf/tinkerpop/blob/8ffa5af6/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTest.java ---------------------------------------------------------------------- diff --git a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTest.java b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTest.java index eb0a44b..0606721 100644 --- a/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTest.java +++ b/gremlin-groovy/src/test/java/org/apache/tinkerpop/gremlin/groovy/jsr223/GremlinGroovyScriptEngineTest.java @@ -497,7 +497,7 @@ public class GremlinGroovyScriptEngineTest { } @Test - public void testInvokeFunctionRedirectsOutputToContextOut() throws Exception { + public void shouldInvokeFunctionRedirectsOutputToContextOut() throws Exception { final GremlinGroovyScriptEngine engine = new GremlinGroovyScriptEngine(); StringWriter writer = new StringWriter(); final StringWriter unusedWriter = new StringWriter(); @@ -520,7 +520,7 @@ public class GremlinGroovyScriptEngineTest { } @Test - public void testEngineContextAccessibleToScript() throws Exception { + public void shouldEnableEngineContextAccessibleToScript() throws Exception { final GremlinGroovyScriptEngine engine = new GremlinGroovyScriptEngine(); final ScriptContext engineContext = engine.getContext(); engine.put("theEngineContext", engineContext); @@ -529,7 +529,7 @@ public class GremlinGroovyScriptEngineTest { } @Test - public void testContextBindingOverridesEngineContext() throws Exception { + public void shouldEnableContextBindingOverridesEngineContext() throws Exception { final GremlinGroovyScriptEngine engine = new GremlinGroovyScriptEngine(); final ScriptContext engineContext = engine.getContext(); final Map<String,Object> otherContext = new HashMap<>(); @@ -539,4 +539,68 @@ public class GremlinGroovyScriptEngineTest { final String code = "[answer: context.is(theEngineContext) ? \"wrong\" : context.foo]"; assertEquals("bar", ((Map) engine.eval(code)).get("answer")); } + + @Test + public void shouldGetClassMapCacheBasicStats() throws Exception { + final GremlinGroovyScriptEngine engine = new GremlinGroovyScriptEngine(); + assertEquals(0, engine.getClassCacheEstimatedSize()); + assertEquals(0, engine.getClassCacheHitCount()); + assertEquals(0, engine.getClassCacheLoadCount()); + assertEquals(0, engine.getClassCacheLoadFailureCount()); + assertEquals(0, engine.getClassCacheLoadSuccessCount()); + + engine.eval("1+1"); + + assertEquals(1, engine.getClassCacheEstimatedSize()); + assertEquals(0, engine.getClassCacheHitCount()); + assertEquals(1, engine.getClassCacheLoadCount()); + assertEquals(0, engine.getClassCacheLoadFailureCount()); + assertEquals(1, engine.getClassCacheLoadSuccessCount()); + + for (int ix = 0; ix < 100; ix++) { + engine.eval("1+1"); + } + + assertEquals(1, engine.getClassCacheEstimatedSize()); + assertEquals(100, engine.getClassCacheHitCount()); + assertEquals(1, engine.getClassCacheLoadCount()); + assertEquals(0, engine.getClassCacheLoadFailureCount()); + assertEquals(1, engine.getClassCacheLoadSuccessCount()); + + for (int ix = 0; ix < 100; ix++) { + engine.eval("1+" + ix); + } + + assertEquals(100, engine.getClassCacheEstimatedSize()); + assertEquals(101, engine.getClassCacheHitCount()); + assertEquals(100, engine.getClassCacheLoadCount()); + assertEquals(0, engine.getClassCacheLoadFailureCount()); + assertEquals(100, engine.getClassCacheLoadSuccessCount()); + + try { + engine.eval("(me broken"); + fail("Should have tanked with compilation error"); + } catch (Exception ex) { + assertThat(ex, instanceOf(ScriptException.class)); + } + + assertEquals(101, engine.getClassCacheEstimatedSize()); + assertEquals(101, engine.getClassCacheHitCount()); + assertEquals(101, engine.getClassCacheLoadCount()); + assertEquals(1, engine.getClassCacheLoadFailureCount()); + assertEquals(100, engine.getClassCacheLoadSuccessCount()); + + try { + engine.eval("(me broken"); + fail("Should have tanked with compilation error"); + } catch (Exception ex) { + assertThat(ex, instanceOf(ScriptException.class)); + } + + assertEquals(101, engine.getClassCacheEstimatedSize()); + assertEquals(102, engine.getClassCacheHitCount()); + assertEquals(101, engine.getClassCacheLoadCount()); + assertEquals(1, engine.getClassCacheLoadFailureCount()); + assertEquals(100, engine.getClassCacheLoadSuccessCount()); + } } \ No newline at end of file
