Guy Brand created MRESOLVER-153:
-----------------------------------

             Summary: resolver-status.properties file is corrupted due to 
concurrent writes
                 Key: MRESOLVER-153
                 URL: https://issues.apache.org/jira/browse/MRESOLVER-153
             Project: Maven Resolver
          Issue Type: Bug
          Components: Resolver
    Affects Versions: 1.6.1
         Environment: OSX 11.1 on adoptopenjdk-11.0.8+10
            Reporter: Guy Brand


In our integration tests which run with Maven {{4.0.0-alpha-1-SNAPSHOT}} after 
[this 
commit|https://github.com/apache/maven/commit/7c7de41562a8d83635e8fa21c3a3340298b508a1],
 we face the following error:
{code:java}
[main] [INFO] 
------------------------------------------------------------------------
[main] [INFO] BUILD FAILURE
[main] [INFO] 
------------------------------------------------------------------------
[main] [INFO] Total time: 0.243 s
[main] [INFO] Finished at: 2020-12-23T13:48:59+01:00
[main] [INFO] 
------------------------------------------------------------------------
[main] [ERROR] Malformed \uxxxx encoding.
java.lang.IllegalArgumentException: Malformed \uxxxx encoding.
 at java.util.Properties.loadConvert (Properties.java:675)
 at java.util.Properties.load0 (Properties.java:451)
 at java.util.Properties.load (Properties.java:404)
 at org.eclipse.aether.internal.impl.TrackingFileManager.read 
(TrackingFileManager.java:56)
 at org.eclipse.aether.internal.impl.DefaultUpdateCheckManager.read 
(DefaultUpdateCheckManager.java:511)
 at org.eclipse.aether.internal.impl.DefaultUpdateCheckManager.checkMetadata 
(DefaultUpdateCheckManager.java:250)
 at org.eclipse.aether.internal.impl.DefaultMetadataResolver.resolve 
(DefaultMetadataResolver.java:302)
 at org.eclipse.aether.internal.impl.DefaultMetadataResolver.resolveMetadata 
(DefaultMetadataResolver.java:181)
 at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveMetadata 
(DefaultRepositorySystem.java:277)
 at 
org.apache.maven.plugin.version.internal.DefaultPluginVersionResolver.resolveFromRepository
 (DefaultPluginVersionResolver.java:134)
 at 
org.apache.maven.plugin.version.internal.DefaultPluginVersionResolver.resolve 
(DefaultPluginVersionResolver.java:97)
 at 
org.apache.maven.lifecycle.internal.LifecyclePluginResolver.resolveMissingPluginVersions
 (LifecyclePluginResolver.java:67)
 at 
org.apache.maven.lifecycle.internal.DefaultLifecycleTaskSegmentCalculator.calculateTaskSegments
 (DefaultLifecycleTaskSegmentCalculator.java:104)
 at 
org.apache.maven.lifecycle.internal.DefaultLifecycleTaskSegmentCalculator.calculateTaskSegments
 (DefaultLifecycleTaskSegmentCalculator.java:86)
 at org.apache.maven.lifecycle.internal.LifecycleStarter.execute 
(LifecycleStarter.java:92)
 at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:321)
 at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:206)
 at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:119)
 at org.apache.maven.cli.MavenCli.execute (MavenCli.java:982)
 at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:296)
 at org.apache.maven.cli.MavenCli.main (MavenCli.java:200)
 at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
 at jdk.internal.reflect.NativeMethodAccessorImpl.invoke 
(NativeMethodAccessorImpl.java:62)
 at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke 
(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke (Method.java:566)
 at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced 
(Launcher.java:282)
 at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:225)
 at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode 
(Launcher.java:406)
 at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:347)
{code}
It's not consistently failing and OSX based CI agents fail more often than 
Linux or Windows ones. After some investigations we saw that as part of 
https://issues.apache.org/jira/browse/MRESOLVER-132 the synchronization has 
been removed on the {{TrackingFileManager}} 
([https://github.com/apache/maven-resolver/pull/67]). This now leads to 
concurrent writes on the {{resolver-status.properties}} file in our tests and 
causes the error during the {{Properties#load()}} method wich then throws the 
above error. See this screenshot on how these files look like (cannot add the 
text here as {{null}} characters aren't shown):

When enabling debug log we also see that the {{DefaultMetadataResolver}} 
threads try to write concurrently to this file:
{code:java}
[DefaultMetadataResolver-0-0] [INFO] Downloading from custom-repo2: 
https://repo.maven.apache.org/maven2/mng-xxxx-concurrent-writes-to-resolver-status-file/plugin/maven-metadata.xml
[DefaultMetadataResolver-0-2] [INFO] Downloading from central-proxy: 
https://repo.maven.apache.org/maven2/mng-xxxx-concurrent-writes-to-resolver-status-file/plugin/maven-metadata.xml
[DefaultMetadataResolver-0-1] [INFO] Downloading from custom-repo: 
https://repository.apache.org/snapshots/mng-xxxx-concurrent-writes-to-resolver-status-file/plugin/maven-metadata.xml
[DefaultMetadataResolver-0-1] [DEBUG] Writing tracking file 
/.../core-it-suite/target/test-classes/mng-xxxx-concurrent-writes-to-resolver-status-file/repo/mng-xxxx-concurrent-writes-to-resolver-status-file/plugin/resolver-status.properties
[DefaultMetadataResolver-0-2] [DEBUG] Writing tracking file 
/.../core-it-suite/target/test-classes/mng-xxxx-concurrent-writes-to-resolver-status-file/repo/mng-xxxx-concurrent-writes-to-resolver-status-file/plugin/resolver-status.properties
[DefaultMetadataResolver-0-0] [DEBUG] Writing tracking file 
/.../core-it-suite/target/test-classes/mng-xxxx-concurrent-writes-to-resolver-status-file/repo/mng-xxxx-concurrent-writes-to-resolver-status-file/plugin/resolver-status.properties
{code}
We [created a Maven integration 
test|https://github.com/guylabs/maven-integration-testing/commit/56edeb28895a6704ad28e76655ee792d19797a8c]
 which reproduces the issue. The test is not always failing as in some runs the 
{{null}} characters are normalized to {{\u0000}} Strings and then written back 
to the {{resolver-status.properties}} file which then can be read properly by 
the {{Properties#load()}} method. You can monitor the 
{{core-it-suite/target/test-classes/mng-xxxx-concurrent-writes-to-resolver-status-file/repo/mng-xxxx-concurrent-writes-to-resolver-status-file/plugin/resolver-status.properties}}
 file while running the test as there you'll see the corrupted updates.

Readding the thread synchronization to the {{TrackingFileManager}} would solve 
this race condition, as file locking is indeed not required as stated in 
MRESOLVER-132.

Can we get this change into a new Maven {{4.0.0-alpha-1-SNAPSHOT}} version to 
be able to test the fix?



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Reply via email to