Berkeley DB and multiple removes or updates cause LockTimeoutException

[Karl Koster]

I have scoured the list looking for a resolution to this issue and haven't really found any. I am using Titan:db 0.5.0 on BDB only through Rexster. I have created a small graph and am testing the removal and modification of the vertices. When I start the server, I can issue a single update or removal (followed by a commit) that succeeds. Any update or removal after that fails with a LockTimeoutException (stack trace below). It does not matter if I issue additional commits or stopTransaction calls. I still get the exception, until I stop/start the server. I then have a single opportunity to issue another removal or update. I have tried setting setting storage.lock-mode to RMW in the rexster.xml configuration as well as the titan-*.properties file (as per https://github.com/thinkaurelius/titan/issues/293) to no avail.

StackTrace:

565813 [GremlinSession] ERROR com.tinkerpop.rexster.gremlin.GremlinSession  - ScriptEngine error running [%s]
javax.script.ScriptException: javax.script.ScriptException: com.thinkaurelius.titan.core.TitanException: Could not commit transaction due to exception during persistence
        at com.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine.eval(GremlinGroovyScriptEngine.java:94)
        at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:264)
        at com.tinkerpop.rexster.gremlin.GremlinSession.performEvaluation(GremlinSession.java:145)
        at com.tinkerpop.rexster.gremlin.GremlinSession.run(GremlinSession.java:79)
        at java.lang.Thread.run(Thread.java:745)
Caused by: javax.script.ScriptException: com.thinkaurelius.titan.core.TitanException: Could not commit transaction due to exception during persistence
       at com.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine.eval(GremlinGroovyScriptEngine.java:221)
       at com.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine.eval(GremlinGroovyScriptEngine.java:90)
       ... 4 more
Caused by: com.thinkaurelius.titan.core.TitanException: Could not commit transaction due to exception during persistence
       at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.commit(StandardTitanTx.java:1239)
       at com.thinkaurelius.titan.graphdb.blueprints.TitanBlueprintsGraph.commit(TitanBlueprintsGraph.java:57)
       at com.tinkerpop.blueprints.TransactionalGraph$commit.call(Unknown Source)
       at Script4.run(Script4.groovy:1)
       at com.tinkerpop.gremlin.groovy.jsr223.GremlinGroovyScriptEngine.eval(GremlinGroovyScriptEngine.java:219)
       ... 5 more
Caused by: com.thinkaurelius.titan.core.TitanException: Could not execute operation due to backend exception
       at com.thinkaurelius.titan.diskstorage.util.BackendOperation.execute(BackendOperation.java:44)
       at com.thinkaurelius.titan.diskstorage.keycolumnvalue.cache.CacheTransaction.persist(CacheTransaction.java:86)
       at com.thinkaurelius.titan.diskstorage.keycolumnvalue.cache.CacheTransaction.flushInternal(CacheTransaction.java:140)
       at com.thinkaurelius.titan.diskstorage.keycolumnvalue.cache.CacheTransaction.commit(CacheTransaction.java:197)
       at com.thinkaurelius.titan.diskstorage.BackendTransaction.commitStorage(BackendTransaction.java:117)
       at com.thinkaurelius.titan.graphdb.database.StandardTitanGraph.commit(StandardTitanGraph.java:625)
       at com.thinkaurelius.titan.graphdb.transaction.StandardTitanTx.commit(StandardTitanTx.java:1228)
       ... 9 more
Caused by: com.thinkaurelius.titan.diskstorage.PermanentBackendException: Permanent failure in storage backend
       at com.thinkaurelius.titan.diskstorage.berkeleyje.BerkeleyJEKeyValueStore.insert(BerkeleyJEKeyValueStore.java:206)
       at com.thinkaurelius.titan.diskstorage.berkeleyje.BerkeleyJEKeyValueStore.insert(BerkeleyJEKeyValueStore.java:183)
       at com.thinkaurelius.titan.diskstorage.berkeleyje.BerkeleyJEStoreManager.mutateMany(BerkeleyJEStoreManager.java:193)
       at com.thinkaurelius.titan.diskstorage.keycolumnvalue.keyvalue.OrderedKeyValueStoreManagerAdapter.mutateMany(OrderedKeyValueStoreManagerAdapter.java:100)
       at com.thinkaurelius.titan.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:89)
       at com.thinkaurelius.titan.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:86)
       at com.thinkaurelius.titan.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:56)
       at com.thinkaurelius.titan.diskstorage.util.BackendOperation.execute(BackendOperation.java:42)
       ... 15 more
