Uploaded image for project: 'Maven Resolver'
  1. Maven Resolver
  2. MRESOLVER-153

resolver-status.properties file is corrupted due to concurrent writes

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 1.6.1
    • Fix Version/s: 1.6.3, 1.7.0
    • Component/s: Resolver
    • Labels:
      None
    • Environment:
      OSX 11.1 on adoptopenjdk-11.0.8+10

      Description

      In our integration tests which run with Maven 4.0.0-alpha-1-SNAPSHOT after this commit, we face the following error:

      [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)
      

      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:

      [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
      

      We created a Maven integration test 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?

        Attachments

        1. gdmr.txt
          1 kB
          Naga Vijayapuram
        2. gdmr.txt
          1 kB
          Naga Vijayapuram
        3. image-2021-06-05-10-00-08-542.png
          11 kB
          Naga Vijayapuram
        4. screenshot-1.png
          14 kB
          Guy Brand
        5. with-global-sync-context.txt
          61 kB
          Guy Brand
        6. without-global-sync-context.txt
          154 kB
          Guy Brand

          Issue Links

            Activity

              People

              • Assignee:
                michael-o Michael Osipov
                Reporter:
                Brand Guy Brand
              • Votes:
                1 Vote for this issue
                Watchers:
                7 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: