[ https://issues.apache.org/jira/browse/MRESOLVER-153?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17353690#comment-17353690 ]
Jonathan Gafner edited comment on MRESOLVER-153 at 5/29/21, 8:12 AM: --------------------------------------------------------------------- [~michael-o] updated. Still happen ``` Picked up JAVA_TOOL_OPTIONS: Dmaven.ext.class.path="/home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531/pipeline-maven-spy.jar" Dorg.jenkinsci.plugins.pipeline.maven.reportsFolder="/home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531" Apache Maven 3.8.1 (05c21c65bdfed0f71a2f2ada8b84da59348c4c5d) Maven home: /home/builder/jenkins2/tools/hudson.tasks.Maven_MavenInstallation/maven-3.8.1/apache-maven-3.8.1 Java version: 1.8.0_222, vendor: Azul Systems, Inc., runtime: /home/builder/jenkins2/tools/hudson.model.JDK/azul-jdk-zulu-8.40.0.25-8u222-b10/zulu8.40.0.25-ca-jdk8.0.222-linux_x64/jre Default locale: en_US, platform encoding: UTF-8 OS name: "linux", version: "4.14.35-1818.1.6.el7uek.x86_64", arch: "amd64", family: "unix" [INFO] [jenkins-event-spy] Generate /home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531/maven-spy-20210529-074222-7507020269431673965256.log.tmp ... [INFO] Error stacktraces are turned on. [INFO] Scanning for projects... [INFO] [INFO] < com.organization.testing:tests-suite-runner > [INFO] Building tests-suite-runner 4 [INFO] [ pom ][INFO] [INFO] BUILD FAILURE [INFO] [INFO] Total time: 1.295 s [INFO] Finished at: 2021-05-29T07:42:24Z [INFO] [INFO] [jenkins-event-spy] Generated /home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531/maven-spy-20210529-074222-7507020269431673965256.log [ERROR] Malformed \uxxxx encoding. java.lang.IllegalArgumentException: Malformed \uxxxx encoding. at java.util.Properties.loadConvert (Properties.java:574) at java.util.Properties.load0 (Properties.java:390) at java.util.Properties.load (Properties.java:341) 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.apache.maven.repository.internal.DefaultVersionRangeResolver.getVersions (DefaultVersionRangeResolver.java:198) ``` was (Author: jgafner): [~michael-o] updated. Still happen ``` Picked up JAVA_TOOL_OPTIONS: Dmaven.ext.class.path="/home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531/pipeline-maven-spy.jar" Dorg.jenkinsci.plugins.pipeline.maven.reportsFolder="/home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531" Apache Maven 3.8.1 (05c21c65bdfed0f71a2f2ada8b84da59348c4c5d) Maven home: /home/builder/jenkins2/tools/hudson.tasks.Maven_MavenInstallation/maven-3.8.1/apache-maven-3.8.1 Java version: 1.8.0_222, vendor: Azul Systems, Inc., runtime: /home/builder/jenkins2/tools/hudson.model.JDK/azul-jdk-zulu-8.40.0.25-8u222-b10/zulu8.40.0.25-ca-jdk8.0.222-linux_x64/jre Default locale: en_US, platform encoding: UTF-8 OS name: "linux", version: "4.14.35-1818.1.6.el7uek.x86_64", arch: "amd64", family: "unix" [INFO] [jenkins-event-spy] Generate /home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531/maven-spy-20210529-074222-7507020269431673965256.log.tmp ... [INFO] Error stacktraces are turned on. [INFO] Scanning for projects... [INFO] [INFO] -------------< com.organization.testing:tests-suite-runner >----------- [INFO] Building tests-suite-runner 4 [INFO] -------------------------------[ pom ]-------------------------------- [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 1.295 s [INFO] Finished at: 2021-05-29T07:42:24Z [INFO] ------------------------------------------------------------------------ [INFO] [jenkins-event-spy] Generated /home/builder/jenkins2/workspace/test@4/tests-suite-runner@tmp/withMaven37bd3531/maven-spy-20210529-074222-7507020269431673965256.log [ERROR] Malformed \uxxxx encoding. java.lang.IllegalArgumentException: Malformed \uxxxx encoding. at java.util.Properties.loadConvert (Properties.java:574) at java.util.Properties.load0 (Properties.java:390) at java.util.Properties.load (Properties.java:341) 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.apache.maven.repository.internal.DefaultVersionRangeResolver.getVersions (DefaultVersionRangeResolver.java:198) ``` > 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 > Assignee: Michael Osipov > Priority: Major > Fix For: 1.6.3, 1.7.0 > > Attachments: screenshot-1.png, with-global-sync-context.txt, > without-global-sync-context.txt > > > 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): > !screenshot-1.png! > 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)