Janusgraph: PermanentLockingException while committing one of the concurrent transactions

Created on 31 Mar 2020 · 18Comments · Source: JanusGraph/janusgraph

Version: 0.5.0
Storage Backend: inmemory, cql
Steps to Reproduce: you can reproduce it running MavenGroupRepositoryProviderTest from strongbox project

the problem only occurs in case of CONCURRENT execution, with SAME_THREAD everything works fine

Stack Trace

org.junit.jupiter.api.extension.ParameterResolutionException: Failed to resolve parameter [java.nio.file.Path arg4] in method [public void org.carlspring.strongbox.providers.repository.MavenGroupRepositoryProviderTest.deniedRoutingRuleShouldBeValid(org.carlspring.strongbox.storage.repository.Repository,org.carlspring.strongbox.storage.repository.Repository,org.carlspring.strongbox.storage.repository.Repository,java.nio.file.Path,java.nio.file.Path) throws java.lang.Exception]: Error creating bean with name 'storage0/mgrpt-releases-drrsbv-1/com.artifacts.accepted:foo': Bean instantiation via constructor failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.carlspring.strongbox.testing.artifact.TestArtifactContext]: Constructor threw exception; nested exception is java.lang.RuntimeException: org.springframework.dao.InvalidDataAccessApiUsageException: Could not commit transaction due to exception during persistence; nested exception is org.neo4j.ogm.exception.TransactionException: Could not commit transaction due to exception during persistence
    at org.junit.jupiter.engine.execution.ExecutableInvoker.resolveParameter(ExecutableInvoker.java:232)
    at org.junit.jupiter.engine.execution.ExecutableInvoker.resolveParameters(ExecutableInvoker.java:176)
    at org.junit.jupiter.engine.execution.ExecutableInvoker.resolveParameters(ExecutableInvoker.java:137)
    at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:118)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:184)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:180)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:127)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:135)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
    at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:171)
    at java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:189)
    at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
    at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
    at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
    at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'storage0/mgrpt-releases-drrsbv-1/com.artifacts.accepted:foo': Bean instantiation via constructor failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.carlspring.strongbox.testing.artifact.TestArtifactContext]: Constructor threw exception; nested exception is java.lang.RuntimeException: org.springframework.dao.InvalidDataAccessApiUsageException: Could not commit transaction due to exception during persistence; nested exception is org.neo4j.ogm.exception.TransactionException: Could not commit transaction due to exception during persistence
    at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:314)
    at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:295)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1358)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1204)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:557)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:879)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:878)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550)
    at org.carlspring.strongbox.testing.storage.repository.TestRepositoryManagementApplicationContext.tryToStart(TestRepositoryManagementApplicationContext.java:163)
    at org.carlspring.strongbox.testing.artifact.ArtifactManagementTestExecutionListener.resolveParameter(ArtifactManagementTestExecutionListener.java:90)
    at org.junit.jupiter.engine.execution.ExecutableInvoker.resolveParameter(ExecutableInvoker.java:209)
    ... 22 more
Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.carlspring.strongbox.testing.artifact.TestArtifactContext]: Constructor threw exception; nested exception is java.lang.RuntimeException: org.springframework.dao.InvalidDataAccessApiUsageException: Could not commit transaction due to exception during persistence; nested exception is org.neo4j.ogm.exception.TransactionException: Could not commit transaction due to exception during persistence
    at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:216)
    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:117)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:310)
    ... 37 more
Caused by: java.lang.RuntimeException: org.springframework.dao.InvalidDataAccessApiUsageException: Could not commit transaction due to exception during persistence; nested exception is org.neo4j.ogm.exception.TransactionException: Could not commit transaction due to exception during persistence
    at org.carlspring.strongbox.util.ThrowingConsumer.lambda$0(ThrowingConsumer.java:23)
    at java.lang.Iterable.forEach(Iterable.java:75)
    at org.carlspring.strongbox.testing.artifact.TestArtifactContext.deployArtifact(TestArtifactContext.java:199)
    at org.carlspring.strongbox.testing.artifact.TestArtifactContext.generateArtifact(TestArtifactContext.java:166)
    at org.carlspring.strongbox.testing.artifact.TestArtifactContext.createArtifacts(TestArtifactContext.java:139)
    at org.carlspring.strongbox.testing.artifact.TestArtifactContext.<init>(TestArtifactContext.java:78)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
    at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:203)
    ... 39 more