Caused by: com.sleepycat.je.LockTimeoutException: (JE 5.0.73) Lock expired. Locker 1072320566 3330_GremlinSession_Txn: waited for lock on database=edgestore LockAddr:540895127 LSN=0x0/0x61bd type=WRITE grant=WAIT_PROMOTION timeoutMillis=500 startTime=1411431485731 endTime=1411431486232
Owners: [<LockInfo locker="739807959 3234_Grizzly(2)_Txn" type="READ"/>, <LockInfo locker="1072320566 3330_GremlinSession_Txn" type="READ"/>, <LockInfo locker="265778226 3224_Grizzly(8)_Txn" type="READ"/>, <LockInfo locker="1048738165 3241_Grizzly(1)_Txn" type="READ"/>]
Waiters: []
Transaction 1072320566 3330_GremlinSession_Txn owns LockAddr:540895127 <LockInfo locker="1072320566 3330_GremlinSession_Txn" type="READ"/>
Transaction 1072320566 3330_GremlinSession_Txn waits for LockAddr:540895127
       at com.sleepycat.je.txn.LockManager.newLockTimeoutException(LockManager.java:664)
       at com.sleepycat.je.txn.LockManager.makeTimeoutMsgInternal(LockManager.java:623)
       at com.sleepycat.je.txn.SyncedLockManager.makeTimeoutMsg(SyncedLockManager.java:97)
       at com.sleepycat.je.txn.LockManager.lockInternal(LockManager.java:390)
       at com.sleepycat.je.txn.LockManager.lock(LockManager.java:276)
       at com.sleepycat.je.txn.Txn.lockInternal(Txn.java:498)
       at com.sleepycat.je.txn.Locker.lock(Locker.java:443)
       at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2621)
       at com.sleepycat.je.dbi.CursorImpl.getSlotReuseInfo(CursorImpl.java:1091)
       at com.sleepycat.je.dbi.CursorImpl.putInternal(CursorImpl.java:880)
       at com.sleepycat.je.dbi.CursorImpl.put(CursorImpl.java:811)
       at com.sleepycat.je.Cursor.putAllowPhantoms(Cursor.java:2243)
       at com.sleepycat.je.Cursor.putNoNotify(Cursor.java:2200)
       at com.sleepycat.je.Cursor.putNotify(Cursor.java:2117)
       at com.sleepycat.je.Cursor.putNoDups(Cursor.java:2052)
       at com.sleepycat.je.Cursor.putInternal(Cursor.java:2020)
       at com.sleepycat.je.Database.putInternal(Database.java:1302)
       at com.sleepycat.je.Database.put(Database.java:1172)
       at com.thinkaurelius.titan.diskstorage.berkeleyje.BerkeleyJEKeyValueStore.insert(BerkeleyJEKeyValueStore.java:194)
       ... 22 more

Any constructive help would be appreciated.

Thanks,

Karl

[Dan LaRocque]

Hi Karl,

Can you share minimal steps to reproduce this?  Something is leaking a transaction.

thanks,
Dan

--
You received this message because you are subscribed to the Google Groups "Aurelius" group.
To unsubscribe from this group and stop receiving emails from it, send an email to aureliusgraph...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/aureliusgraphs/e5da168c-3ac0-4748-9b5b-09e69fc4c159%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Nicholas Grealy]

Hey Karl,

How did you go with this issue? I'm getting the same thing...

Kind regards,

Nick Grealy

...