[jira] [Created] (MRESOLVER-374) With v.1.9.13 70% of acquire lock attempts end up with java.lang.IllegalStateException: Could not acquire lock(s)

["Victor Rubezhny (Jira)" <ji...@apache.org>]

Victor Rubezhny created MRESOLVER-374:
-----------------------------------------

             Summary: With v.1.9.13 70% of acquire lock attempts end up with java.lang.IllegalStateException: Could not acquire lock(s)
                 Key: MRESOLVER-374
                 URL: https://issues.apache.org/jira/browse/MRESOLVER-374
             Project: Maven Resolver
          Issue Type: Bug
          Components: Resolver
    Affects Versions: 1.9.13
            Reporter: Victor Rubezhny


While trying to update the maven resolver dependency of Lemminx-Maven project to v. 1.9.13 we faced the following problem - https://github.com/eclipse/lemminx-maven/pull/422

With version v.1.9.13 more than 70% of attempts to build a Maven Project end up with getting `.IllegalStateException: Could not acquire lock(s)` exception:
 
```
Jun 23, 2023 2:23:02 PM org.eclipse.lemminx.extensions.maven.MavenProjectCache parseAndCache
SEVERE: Could not acquire lock(s)
java.lang.IllegalStateException: Could not acquire lock(s)
at org.eclipse.aether.internal.impl.synccontext.named.NamedLockFactoryAdapter$AdaptedLockSyncContext.acquire(NamedLockFactoryAdapter.java:219)
at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:271)
at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:259)
at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifact(DefaultArtifactResolver.java:242)
at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.loadPom(DefaultArtifactDescriptorReader.java:231)
at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.readArtifactDescriptor(DefaultArtifactDescriptorReader.java:172)
at org.eclipse.aether.internal.impl.collect.df.DfDependencyCollector.resolveCachedArtifactDescriptor(DfDependencyCollector.java:382)
at org.eclipse.aether.internal.impl.collect.df.DfDependencyCollector.getArtifactDescriptorResult(DfDependencyCollector.java:368)
at org.eclipse.aether.internal.impl.collect.df.DfDependencyCollector.processDependency(DfDependencyCollector.java:218)
at org.eclipse.aether.internal.impl.collect.df.DfDependencyCollector.processDependency(DfDependencyCollector.java:156)
at org.eclipse.aether.internal.impl.collect.df.DfDependencyCollector.process(DfDependencyCollector.java:138)
at org.eclipse.aether.internal.impl.collect.df.DfDependencyCollector.doCollectDependencies(DfDependencyCollector.java:108)
at org.eclipse.aether.internal.impl.collect.DependencyCollectorDelegate.collectDependencies(DependencyCollectorDelegate.java:222)
at org.eclipse.aether.internal.impl.collect.DefaultDependencyCollector.collectDependencies(DefaultDependencyCollector.java:87)
at org.eclipse.aether.internal.impl.DefaultRepositorySystem.collectDependencies(DefaultRepositorySystem.java:305)
at org.apache.maven.project.DefaultProjectDependenciesResolver.resolve(DefaultProjectDependenciesResolver.java:151)
at org.apache.maven.project.DefaultProjectBuilder.resolveDependencies(DefaultProjectBuilder.java:224)
at org.apache.maven.project.DefaultProjectBuilder.build(DefaultProjectBuilder.java:202)
at org.apache.maven.project.DefaultProjectBuilder.build(DefaultProjectBuilder.java:139)
at org.eclipse.lemminx.extensions.maven.MavenProjectCache.parseAndCache(MavenProjectCache.java:159)
at org.eclipse.lemminx.extensions.maven.MavenProjectCache.parseAndCache(MavenProjectCache.java:240)
at org.eclipse.lemminx.extensions.maven.MavenProjectCache.check(MavenProjectCache.java:130)
at org.eclipse.lemminx.extensions.maven.MavenProjectCache.getLastSuccessfulMavenProject(MavenProjectCache.java:105)
at org.eclipse.lemminx.extensions.maven.MavenLemminxWorkspaceReader$ResolveArtifactsAndPopulateWorkspaceRunnable.run(MavenLemminxWorkspaceReader.java:79)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
Suppressed: java.lang.IllegalStateException: Attempt 1: Could not acquire write lock for 'artifact:org.test.modules:ModuleA:0.0.1-SNAPSHOT' in 30 SECONDS
at org.eclipse.aether.internal.impl.synccontext.named.NamedLockFactoryAdapter$AdaptedLockSyncContext.acquire(NamedLockFactoryAdapter.java:202)
... 26 more
Suppressed: java.lang.IllegalStateException: Attempt 2: Could not acquire write lock for 'artifact:org.test.modules:ModuleA:0.0.1-SNAPSHOT' in 30 SECONDS
at org.eclipse.aether.internal.impl.synccontext.named.NamedLockFactoryAdapter$AdaptedLockSyncContext.acquire(NamedLockFactoryAdapter.java:202)
... 26 more
```
 
Every such failing attempt to acquire a lock  takes ~60 seconds to finish (fail) - while normally a test Maven Project (from Lemminx-Maven JUnit tests) takes 5-50 ms to resolve. 
 
So building and running JUnit tests with maven-resolver v.1.9.13 took 3h 16m while it normally takes about 7m 30s to finish.

Not a single `ProjectBuildingException` is returned during the tests so no recovery is possible for the projects that cannot be built for various reasons, as well as we don't have any statistics on how many "good and buildable' vs. `bad and not buildable` projects build attempts were ended up with that `lock failure`   
 
 
    



--
This message was sent by Atlassian Jira
(v8.20.10#820010)