Caused by: org.springframework.dao.InvalidDataAccessApiUsageException: Could not commit transaction due to exception during persistence; nested exception is org.neo4j.ogm.exception.TransactionException: Could not commit transaction due to exception during persistence
    at org.springframework.data.neo4j.transaction.SessionFactoryUtils.convertOgmAccessException(SessionFactoryUtils.java:140)
    at org.springframework.data.neo4j.transaction.Neo4jTransactionManager.doCommit(Neo4jTransactionManager.java:305)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:744)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:712)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:631)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:385)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:99)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at org.carlspring.strongbox.services.ArtifactManagementService$$EnhancerBySpringCGLIB$$60efbce2.store(<generated>)
    at org.carlspring.strongbox.testing.artifact.TestArtifactContext.store(TestArtifactContext.java:209)
    at org.carlspring.strongbox.util.ThrowingConsumer.lambda$0(ThrowingConsumer.java:19)
    ... 49 more
Caused by: org.neo4j.ogm.exception.TransactionException: Could not commit transaction due to exception during persistence
    at org.opencypher.gremlin.neo4j.ogm.transaction.GremlinTransaction.commit(GremlinTransaction.java:87)
    at org.springframework.data.neo4j.transaction.Neo4jTransactionManager.doCommit(Neo4jTransactionManager.java:288)
    ... 60 more
Caused by: org.janusgraph.core.JanusGraphException: Could not commit transaction due to exception during persistence
    at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.commit(StandardJanusGraphTx.java:1436)
    at org.janusgraph.graphdb.tinkerpop.JanusGraphBlueprintsTransaction$1.doCommit(JanusGraphBlueprintsTransaction.java:185)
    at org.apache.tinkerpop.gremlin.structure.util.AbstractTransaction.commit(AbstractTransaction.java:104)
    at org.opencypher.gremlin.neo4j.ogm.transaction.GremlinTransaction.doCommit(GremlinTransaction.java:111)
    at org.opencypher.gremlin.neo4j.ogm.transaction.GremlinTransaction.commit(GremlinTransaction.java:82)
    ... 61 more
Caused by: org.janusgraph.core.JanusGraphException: Unexpected exception
    at org.janusgraph.graphdb.database.StandardJanusGraph.commit(StandardJanusGraph.java:812)
    at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.commit(StandardJanusGraphTx.java:1425)
    ... 65 more
Caused by: org.janusgraph.diskstorage.locking.PermanentLockingException: Local lock contention
    at org.janusgraph.diskstorage.locking.AbstractLocker.writeLock(AbstractLocker.java:327)
    at org.janusgraph.diskstorage.locking.consistentkey.ExpectedValueCheckingStore.acquireLock(ExpectedValueCheckingStore.java:103)
    at org.janusgraph.diskstorage.keycolumnvalue.KCVSProxy.acquireLock(KCVSProxy.java:51)
    at org.janusgraph.diskstorage.BackendTransaction.acquireIndexLock(BackendTransaction.java:255)
    at org.janusgraph.graphdb.database.StandardJanusGraph.prepareCommit(StandardJanusGraph.java:587)
    at org.janusgraph.graphdb.database.StandardJanusGraph.commit(StandardJanusGraph.java:708)
    ... 66 more

The root cause Caused by: org.janusgraph.diskstorage.locking.PermanentLockingException: Local lock contention seems related with concurrent transactions execution.

If this is some kind of expected concurrent behavior then how do I know what exactly the problem is? What exact Graph elements causing this locking conflict? Does it vertex, edge or maybe index and with what label?

kinbupossible

Source

sbespalov

👍2 😕1

All 18 comments

@sbespalov It would be better provide the issue before into our users group. This would allow more users to comment on.

I have to say, transaction part hasn't changed over the years. So, I think the most people that are currently working on this project never looked into this part of the code. If you like to find a solution could ask on the user group or just dig by your own into this part of the code.

I can say some things on the inmemory (old version before rewrite).
For example, reopen the database would reset the database.

_For example, the issues could be each thread contain their own version a inmemory database, but the transaction is multi thread and would interact with different inmemory database at same time._
-- Don't count on me for this example.

farodin91 on 1 Apr 2020

@farodin91 thanks for your reply! Do you mean we should ask this question on janusgraph-users at google or the gitter chat? :)

steve-todorov on 2 Apr 2020

@farodin91 thanks for response!
The reason for this task is that it seems a lot of people have similar problems and this suggests that the exception is probably not very informative and it would be nice to add a bit more details about what exactly caused the error.
Regarding inmemory storage we have the same with cql and probably it caused on JG side.

