[
https://issues.apache.org/jira/browse/MRESOLVER-114?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17129720#comment-17129720
]
Eva Müller commented on MRESOLVER-114:
--------------------------------------
Here's the first build log [^mvn-build-120.log].
Built with/by
* {{mvn clean ... deploy -T3 --builder smart ...}}
* Latest {{takari-local-repository}} Maven extension 0.11.2 with additional
log statements
* [^DefaultArtifactResolver.java] with additional log statements
* [^BasicRepositoryConnector.java] with additional log statements
* {{MAVEN_OPTS}} set to
{{"-Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.SimpleLog
-Dorg.slf4j.simpleLogger.log.org.apache.maven.wagon.providers.http.httpclient=DEBUG"}}
(Hope these are the correct HttpClient debug log statements for headers)
With the updated [^DefaultArtifactResolver.java], I log the used SyncContext:
{{[2020-06-09T15:05:54.478Z] [main] [INFO] [EMU]
org.eclipse.aether.internal.impl.DefaultSyncContextFactory$DefaultSyncContext@7ee3d262
=> SyncContext: acquire locks}}
Although we use the {{takari-local-repository}} Maven extension,
{color:red}*the DefaultSyncContext is used* and the not the
[LockingSyncContext|https://github.com/takari/takari-local-repository/blob/takari-local-repository-0.11.2/src/main/java/io/takari/aether/concurrency/LockingSyncContext.java]
from the {{takari-local-repository}} Maven extension - as I assumed.{color}
Additionally, I filtered the [^mvn-build-120.log] by
* my log statements,
* the affected artefact {{gson/gson/2.8.6/gson-2.8.6.jar}},
* and the HTTP DEBUG output referring to {{gson/gson/2.8.6/gson-2.8.6}}
and stored the result in [^mvn-build-120-sorted.txt].
----
I'm still trying to produce the following build logs
# One without the {{takari-local-repository}} Maven extension and the
HttpClient debug log statements enabled.
# And one with the {{takari-local-repository}} Maven extension based on the
master which contains (maybe interesting) commits:
** [Aether Bug
413867|https://github.com/takari/takari-local-repository/commit/59b28b9b25f09707947e0a4ea82015d17f9570c5]:
{noformat}
Concurrent artifact resolution using same repo session (data) in
combination with enhanced local repo can fail sporadically
Fixed interaction between DefaultArtifactResolver and
DefaultUpdateCheckManager to ensure download requests for unavailable
artifacts are not suppressed unless a resolution error has been cached
{noformat}
** [Aether Bug
407799|https://github.com/takari/takari-local-repository/commit/9c3cc4dc92eec44c036daefd36fb9c4d3ba2b3f8]
> ArtifactNotFoundExceptions when building in parallel
> ----------------------------------------------------
>
> Key: MRESOLVER-114
> URL: https://issues.apache.org/jira/browse/MRESOLVER-114
> Project: Maven Resolver
> Issue Type: Bug
> Components: resolver
> Affects Versions: 1.4.2
> Reporter: Rainer Reich
> Priority: Major
> Attachments: BasicRepositoryConnector.java,
> DefaultArtifactResolver.java, maven-debug-log.txt, mvn-build-120-sorted.txt,
> mvn-build-120.log
>
> Time Spent: 20m
> Remaining Estimate: 0h
>
> We have a multi-module project with quite many modules and many dependencies
> and observe pretty random {{ArtifactNotFoundExceptions}} when building in
> parallel with an empty local repository.
> The "funny" thing is that Maven did in fact download the jar that it
> complained about not finding.
> In this example Maven said it could not find
> {{edu.tum.cs:cup-runtime:jar:11a}} (see stacktrace below)
> But it also said: {{Downloaded from central-mirror:
> [https://mirror.xy.com/repository/maven-all-mirror/edu/tum/cs/cup-runtime/11a/cup-runtime-11a.jar]}}.
> When looking into the local repository after the failed build we found the
> cup-runtime.jar in the correct place with the correct checksum.
> We tried the following to "fix" the problem:
> * build with and without the takari extensions ({{takari-local-repository}}
> & {{takari-smart-builder}}) using {{--builder smart}}
> * also build with {{io.takari.aether:aether-connector-okhttp}} extension
> * only execute goal package instead of install
> * build with these properties: {{-Daether.connector.basic.threads=1
> -Daether.connector.resumeDownloads=false}}
> But nothing helped.
> Unfortunately it seems to be a race condition and we cannot reproduce it
> consistently but it happens in about 1 out of 5 builds.
> {code:java}
> ...
> [2019-11-18T16:46:29.370Z] [INFO] Downloaded from central-mirror:
> https://mirror.xy.com/repository/maven-all-mirror/edu/tum/cs/cup-runtime/11a/cup-runtime-11a.jar
> (13 kB at 738 kB/s)
> ...
> [2019-11-18T16:46:30.894Z] [ERROR] Failed to execute goal on project xy:
> Could not resolve dependencies for project xy: The following artifacts could
> not be resolved: edu.tum.cs:cup-runtime:jar:11a,
> org.checkerframework:checker-qual:jar:2.5.7, org.ow2.asm:asm:jar:7.2,
> cglib:cglib:jar:3.3.0: Could not find artifact edu.tum.cs:cup-runtime:jar:11a
> -> [Help 1]
> [2019-11-18T16:46:30.894Z]
> org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute
> goal on project xy: Could not resolve dependencies for project xy: The
> following artifacts could not be resolved: edu.tum.cs:cup-runtime:jar:11a,
> org.checkerframework:checker-qual:jar:2.5.7, org.ow2.asm:asm:jar:7.2,
> cglib:cglib:jar:3.3.0: Could not find artifact edu.tum.cs:cup-runtime:jar:11a
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.getDependencies
> (LifecycleDependencyResolver.java:269)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.resolveProjectDependencies
> (LifecycleDependencyResolver.java:147)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.ensureDependenciesAreResolved
> (MojoExecutor.java:248)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:156)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:148)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject
> (LifecycleModuleBuilder.java:117)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl.buildProject
> (SmartBuilderImpl.java:205)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl$ProjectBuildTask.run
> (SmartBuilderImpl.java:77)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
> [2019-11-18T16:46:30.894Z] at java.util.concurrent.FutureTask.run
> (FutureTask.java:264)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor.runWorker
> (ThreadPoolExecutor.java:1128)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run
> (ThreadPoolExecutor.java:628)
> [2019-11-18T16:46:30.894Z] at java.lang.Thread.run (Thread.java:834)
> [2019-11-18T16:46:30.894Z] Caused by:
> org.apache.maven.project.DependencyResolutionException: Could not resolve
> dependencies for project xy: The following artifacts could not be resolved:
> edu.tum.cs:cup-runtime:jar:11a, org.checkerframework:checker-qual:jar:2.5.7,
> org.ow2.asm:asm:jar:7.2, cglib:cglib:jar:3.3.0: Could not find artifact
> edu.tum.cs:cup-runtime:jar:11a
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.project.DefaultProjectDependenciesResolver.resolve
> (DefaultProjectDependenciesResolver.java:209)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.getDependencies
> (LifecycleDependencyResolver.java:243)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.resolveProjectDependencies
> (LifecycleDependencyResolver.java:147)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.ensureDependenciesAreResolved
> (MojoExecutor.java:248)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:156)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:148)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject
> (LifecycleModuleBuilder.java:117)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl.buildProject
> (SmartBuilderImpl.java:205)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl$ProjectBuildTask.run
> (SmartBuilderImpl.java:77)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
> [2019-11-18T16:46:30.894Z] at java.util.concurrent.FutureTask.run
> (FutureTask.java:264)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor.runWorker
> (ThreadPoolExecutor.java:1128)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run
> (ThreadPoolExecutor.java:628)
> [2019-11-18T16:46:30.894Z] at java.lang.Thread.run (Thread.java:834)
> [2019-11-18T16:46:30.894Z] Caused by:
> org.eclipse.aether.resolution.DependencyResolutionException: The following
> artifacts could not be resolved: edu.tum.cs:cup-runtime:jar:11a,
> org.checkerframework:checker-qual:jar:2.5.7, org.ow2.asm:asm:jar:7.2,
> cglib:cglib:jar:3.3.0: Could not find artifact edu.tum.cs:cup-runtime:jar:11a
> [2019-11-18T16:46:30.894Z] at
> org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies
> (DefaultRepositorySystem.java:357)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.project.DefaultProjectDependenciesResolver.resolve
> (DefaultProjectDependenciesResolver.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.getDependencies
> (LifecycleDependencyResolver.java:243)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.resolveProjectDependencies
> (LifecycleDependencyResolver.java:147)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.ensureDependenciesAreResolved
> (MojoExecutor.java:248)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:156)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:148)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject
> (LifecycleModuleBuilder.java:117)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl.buildProject
> (SmartBuilderImpl.java:205)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl$ProjectBuildTask.run
> (SmartBuilderImpl.java:77)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
> [2019-11-18T16:46:30.894Z] at java.util.concurrent.FutureTask.run
> (FutureTask.java:264)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor.runWorker
> (ThreadPoolExecutor.java:1128)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run
> (ThreadPoolExecutor.java:628)
> [2019-11-18T16:46:30.894Z] at java.lang.Thread.run (Thread.java:834)
> [2019-11-18T16:46:30.894Z] Caused by:
> org.eclipse.aether.resolution.ArtifactResolutionException: The following
> artifacts could not be resolved: edu.tum.cs:cup-runtime:jar:11a,
> org.checkerframework:checker-qual:jar:2.5.7, org.ow2.asm:asm:jar:7.2,
> cglib:cglib:jar:3.3.0: Could not find artifact edu.tum.cs:cup-runtime:jar:11a
> [2019-11-18T16:46:30.894Z] at
> org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve
> (DefaultArtifactResolver.java:424)
> [2019-11-18T16:46:30.894Z] at
> org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts
> (DefaultArtifactResolver.java:229)
> [2019-11-18T16:46:30.894Z] at
> org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies
> (DefaultRepositorySystem.java:340)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.project.DefaultProjectDependenciesResolver.resolve
> (DefaultProjectDependenciesResolver.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.getDependencies
> (LifecycleDependencyResolver.java:243)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.resolveProjectDependencies
> (LifecycleDependencyResolver.java:147)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.ensureDependenciesAreResolved
> (MojoExecutor.java:248)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:156)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:148)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject
> (LifecycleModuleBuilder.java:117)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl.buildProject
> (SmartBuilderImpl.java:205)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl$ProjectBuildTask.run
> (SmartBuilderImpl.java:77)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
> [2019-11-18T16:46:30.894Z] at java.util.concurrent.FutureTask.run
> (FutureTask.java:264)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor.runWorker
> (ThreadPoolExecutor.java:1128)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run
> (ThreadPoolExecutor.java:628)
> [2019-11-18T16:46:30.894Z] at java.lang.Thread.run (Thread.java:834)
> [2019-11-18T16:46:30.894Z] Caused by:
> org.eclipse.aether.transfer.ArtifactNotFoundException: Could not find
> artifact edu.tum.cs:cup-runtime:jar:11a
> [2019-11-18T16:46:30.894Z] at
> org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve
> (DefaultArtifactResolver.java:414)
> [2019-11-18T16:46:30.894Z] at
> org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts
> (DefaultArtifactResolver.java:229)
> [2019-11-18T16:46:30.894Z] at
> org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies
> (DefaultRepositorySystem.java:340)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.project.DefaultProjectDependenciesResolver.resolve
> (DefaultProjectDependenciesResolver.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.getDependencies
> (LifecycleDependencyResolver.java:243)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleDependencyResolver.resolveProjectDependencies
> (LifecycleDependencyResolver.java:147)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.ensureDependenciesAreResolved
> (MojoExecutor.java:248)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:202)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:156)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.MojoExecutor.execute
> (MojoExecutor.java:148)
> [2019-11-18T16:46:30.894Z] at
> org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject
> (LifecycleModuleBuilder.java:117)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl.buildProject
> (SmartBuilderImpl.java:205)
> [2019-11-18T16:46:30.894Z] at
> io.takari.maven.builder.smart.SmartBuilderImpl$ProjectBuildTask.run
> (SmartBuilderImpl.java:77)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
> [2019-11-18T16:46:30.894Z] at java.util.concurrent.FutureTask.run
> (FutureTask.java:264)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor.runWorker
> (ThreadPoolExecutor.java:1128)
> [2019-11-18T16:46:30.894Z] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run
> (ThreadPoolExecutor.java:628)
> [2019-11-18T16:46:30.894Z] at java.lang.Thread.run (Thread.java:834)
> {code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
