Open mad opened 5 years ago
Hi, I have a similar issue but the error is not exactly the same
Caused by: com.sleepycat.je.LockTimeoutException: (JE 7.5.11) Lock expired. Locker 819928704 173_pool-1-thread-2_Txn: waited for lock on database=edgestore LockAddr:1660879861 LSN=0x0/0x2045 type=WRITE grant=WAIT_NEW timeoutMillis=500 startTime=1582110227848 endTime=1582110228349
Owners: [<LockInfo locker="1161703245 174_pool-1-thread-3_Txn" type="READ"/>, <LockInfo locker="1296149042 171_pool-1-thread-1_Txn" type="READ"/>]
Waiters: [<LockInfo locker="819928704 173_pool-1-thread-2_Txn" type="WRITE"/>]
at com.sleepycat.je.txn.LockManager.makeTimeoutException(LockManager.java:1117)
Which is identical to this old issue with Titan
This is with the latest version of Janus and Berkely available.
Any update or plan on fixing this?
Any update on this. I am facing the same Lock issue in janus with berkeley on version 0.5.3. I just did the work around by setting isolation level as READ_UNCOMMITTED
This is not happening in Janus 0.4.0
Using JanusGraph 0.6.3 with berkleyje we are running into the same problems. Actually can reproduce both, deadlock and locktimeout. Situation is we currently have a lot of imports (doing reads and writes) to the db, which are currently single threaded, so only one transaction is running at the same time. We try to parallelize this, such that there will be concurrent thread local transactions doing the import.
Lock mode and isolation level are used synonymously in this thread, but there are two berkley related Janusgraph options, so I am not sure which are meant. But even if we set both like this in org.janusgraph.core.JanusGraphFactory.build
:
.set("storage.berkeleyje.isolation-level", "READ_UNCOMMITTED")
.set("storage.berkeleyje.lock-mode", com.sleepycat.je::LockMode::READ_UNCOMMITTED)
The issues still remain. Only by changing EnvironmentConfig.LOCK_TIMEOUT (additionally) things change. Sadly, not found a way to do this programatically, as JanusGraph is not exposing the environment
variable of berkley instance to the outside. So we do this by writing the je.properties
file inside the database folder with contents: je.lock.timeout = 0
(see also https://download.oracle.com/berkeley-db/docs/je/3.0.12/java/com/sleepycat/je/EnvironmentConfig.html#setLockTimeout(long))
Few details on the deadlock situation. We encountered this only if we have two concurrent transactions which both first read and then update properties of an identical set of vertices (code on our side was an error, so deadlock is not as much an issue for us atm). Not sure if the transaction system should handle this case or the deadlock is expected, but just for completeness here is the stracktrace:
[Ruby-0-Thread-25: lib/ThreadedSlice.rb:6] ERROR org.janusgraph.graphdb.database.StandardJanusGraph - Could not commit transaction [7] due to storage exception in commit
org.janusgraph.core.JanusGraphException: Could not execute operation due to backend exception
at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:54)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.persist(CacheTransaction.java:96)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.flushInternal(CacheTransaction.java:153)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.commit(CacheTransaction.java:210)
at org.janusgraph.diskstorage.BackendTransaction.commitStorage(BackendTransaction.java:136)
at org.janusgraph.graphdb.database.StandardJanusGraph.commit(StandardJanusGraph.java:790)
at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.commit(StandardJanusGraphTx.java:1525)
at org.janusgraph.graphdb.tinkerpop.JanusGraphBlueprintsGraph$GraphTransaction.doCommit(JanusGraphBlueprintsGraph.java:322)
at org.apache.tinkerpop.gremlin.structure.util.AbstractTransaction.commit(AbstractTransaction.java:104)
at org.janusgraph.graphdb.tinkerpop.JanusGraphBlueprintsGraph$GraphTransaction.commit(JanusGraphBlueprintsGraph.java:300)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
at java.base/java.lang.reflect.Method.invoke(Method.java:578)
at org.jruby.dist/org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:329)
at org.jruby.dist/org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:193)
at org.jruby.dist/org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:32)
at org.jruby.dist/org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:193)
at org.jruby.dist/org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:350)
at org.jruby.dist/org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)
at org.jruby.dist/org.jruby.internal.runtime.methods.InterpretedIRMethod.INTERPRET_METHOD(InterpretedIRMethod.java:131)
at org.jruby.dist/org.jruby.internal.runtime.methods.InterpretedIRMethod.call(InterpretedIRMethod.java:109)
at org.jruby.dist/org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:90)
at org.jruby.dist/org.jruby.ir.instructions.CallBase.interpret(CallBase.java:561)
at org.jruby.dist/org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:367)
at org.jruby.dist/org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)
at org.jruby.dist/org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:116)
at org.jruby.dist/org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:135)
at org.jruby.dist/org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:170)
at org.jruby.dist/org.jruby.runtime.BlockBody.yield(BlockBody.java:108)
at org.jruby.dist/org.jruby.runtime.Block.yield(Block.java:188)
at org.jruby.dist/org.jruby.ir.runtime.IRRuntimeHelpers.yield(IRRuntimeHelpers.java:492)
at org.jruby.dist/org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:96)
at org.jruby.dist/org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:166)
at org.jruby.dist/org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:98)
at org.jruby.dist/org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:116)
at org.jruby.dist/org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:135)
at org.jruby.dist/org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:66)
at org.jruby.dist/org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)
at org.jruby.dist/org.jruby.runtime.Block.call(Block.java:143)
at org.jruby.dist/org.jruby.RubyProc.call(RubyProc.java:357)
at org.jruby.dist/org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:110)
at java.base/java.lang.Thread.run(Thread.java:1589)
Caused by: org.janusgraph.diskstorage.PermanentBackendException: Permanent exception while executing backend operation CacheMutation
at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:79)
at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:52)
... 40 more
Caused by: com.sleepycat.je.DeadlockException: (JE 18.3.12) Deadlock was detected. Locker: "1773081160 5462_Ruby-0-Thread-25: lib/ThreadedSlice.rb:6_Txn" was chosen randomly as the victim.
DB: edgestore. Timeout: 500ms.
Locker: "407106594 5459_Ruby-0-Thread-22: lib/ThreadedSlice.rb:6_Txn" waits for lock: 831772068(LSN: 0x0/0x8f6e7, requestType: WRITE).
Locker: "1773081160 5462_Ruby-0-Thread-25: lib/ThreadedSlice.rb:6_Txn" owns lock: 831772068(LSN: 0x0/0x8f6e7, ownedType: null). Locker: "1773081160 5462_Ruby-0-Thread-25: lib/ThreadedSlice.rb:6_Txn" waits for lock: 1385254751(LSN: 0x0/0x8298e, requestType: WRITE).
at com.sleepycat.je.txn.LockManager.makeDeadlockException(LockManager.java:1120)
at com.sleepycat.je.txn.LockManager.checkAndHandleDeadlock(LockManager.java:961)
at com.sleepycat.je.txn.LockManager.waitForLock(LockManager.java:490)
at com.sleepycat.je.txn.LockManager.lock(LockManager.java:353)
at com.sleepycat.je.txn.Txn.lockInternal(Txn.java:545)
at com.sleepycat.je.txn.Locker.lock(Locker.java:496)
at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:3674)
at com.sleepycat.je.dbi.CursorImpl.insertRecordInternal(CursorImpl.java:1406)
at com.sleepycat.je.dbi.CursorImpl.insertOrUpdateRecord(CursorImpl.java:1242)
at com.sleepycat.je.Cursor.putNoNotify(Cursor.java:2938)
at com.sleepycat.je.Cursor.putNotify(Cursor.java:2776)
at com.sleepycat.je.Cursor.putNoDups(Cursor.java:2623)
at com.sleepycat.je.Cursor.putInternal(Cursor.java:2454)
at com.sleepycat.je.Cursor.putInternal(Cursor.java:841)
at com.sleepycat.je.Database.put(Database.java:1635)
at org.janusgraph.diskstorage.berkeleyje.BerkeleyJEKeyValueStore.insert(BerkeleyJEKeyValueStore.java:241)
at org.janusgraph.diskstorage.berkeleyje.BerkeleyJEKeyValueStore.insert(BerkeleyJEKeyValueStore.java:225)
at org.janusgraph.diskstorage.berkeleyje.BerkeleyJEStoreManager.mutateMany(BerkeleyJEStoreManager.java:233)
at org.janusgraph.diskstorage.keycolumnvalue.keyvalue.OrderedKeyValueStoreManagerAdapter.mutateMany(OrderedKeyValueStoreManagerAdapter.java:135)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:99)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:96)
at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:66)
As for the locktimeout issue, this went away removing the lock timeout (and nothing froze). Here is our stacktrace for diagnosis:
[Ruby-0-Thread-186: lib/JanusGraphLuceneSearchBackend.rb:146] ERROR org.janusgraph.graphdb.database.StandardJanusGraph - Could not commit transaction [109] due to storage exception in commit
org.janusgraph.core.JanusGraphException: Could not execute operation due to backend exception
at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:54)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.persist(CacheTransaction.java:96)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.flushInternal(CacheTransaction.java:153)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.commit(CacheTransaction.java:210)
at org.janusgraph.diskstorage.BackendTransaction.commitStorage(BackendTransaction.java:136)
at org.janusgraph.graphdb.database.StandardJanusGraph.commit(StandardJanusGraph.java:790)
at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.commit(StandardJanusGraphTx.java:1525)
at org.janusgraph.graphdb.tinkerpop.JanusGraphBlueprintsGraph$GraphTransaction.doCommit(JanusGraphBlueprintsGraph.java:322)
at org.apache.tinkerpop.gremlin.structure.util.AbstractTransaction.commit(AbstractTransaction.java:104)
at org.janusgraph.graphdb.tinkerpop.JanusGraphBlueprintsGraph$GraphTransaction.commit(JanusGraphBlueprintsGraph.java:300)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
at java.base/java.lang.reflect.Method.invoke(Method.java:578)
at org.jruby.dist/org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:329)
at org.jruby.dist/org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:193)
at org.jruby.dist/org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:32)
at org.jruby.dist/org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:193)
at org.jruby.dist/org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:350)
at org.jruby.dist/org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:157)
at org.jruby.dist/org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:116)
at org.jruby.dist/org.jruby.runtime.InterpretedIRBlockBody.yieldDirect(InterpretedIRBlockBody.java:108)
at org.jruby.dist/org.jruby.runtime.BlockBody.yield(BlockBody.java:114)
at org.jruby.dist/org.jruby.runtime.Block.yieldNonArray(Block.java:224)
at org.jruby.dist/org.jruby.RubyArray.collectArray(RubyArray.java:2778)
at org.jruby.dist/org.jruby.RubyArray.map(RubyArray.java:2812)
at org.jruby.dist/org.jruby.RubyArray$INVOKER$i$0$0$map.call(RubyArray$INVOKER$i$0$0$map.gen)
at org.jruby.dist/org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroBlock.call(JavaMethod.java:560)
at org.jruby.dist/org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:90)
at org.jruby.dist/org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:103)
at org.jruby.dist/org.jruby.ir.instructions.CallBase.interpret(CallBase.java:558)
at org.jruby.dist/org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:367)
at org.jruby.dist/org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)
at org.jruby.dist/org.jruby.internal.runtime.methods.InterpretedIRMethod.INTERPRET_METHOD(InterpretedIRMethod.java:131)
at org.jruby.dist/org.jruby.internal.runtime.methods.InterpretedIRMethod.call(InterpretedIRMethod.java:109)
at org.jruby.dist/org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:90)
at org.jruby.dist/org.jruby.ir.instructions.CallBase.interpret(CallBase.java:561)
at org.jruby.dist/org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:367)
at org.jruby.dist/org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)
at org.jruby.dist/org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:116)
at org.jruby.dist/org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:135)
at org.jruby.dist/org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:66)
at org.jruby.dist/org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)
at org.jruby.dist/org.jruby.runtime.Block.call(Block.java:143)
at org.jruby.dist/org.jruby.RubyProc.call(RubyProc.java:357)
at org.jruby.dist/org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:110)
at java.base/java.lang.Thread.run(Thread.java:1589)
Caused by: org.janusgraph.diskstorage.PermanentBackendException: Permanent exception while executing backend operation CacheMutation
at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:79)
at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:52)
... 44 more
Caused by: com.sleepycat.je.LockTimeoutException: (JE 18.3.12) Lock expired. Locker 1517840666 661642_Ruby-0-Thread-186: lib/JanusGraphLuceneSearchBackend.rb:146_Txn: waited for lock on database=graphindex LockAddr:2017444625 LSN=0x1a8/0x8da32c type=WRITE grant=WAIT_NEW timeoutMillis=500 startTime=1710243806275 endTime=1710243806775
Owners: [<LockInfo locker="1791837997 661635_Ruby-0-Thread-180: lib/JanusGraphLuceneSearchBackend.rb:146_Txn" type="WRITE"/>]
Waiters: [<LockInfo locker="1517840666 661642_Ruby-0-Thread-186: lib/JanusGraphLuceneSearchBackend.rb:146_Txn" type="WRITE"/>, <LockInfo locker="479317756 661639_Ruby-0-Thread-184: lib/JanusGraphLuceneSearchBackend.rb:146_Txn" type="WRITE"/>]
at com.sleepycat.je.txn.LockManager.makeTimeoutException(LockManager.java:1154)
at com.sleepycat.je.txn.LockManager.waitForLock(LockManager.java:621)
at com.sleepycat.je.txn.LockManager.lock(LockManager.java:353)
at com.sleepycat.je.txn.Txn.lockInternal(Txn.java:545)
at com.sleepycat.je.txn.Locker.lock(Locker.java:496)
at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:3674)
at com.sleepycat.je.dbi.CursorImpl.insertRecordInternal(CursorImpl.java:1406)
at com.sleepycat.je.dbi.CursorImpl.insertOrUpdateRecord(CursorImpl.java:1242)
at com.sleepycat.je.Cursor.putNoNotify(Cursor.java:2938)
at com.sleepycat.je.Cursor.putNotify(Cursor.java:2776)
at com.sleepycat.je.Cursor.putNoDups(Cursor.java:2623)
at com.sleepycat.je.Cursor.putInternal(Cursor.java:2454)
at com.sleepycat.je.Cursor.putInternal(Cursor.java:841)
at com.sleepycat.je.Database.put(Database.java:1635)
at org.janusgraph.diskstorage.berkeleyje.BerkeleyJEKeyValueStore.insert(BerkeleyJEKeyValueStore.java:241)
at org.janusgraph.diskstorage.berkeleyje.BerkeleyJEKeyValueStore.insert(BerkeleyJEKeyValueStore.java:225)
at org.janusgraph.diskstorage.berkeleyje.BerkeleyJEStoreManager.mutateMany(BerkeleyJEStoreManager.java:233)
at org.janusgraph.diskstorage.keycolumnvalue.keyvalue.OrderedKeyValueStoreManagerAdapter.mutateMany(OrderedKeyValueStoreManagerAdapter.java:135)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:99)
at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:96)
at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:66)
Sadly, we encountered different exceptions after applying the workarounds (remove locktimeout, set configuration to READ_UNCOMMITTED). As a first intuition I think they all are happening when JanusGraph is implicitly creating the schema in a concurrent setting. It seems they all go away if we do not rely on implicit schema creation and generate the schema beforehand, but importantly only single threaded, so not concurrently. In that case so far we havent seen the numerous errors which I will post below. So, I guess JanusGraph has some problems with automatic schema creation either only with the lock modes READ_UNCOMMITTED or in general with the berkleyje backend...
So here are all the stacktraces we encountered when JanusGraph had to automatically create the schema inside the concurrent transactions:
org.janusgraph.graphdb.transaction.StandardJanusGraphTx.addProperty(org/janusgraph/graphdb/transaction/StandardJanusGraphTx.java:916): Adding this property for key [~T$SchemaName] and value [rt_label] violates a uniqueness constraint [SystemIndex#~T$SchemaName] (Java::OrgJanusgraphCore::SchemaViolationException)
from org.janusgraph.graphdb.transaction.StandardJanusGraphTx.addProperty(org/janusgraph/graphdb/transaction/StandardJanusGraphTx.java:838)
from org.janusgraph.graphdb.transaction.StandardJanusGraphTx.addProperty(org/janusgraph/graphdb/transaction/StandardJanusGraphTx.java:834)
from org.janusgraph.graphdb.transaction.StandardJanusGraphTx.makeSchemaVertex(org/janusgraph/graphdb/transaction/StandardJanusGraphTx.java:970)
from org.janusgraph.graphdb.transaction.StandardJanusGraphTx.makePropertyKey(org/janusgraph/graphdb/transaction/StandardJanusGraphTx.java:989)
from org.janusgraph.graphdb.types.StandardPropertyKeyMaker.make(org/janusgraph/graphdb/types/StandardPropertyKeyMaker.java:114)
from org.janusgraph.core.schema.JanusGraphDefaultSchemaMaker.makePropertyKey(org/janusgraph/core/schema/JanusGraphDefaultSchemaMaker.java:73)
from org.janusgraph.graphdb.transaction.StandardJanusGraphTx.getOrCreatePropertyKey(org/janusgraph/graphdb/transaction/StandardJanusGraphTx.java:1100)
from org.janusgraph.graphdb.vertices.AbstractVertex.property(org/janusgraph/graphdb/vertices/AbstractVertex.java:165)
from org.janusgraph.graphdb.vertices.AbstractVertex.property(org/janusgraph/graphdb/vertices/AbstractVertex.java:45)
from org.apache.tinkerpop.gremlin.process.traversal.step.sideEffect.AddPropertyStep.sideEffect(org/apache/tinkerpop/gremlin/process/traversal/step/sideEffect/AddPropertyStep.java:153)
from org.apache.tinkerpop.gremlin.process.traversal.step.sideEffect.SideEffectStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/sideEffect/SideEffectStep.java:39)
from org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:135)
from org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:40)
from org.apache.tinkerpop.gremlin.process.traversal.util.DefaultTraversal.next(org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversal.java:249)
from jdk.internal.reflect.DirectMethodHandleAccessor.invoke(jdk/internal/reflect/DirectMethodHandleAccessor.java:104)
from java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:578)
from org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:329)
from org.jruby.javasupport.JavaMethod.invokeDirect(org/jruby/javasupport/JavaMethod.java:193)
from RUBY.traverse_cliques(lib/JanusGraphLuceneSearchBackend.rb:366)
from org.jruby.javasupport.ext.JavaLang$Iterable.each(org/jruby/javasupport/ext/JavaLang.java:112)
from org.jruby.javasupport.ext.JavaUtil$Collection.each(org/jruby/javasupport/ext/JavaUtil.java:138)
from org.jruby.javasupport.ext.JavaUtil$Collection$INVOKER$s$0$0$each.call(org/jruby/javasupport/ext/JavaUtil$Collection$INVOKER$s$0$0$each.gen)
from RUBY.traverse_cliques(lib/JanusGraphLuceneSearchBackend.rb:362)
from org.jruby.RubyArray.collectArray(org/jruby/RubyArray.java:2778)
from org.jruby.RubyArray.map(org/jruby/RubyArray.java:2812)
from org.jruby.RubyArray$INVOKER$i$0$0$map.call(org/jruby/RubyArray$INVOKER$i$0$0$map.gen)
from RUBY.traverse_cliques(lib/JanusGraphLuceneSearchBackend.rb:196)
from RUBY.reindex_nodes(lib/JanusGraphLuceneSearchBackend.rb:186)
from RUBY.initialize(lib/ThreadedSlice.rb:10)
from org.jruby.RubyProc.call(org/jruby/RubyProc.java:357)
from java.lang.Thread.run(java/lang/Thread.java:1589)
java.lang.NullPointerException: Cannot invoke "org.janusgraph.core.Multiplicity.getCardinality()" because the return value of "org.janusgraph.graphdb.types.vertices.RelationTypeVertex.multiplicity()" is null
at org.janusgraph.graphdb.types.vertices.PropertyKeyVertex.cardinality(org/janusgraph/graphdb/types/vertices/PropertyKeyVertex.java:36)
at org.janusgraph.graphdb.vertices.AbstractVertex.property(org/janusgraph/graphdb/vertices/AbstractVertex.java:169)
at org.janusgraph.graphdb.vertices.AbstractVertex.property(org/janusgraph/graphdb/vertices/AbstractVertex.java:160)
at org.janusgraph.core.JanusGraphVertex.property(org/janusgraph/core/JanusGraphVertex.java:72)
at org.janusgraph.graphdb.util.ElementHelper.attachProperties(org/janusgraph/graphdb/util/ElementHelper.java:87)
at org.janusgraph.graphdb.tinkerpop.JanusGraphBlueprintsTransaction.addVertex(org/janusgraph/graphdb/tinkerpop/JanusGraphBlueprintsTransaction.java:128)
at org.janusgraph.graphdb.tinkerpop.JanusGraphBlueprintsGraph.addVertex(org/janusgraph/graphdb/tinkerpop/JanusGraphBlueprintsGraph.java:143)
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(jdk/internal/reflect/DirectMethodHandleAccessor.java:104)
at java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:578)
at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:314)
at org.jruby.javasupport.JavaMethod.invokeDirect(org/jruby/javasupport/JavaMethod.java:181)
at RUBY.create(lib/GraphDatabase.rb:113)
at RUBY.assign_property(lib/GraphDatabase.rb:178)
at RUBY.commit(importers/lib/ImporterBase.rb:303)
at org.jruby.RubyArray.each(org/jruby/RubyArray.java:1988)
at org.jruby.RubyArray$INVOKER$i$0$0$each.call(org/jruby/RubyArray$INVOKER$i$0$0$each.gen)
at RUBY.commit(importers/lib/ImporterBase.rb:282)
at org.jruby.RubyHash$10.visit(org/jruby/RubyHash.java:1605)
at org.jruby.RubyHash$10.visit(org/jruby/RubyHash.java:1599)
at org.jruby.RubyHash.visitLimited(org/jruby/RubyHash.java:759)
at org.jruby.RubyHash.visitAll(org/jruby/RubyHash.java:744)
at org.jruby.RubyHash.iteratorVisitAll(org/jruby/RubyHash.java:1563)
at org.jruby.RubyHash.each_pairCommon(org/jruby/RubyHash.java:1594)
at org.jruby.RubyHash.each(org/jruby/RubyHash.java:1587)
at org.jruby.RubyHash$INVOKER$i$0$0$each.call(org/jruby/RubyHash$INVOKER$i$0$0$each.gen)
at RUBY.commit(importers/lib/ImporterBase.rb:281)
at org.jruby.RubyArray.collectArray(org/jruby/RubyArray.java:2778)
at org.jruby.RubyArray.map(org/jruby/RubyArray.java:2812)
at org.jruby.RubyArray$INVOKER$i$0$0$map.call(org/jruby/RubyArray$INVOKER$i$0$0$map.gen)
at RUBY.commit(importers/lib/ImporterBase.rb:254)
at RUBY.initialize(lib/ThreadedSlice.rb:10)
at org.jruby.RubyProc.call(org/jruby/RubyProc.java:357)
at java.lang.Thread.run(java/lang/Thread.java:1589)
java.lang.NullPointerException: Could not find type for id: 48149
at com.google.common.base.Preconditions.checkNotNull(com/google/common/base/Preconditions.java:971)
at org.janusgraph.graphdb.types.vertices.JanusGraphSchemaVertex.name(org/janusgraph/graphdb/types/vertices/JanusGraphSchemaVertex.java:68)
at org.janusgraph.graphdb.query.vertex.BasicVertexCentricQueryBuilder.constructQueryWithoutProfile(org/janusgraph/graphdb/query/vertex/BasicVertexCentricQueryBuilder.java:534)
at org.janusgraph.graphdb.query.vertex.BasicVertexCentricQueryBuilder.constructQuery(org/janusgraph/graphdb/query/vertex/BasicVertexCentricQueryBuilder.java:447)
at org.janusgraph.graphdb.query.vertex.VertexCentricQueryBuilder.execute(org/janusgraph/graphdb/query/vertex/VertexCentricQueryBuilder.java:73)
at org.janusgraph.graphdb.query.vertex.VertexCentricQueryBuilder.edges(org/janusgraph/graphdb/query/vertex/VertexCentricQueryBuilder.java:98)
at org.janusgraph.graphdb.tinkerpop.optimize.step.JanusGraphVertexStep.flatMap(org/janusgraph/graphdb/tinkerpop/optimize/step/JanusGraphVertexStep.java:142)
at org.apache.tinkerpop.gremlin.process.traversal.step.map.FlatMapStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/map/FlatMapStep.java:49)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:55)
at org.apache.tinkerpop.gremlin.process.traversal.step.map.FlatMapStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/map/FlatMapStep.java:48)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:55)
at org.apache.tinkerpop.gremlin.process.traversal.step.map.FlatMapStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/map/FlatMapStep.java:48)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:55)
at org.apache.tinkerpop.gremlin.process.traversal.step.filter.FilterStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/filter/FilterStep.java:37)
at org.apache.tinkerpop.gremlin.process.traversal.step.filter.WherePredicateStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/filter/WherePredicateStep.java:154)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:55)
at org.apache.tinkerpop.gremlin.process.traversal.step.sideEffect.SideEffectStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/sideEffect/SideEffectStep.java:38)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:55)
at org.apache.tinkerpop.gremlin.process.traversal.step.branch.RepeatStep$RepeatEndStep.standardAlgorithm(org/apache/tinkerpop/gremlin/process/traversal/step/branch/RepeatStep.java:296)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ComputerAwareStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/util/ComputerAwareStep.java:46)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.branch.RepeatStep.standardAlgorithm(org/apache/tinkerpop/gremlin/process/traversal/step/branch/RepeatStep.java:196)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ComputerAwareStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/util/ComputerAwareStep.java:46)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:55)
at org.apache.tinkerpop.gremlin.process.traversal.step.filter.FilterStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/filter/FilterStep.java:37)
at org.apache.tinkerpop.gremlin.process.traversal.step.filter.DedupGlobalStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/filter/DedupGlobalStep.java:107)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:47)
at org.apache.tinkerpop.gremlin.process.traversal.step.sideEffect.AggregateGlobalStep.processAllStarts(org/apache/tinkerpop/gremlin/process/traversal/step/sideEffect/AggregateGlobalStep.java:126)
at org.apache.tinkerpop.gremlin.process.traversal.step.sideEffect.AggregateGlobalStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/sideEffect/AggregateGlobalStep.java:117)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.util.DefaultTraversal.hasNext(org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversal.java:235)
at org.apache.tinkerpop.gremlin.process.traversal.step.sideEffect.TraversalSideEffectStep.sideEffect(org/apache/tinkerpop/gremlin/process/traversal/step/sideEffect/TraversalSideEffectStep.java:48)
at org.apache.tinkerpop.gremlin.process.traversal.step.sideEffect.SideEffectStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/sideEffect/SideEffectStep.java:39)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:150)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/ExpandableStepIterator.java:55)
at org.apache.tinkerpop.gremlin.process.traversal.step.map.ScalarMapStep.processNextStart(org/apache/tinkerpop/gremlin/process/traversal/step/map/ScalarMapStep.java:39)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:135)
at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.next(org/apache/tinkerpop/gremlin/process/traversal/step/util/AbstractStep.java:40)
at org.apache.tinkerpop.gremlin.process.traversal.util.DefaultTraversal.next(org/apache/tinkerpop/gremlin/process/traversal/util/DefaultTraversal.java:249)
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(jdk/internal/reflect/DirectMethodHandleAccessor.java:104)
at java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:578)
at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:329)
at org.jruby.javasupport.JavaMethod.invokeDirect(org/jruby/javasupport/JavaMethod.java:193)
at RUBY.reindex_nodes(lib/JanusGraphLuceneSearchBackend.rb:116)
Example of code
Exception
For fix it, change default isolation level (LOCK_MODE) to LockMode.READ_UNCOMMITTED
But if we want to use default lock mode, we can increase EnvironmentConfig.LOCK_TIMEOUT (default 500ms), so another way to fix that make it parametr customizable