I'll crate a topic in janusgraph-users group and post a result here if there will be a solution.

sbespalov on 2 Apr 2020

@farodin91 thanks for your reply! Do you mean we should ask this question on janusgraph-users at google or the gitter chat? :)

I think you reach more people on the janusgraph-users group at google .

farodin91 on 2 Apr 2020

The stack trace suggests that it was trying to acquire a write lock on an index, using "backend-agnostic" locking mechanism which is based on adding a record to a KCV representing a lock. I haven't looked much further, but there seem to be multiple reasons for this kind of failure, including

lock record expiration
(wrong) implicit use of the same transaction in multiple threads
etc
See https://github.com/JanusGraph/janusgraph/blob/master/janusgraph-core/src/main/java/org/janusgraph/diskstorage/locking/LocalLockMediator.java

If you enable tracing in LocalLockMediator and AbstractLocker, it may give some clues as to what exactly happens in your case.

Also the below piece of docs suggests that for Cassandra specifically, there seems to be a more "native" locking mechanism which you can try and see if it works any better.

https://docs.janusgraph.org/advanced-topics/eventual-consistency/

I haven't dived too deep in the strongbox test you mentioned as a way to reproduce, as it seems quite involved, and it is unclear from just looking at it what is the schema, what is the access pattern, how transactions are managed etc. So my suggestions to you would be:

1) try tracing your test and understanding what is the exact reason for it failing to acquire index lock, and possibly change something in the way transactions/threads/schema is managed
2) try creating a simpler way to reproduce the issue
3) try Astyanax-based locking as per the docs (disclaimer - never tried it myself)

Finally, the same piece of doc says that most backends (and cassandra one specifically) are only eventually consistent - so there might be additional considerations for a project like strongbox beyond just fixing this test when run in "CONCURRENT" mode, as one cannot assume full ACID properties for a transaction.
In my personal experience, when the use case involves massively parallel modifications, it is better to avoid locking as much as possible, use "consistent" indexes only when absolutely necessary, and adjust the write patterns such that only "unrelated" bits of the graph get modified in parallel. For example, in an event-driven model, one can (re)key events and JG schema by the same keys, and make sure that updates to the same key are executed sequentially, while at the same time allowing non-related updates to run in parallel.

Hope some of this helps

dk-github on 2 Apr 2020

👍1

@dk-github many thanks for response, this is undoubtedly very useful info.
I will try to change the consistency settings as suggested and let you know the result.

It would be great if you could also help with checking the log.
If that helps, then our schema definition is here.

Regarding our concurrency in general I can say that at most cases we use synchronization at application level, to avoid concurrent data modifications and unique uuid property index per vertex label to provide some consistancy. In some cases there is asynchronous events without synchronization, which update only the vertices properties, such as the downloadCount property of the Artifact vertex, but in such cases, consistancy control seems not much required.

As for issue subject particular case, we expect that failed transaction is fully synchronized at application level to avoid concurrent modification of same vertices and edges.

sbespalov on 2 Apr 2020

As an addition, I can say that the retry of a failed transaction was tried, but this seems leeds to inconsistent data in other transactions which appears as unexpected exceptions like NPEs.

sbespalov on 2 Apr 2020

@sbespalov the log shows clearly that two parallel transactions attempt to acquire an "index update" lock for the same key.

If I understood you correctly, you state above that this should be handled on your application level and essentially shouldn't happen. So I see two alternatives here:
1) your statement is overly optimistic and there might be a bug in your app-level handling which actually makes it possible to modify value(s) for same key in parallel
2) during normal run time, this is true, but your test is constructed in such a way that with concurrent execution of individual test methods some common graph gets used in an unexpected way, including modification of the same key in parallel which would not happen during normal execution. For example if two test methods set up the same test vertex/property in parallel.

Relevant bits from the log you posted:

