You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tinkerpop.apache.org by "Roy Reznik (Jira)" <ji...@apache.org> on 2021/07/19 06:14:00 UTC
[jira] [Created] (TINKERPOP-2588) Opening a new session is
extremely slow
Roy Reznik created TINKERPOP-2588:
-------------------------------------
Summary: Opening a new session is extremely slow
Key: TINKERPOP-2588
URL: https://issues.apache.org/jira/browse/TINKERPOP-2588
Project: TinkerPop
Issue Type: Bug
Components: groovy, server
Affects Versions: 3.4.11
Reporter: Roy Reznik
When moving from sessionless mode to using sessions in requests (example request):
{code:java}
{"requestId":"02a58ee3-e4d3-11eb-bd29-04d4c4eaf347","op":"eval","processor":"session","args":{"bindings":{},"evaluationTimeout":120000,"gremlin":"g.V().limit(1).id()","language":"gremlin-groovy","rebindings":{},"session":"50052633-079b-4500-bc29-a3eacb1f0dba"}}
{code}
It doesn't really matter what the query is, the first query, which opens the session and transaction is extremely slow (~1.2s).
From the stack trace this seems to be related to groovy script initialization:
{code:java}
"gremlin-server-worker-1" #93 prio=5 os_prio=0 tid=0x00007fe5f0006800 nid=0x179 runnable [0x00007fe6059f3000]
java.lang.Thread.State: RUNNABLE
at java.util.zip.ZipFile.freeEntry(Native Method)
at java.util.zip.ZipFile.access$1000(ZipFile.java:60)
at java.util.zip.ZipFile$ZipEntryIterator.next(ZipFile.java:540)
- locked <0x00000006c02394e0> (a java.util.jar.JarFile)
at java.util.zip.ZipFile$ZipEntryIterator.nextElement(ZipFile.java:514)
at java.util.zip.ZipFile$ZipEntryIterator.nextElement(ZipFile.java:495)
at java.util.jar.JarFile$JarEntryIterator.next(JarFile.java:257)
at java.util.jar.JarFile$JarEntryIterator.nextElement(JarFile.java:266)
at java.util.jar.JarFile$JarEntryIterator.nextElement(JarFile.java:247)
at sun.misc.URLClassPath$JarLoader.validIndex(URLClassPath.java:1017)
at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:1150)
at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:1062)
at sun.misc.URLClassPath.getResource(URLClassPath.java:249)
at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
at java.lang.ClassLoader.loadClass(ClassLoader.java:418)
- locked <0x00000006c1ee5c20> (a java.lang.Object)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:352)
at java.lang.ClassLoader.loadClass(ClassLoader.java:405)
- locked <0x00000007aca0a140> (a org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyClassLoader)
at groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:762)
at groovy.lang.GroovyClassLoader.loadClass(GroovyClassLoader.java:637)
at org.codehaus.groovy.control.ClassNodeResolver.findByClassLoading(ClassNodeResolver.java:209)
at org.codehaus.groovy.control.ClassNodeResolver.tryAsLoaderClassOrScript(ClassNodeResolver.java:198)
at org.codehaus.groovy.control.ClassNodeResolver.findClassNode(ClassNodeResolver.java:169)
at org.codehaus.groovy.control.ClassNodeResolver.resolveName(ClassNodeResolver.java:125)
at org.codehaus.groovy.control.ResolveVisitor.resolveToOuter(ResolveVisitor.java:856)
at org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:467)
at org.codehaus.groovy.control.ResolveVisitor.resolveFromStaticInnerClasses(ResolveVisitor.java:570)
at org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:466)
at org.codehaus.groovy.control.ResolveVisitor.resolveFromStaticInnerClasses(ResolveVisitor.java:570)
at org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:466)
at org.codehaus.groovy.control.ResolveVisitor.resolveFromStaticInnerClasses(ResolveVisitor.java:570)
at org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:466)
at org.codehaus.groovy.control.ResolveVisitor.resolveFromStaticInnerClasses(ResolveVisitor.java:570)
at org.codehaus.groovy.control.ResolveVisitor.resolve(ResolveVisitor.java:466)
at org.codehaus.groovy.control.ResolveVisitor.visitClass(ResolveVisitor.java:1421)
at org.codehaus.groovy.control.ResolveVisitor.startResolving(ResolveVisitor.java:230)
at org.codehaus.groovy.control.CompilationUnit$13.call(CompilationUnit.java:705)
at org.codehaus.groovy.control.CompilationUnit.applyToSourceUnits(CompilationUnit.java:965)
at org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:647)
at org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:596)
at groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:390)
at groovy.lang.GroovyClassLoader.access$300(GroovyClassLoader.java:89)
at groovy.lang.GroovyClassLoader$5.provide(GroovyClassLoader.java:330)
at groovy.lang.GroovyClassLoader$5.provide(GroovyClassLoader.java:327)
at org.codehaus.groovy.runtime.memoize.ConcurrentCommonCache.getAndPut(ConcurrentCommonCache.java:147)
at groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:325)
at groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:309)
at groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:251)
at org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine$GroovyCacheLoader.lambda$load$0(GremlinGroovyScriptEngine.java:819)
at org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine$GroovyCacheLoader$$Lambda$205/522819391.get(Unknown Source)
at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
at org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine$GroovyCacheLoader$$Lambda$206/2128176660.execute(Unknown Source)
at java.util.concurrent.CompletableFuture.asyncSupplyStage(CompletableFuture.java:1618)
at java.util.concurrent.CompletableFuture.supplyAsync(CompletableFuture.java:1843)
at org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine$GroovyCacheLoader.load(GremlinGroovyScriptEngine.java:817)
at org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine$GroovyCacheLoader.load(GremlinGroovyScriptEngine.java:812)
at com.github.benmanes.caffeine.cache.BoundedLocalCache$BoundedLocalLoadingCache.lambda$new$0(BoundedLocalCache.java:3117)
at com.github.benmanes.caffeine.cache.BoundedLocalCache$BoundedLocalLoadingCache$$Lambda$172/669669646.apply(Unknown Source)
at com.github.benmanes.caffeine.cache.LocalCache.lambda$statsAware$0(LocalCache.java:144)
at com.github.benmanes.caffeine.cache.LocalCache$$Lambda$203/911906439.apply(Unknown Source)
at com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$doComputeIfAbsent$16(BoundedLocalCache.java:1968)
at com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda$204/1935679399.apply(Unknown Source)
at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
- locked <0x00000007aca0a8b8> (a java.util.concurrent.ConcurrentHashMap$ReservationNode)
at com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:1966)
at com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:1949)
at com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:113)
at com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:67)
at org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine.getScriptClass(GremlinGroovyScriptEngine.java:567)
at org.apache.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine.eval(GremlinGroovyScriptEngine.java:374)
at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:264)
at org.apache.tinkerpop.gremlin.jsr223.DefaultGremlinScriptEngineManager.lambda$createGremlinScriptEngine$16(DefaultGremlinScriptEngineManager.java:460)
at org.apache.tinkerpop.gremlin.jsr223.DefaultGremlinScriptEngineManager$$Lambda$202/1673908654.accept(Unknown Source)
at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193)
at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1384)
at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:647)
at java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:272)
at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1384)
at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482)
at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:472)
at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:485)
at org.apache.tinkerpop.gremlin.jsr223.DefaultGremlinScriptEngineManager.createGremlinScriptEngine(DefaultGremlinScriptEngineManager.java:450)
at org.apache.tinkerpop.gremlin.jsr223.DefaultGremlinScriptEngineManager.getEngineByName(DefaultGremlinScriptEngineManager.java:219)
at org.apache.tinkerpop.gremlin.jsr223.CachedGremlinScriptEngineManager.lambda$getEngineByName$0(CachedGremlinScriptEngineManager.java:57)
at org.apache.tinkerpop.gremlin.jsr223.CachedGremlinScriptEngineManager$$Lambda$144/332268337.apply(Unknown Source)
at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660)
- locked <0x00000007aca0abf8> (a java.util.concurrent.ConcurrentHashMap$ReservationNode)
at org.apache.tinkerpop.gremlin.jsr223.CachedGremlinScriptEngineManager.getEngineByName(CachedGremlinScriptEngineManager.java:57)
at org.apache.tinkerpop.gremlin.server.op.session.Session.registerMetrics(Session.java:258)
at org.apache.tinkerpop.gremlin.server.op.session.Session$$Lambda$295/1510600006.accept(Unknown Source)
at java.util.LinkedHashMap$LinkedKeySet.forEach(LinkedHashMap.java:559)
at org.apache.tinkerpop.gremlin.server.op.session.Session.<init>(Session.java:113)
at org.apache.tinkerpop.gremlin.server.op.session.SessionOpProcessor.lambda$getSession$2(SessionOpProcessor.java:208)
at org.apache.tinkerpop.gremlin.server.op.session.SessionOpProcessor$$Lambda$291/934345685.apply(Unknown Source)
at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660)
- locked <0x00000007aca0ad00> (a java.util.concurrent.ConcurrentHashMap$ReservationNode)
at org.apache.tinkerpop.gremlin.server.op.session.SessionOpProcessor.getSession(SessionOpProcessor.java:208)
at org.apache.tinkerpop.gremlin.server.op.session.SessionOpProcessor.evalOp(SessionOpProcessor.java:179)
at org.apache.tinkerpop.gremlin.server.op.session.SessionOpProcessor$$Lambda$290/1574293989.accept(Unknown Source)
at org.apache.tinkerpop.gremlin.server.handler.OpExecutorHandler.channelRead0(OpExecutorHandler.java:67)
at org.apache.tinkerpop.gremlin.server.handler.OpExecutorHandler.channelRead0(OpExecutorHandler.java:43)
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
at io.netty.handler.codec.http.websocketx.Utf8FrameValidator.channelRead(Utf8FrameValidator.java:82)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.codec.http.websocketx.WebSocketServerProtocolHandler$1.channelRead(WebSocketServerProtocolHandler.java:283)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:321)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:295)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at java.lang.Thread.run(Thread.java:748)
{code}
Following requests, with the same session id are significantly quicker.
This basically renders session to be unusable, unless you are trying to perform very long-running sessions.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)