19:14:10.906 02-04-2020 | DEBUG | kJoinPool-1-worker-3 | o.j.d.l.consistentkey.ExpectedValueCheckingStore   | Attempting to acquireLock on KeyColumn [k=0x 16-165-160-114-116- 30-100-111-119-110-108-111- 97-100- 67-111-117-110-244, c=0x  0] ev=null
19:14:10.907 02-04-2020 | TRACE | kJoinPool-1-worker-3 | o.janusgraph.diskstorage.locking.LocalLockMediator | New local lock created: KeyColumn [k=0x 16-165-160-114-116- 30-100-111-119-110-108-111- 97-100- 67-111-117-110-244, c=0x  0] namespace=org.janusgraph.diskstorage.inmemory.InMemoryStoreManager@591fd17a txn=org.janusgraph.diskstorage.inmemory.InMemoryStoreManager$InMemoryTransaction@4c380949
19:14:10.907 02-04-2020 | TRACE | kJoinPool-1-worker-3 | o.janusgraph.diskstorage.locking.LocalLockMediator | Updated local lock expiration: KeyColumn [k=0x 16-165-160-114-116- 30-100-111-119-110-108-111- 97-100- 67-111-117-110-244, c=0x  0] namespace=org.janusgraph.diskstorage.inmemory.InMemoryStoreManager@591fd17a txn=org.janusgraph.diskstorage.inmemory.InMemoryStoreManager$InMemoryTransaction@4c380949 oldexp=2020-04-02T13:19:10.907Z newexp=2020-04-02T13:19:10.907Z
19:14:10.908 02-04-2020 | DEBUG | kJoinPool-1-worker-3 | o.j.d.l.c.ExpectedValueCheckingTransaction         | Store expected value for KeyColumn [k=0x 16-165-160-114-116- 30-100-111-119-110-108-111- 97-100- 67-111-117-110-244, c=0x  0]: null

19:14:10.911 02-04-2020 | DEBUG | kJoinPool-1-worker-2 | o.j.d.l.consistentkey.ExpectedValueCheckingStore   | Attempting to acquireLock on KeyColumn [k=0x 16-165-160-114-116- 30-100-111-119-110-108-111- 97-100- 67-111-117-110-244, c=0x  0] ev=null`

19:14:10.911 02-04-2020 | TRACE | kJoinPool-1-worker-2 | o.janusgraph.diskstorage.locking.LocalLockMediator | Local lock failed: KeyColumn [k=0x 16-165-160-114-116- 30-100-111-119-110-108-111- 97-100- 67-111-117-110-244, c=0x  0] namespace=org.janusgraph.diskstorage.inmemory.InMemoryStoreManager@591fd17a

You can also see "lock owners" stack trace and the stack trace where the exception happened, and they are pretty much the same - i.e. both transactions were trying to acquire update locks as part of preparing to commit

dk-github on 2 Apr 2020

As for your mention of async events which lead to updates of vertex properties - I would think that, depending on configuration, this _could_ lead to failures to update count like the one above, or overwrites of count totals etc. You can try emulating the scenario where many concurrent downloads occur, or just write a small test which increments count in multiple threads as your app would do.
Even if that works because you manage to configure proper consistent locking - depending on how many concurrent events you envisage, this might lead to performance issues, not only for counting downloads but for other DB usages.

So I would strongly recommend to write those events out to some kind of event journal first (a kafka topic comes to mind of course :) ), and then making sure that events for same key are processed sequentially. You can do it by reading a bunch of events (but not committing new offset yet), then splitting them up into sub-batches, making sure that you group them by key, and then executing those sub-batches in parallel. If you find yourself having to process a lot of events like these, and having to build a multi-chain preprocessing of these events - it might be worth looking at things like Apache Flink etc.

Hope this helps.

dk-github on 2 Apr 2020

@dk-github you're absolutely right, and thank you very much for your help!
seems we have two ArtifactTag vertices with same uuid=last-version index key created in concurrent transactions:

19:14:10.613 02-04-2020 | INFO  | kJoinPool-1-worker-3 | o.c.strongbox.gremlin.dsl.EntityTraversalDsl       | Created [ArtifactTag]-[4208]-[last-version]
19:14:10.647 02-04-2020 | INFO  | kJoinPool-1-worker-2 | o.c.strongbox.gremlin.dsl.EntityTraversalDsl       | Created [ArtifactTag]-[8304]-[last-version]

this was unexpected, but fixable :)

I'm just curious now regarding the transaction isolation. The thing is that PermanentLockingException seems like some kind of optimistic locking and we tried to fix it by replaying the failed transaction. The result was strange, because we had business exceptions that could be caused by some inconsistent data. Maybe you could clarify as well, whether it is possible that some changes that occurred in a PermanentLockingException failed transaction become available in other transactions?

sbespalov on 3 Apr 2020

You are right, and the "backend-agnostic" code we looked at definitely is "optimistic", i.e. trying to obtain a lock fails immediately if it is taken by someone else, and is not blocking. And if it fails, the whole JG transaction fails and it is up to the app to decide whether it wants to retry or not.

However it may be possible that some backends in certain configurations employ native locking mechanism which behaves differently - no idea on which ones and which configs though. Yesterday we both were looking at that code for the first time ever :)

As to " whether it is possible that some changes that occurred in a PermanentLockingException failed transaction become available in other transactions" - with in-memory backend, it is definitely possible if a transaction has failed in the middle of backend commit - see the links below. Although it shouldn't be the case here, because you got exceptions at "prepareCommit" stage where it is just trying to acquire required locks before actually writing anything out.

https://github.com/JanusGraph/janusgraph/pull/1934
https://github.com/JanusGraph/janusgraph/issues/1836

With other backends, one would think that since they are backed by proper database engines which employ journalling and all kinds of other techniques to achieve atomicity of transactions - this shouldn't be a problem.

Finally, with an "eventually consistent" (non-ACID) backend (which AFAIK form the majority in JG) you don't have to have a failed transaction in order to see strange data issues. Please refer to the docs and read carefully through the few cases they discuss there as an example. Depending on how your schema consistency is configured, you might also get duplicate entries etc. And if you request excessive locking and consistency checks, your performance and scalability will suffer. So really the only 2 ways I know of modifying the data in JG concurrently and without issues is to
a) be very careful about what you can and can't do in parallel
b) decide which types of inconsistencies you can tolerate/fix on sight in your app,and allow them to happen

https://docs.janusgraph.org/advanced-topics/eventual-consistency/

https://docs.janusgraph.org/basics/transactions/

dk-github on 3 Apr 2020

Seems I was able to finally fix it, the main problem that causing it was the[SystemIndex#~T$SchemaName] index which seems contains properities names defined in schema. The thing is that we relied on schema less JG feature, and not all properties was defined with JanusGraphManagement#makePropertyKey, some of the properties was just used at runtome without any declaration. It seems that such properties added to the schema at runtime and such behavior causes conflicts during concurrent execution and PermanentLockingException happens.
@dk-github do you think it will be possible to add index name (maybe key value as well) for the PermanentLockingException message? This would greatly simplify understanding and debugging of such conflicting index cases. If you think it is then I'll create a follow up task.

sbespalov on 6 Apr 2020

Re auto-schema - IMO using it for anything other than some initial prototyping is a bad idea in any case. Not just because of implicit additions which become part of your transactions without you realising it, but also because you don't have your schema explicitly defined anywhere, and no control over types it guesses depending on which data it sees first.

Re better diagnostics, the counter question for you - do you think it will be possible to create an isolated test program (or even better - a unit test within JG test framework) which reliably fails due to each of the reasons you have identified above (concurrent modification of the same key in explicit index defined in schema, and concurrent attempt to add the same auto property key, resulting in concurrent modification of the same index key in schema store)?

Please feel free to submit the issue in any case, but I think attaching the test as above to it will significantly raise the chances of somebody picking it up sooner rather than later.

It should be easy enough to step through the exception stack and see if more human-readable diagnostic info is available, and at which levels. We could then catch at those levels and re-throw with more information.

dk-github on 6 Apr 2020

👍1

@dk-github many thanks again for you time and help.
I'll proceed with follow up issue and a test, this issue could probably be closed now.

As an out of topic, I also prefer strict schema definition, one thing that confusing me in JG is that you can't define properties within graph element (vertex or edge).

sbespalov on 7 Apr 2020

As an out of topic, I also prefer strict schema definition, one thing that confusing me in JG is that you can't define properties within graph element (vertex or edge).

Are you referring to schema-constraints? I didn't follow this issue but you can define it in JanusGraph: https://docs.janusgraph.org/basics/schema/#schema-constraints

porunov on 7 Apr 2020

@sbespalov Also, notice that it is strongly suggested to disable automatic schema creation in production. Also, automatic schema creation is NOT thread safe. Refer to this part of the documentation: https://docs.janusgraph.org/basics/common-questions/#accidental-type-creation

Automatic type creation can cause problems in multi-threaded or highly concurrent environments. Since JanusGraph needs to ensure that types are unique, multiple attempts at creating the same type will lead to locking or other exceptions. It is generally recommended to create all needed types up front or in one batch when new property keys and edge labels are needed.

porunov on 7 Apr 2020

Are you referring to schema-constraints? I didn't follow this issue but you can define it in JanusGraph: https://docs.janusgraph.org/basics/schema/#schema-constraints

yes, we probably missed this feature