Unresolvable dependency leading to hard to debug issues

[maxime-michel]

I have OS X and org.openrewrite.maven.ChangeParentPom is working fine locally. On our CI agent where I'd like to make it run for a batch of projects, I've noticed:

• the change is never done (although other recipes do work)
• with version 5.5.2 and up until version 5.17.0, I am told there were changes (even though I can't see them)
• with version 5.17.0+ (and I suppose Maven POM downloader optimizations rewrite#3822), there are no changes and the message below is no longer present:

[WARNING] Changes have been made to pom.xml by:
[WARNING]     info.magnolia.rewrite.UseExtensionsPoms
[WARNING]         org.openrewrite.maven.ChangeParentPom: {oldGroupId=info.magnolia.services.maven.poms, newGroupId=info.magnolia.maven.poms-extensions, oldArtifactId=magnolia-services-incubator-pom, newArtifactId=magnolia-parent-pom-extensions, newVersion=60-SNAPSHOT}
[WARNING] Please review and commit the results.

My rewrite.yml:

type: specs.openrewrite.org/v1beta/recipe
name: info.magnolia.rewrite.UseExtensionsPoms
recipeList:
- org.openrewrite.maven.ChangeParentPom:
    oldGroupId: info.magnolia.services.maven.poms
    newGroupId: info.magnolia.maven.poms-extensions
    oldArtifactId: magnolia-services-incubator-pom
    newArtifactId: magnolia-parent-pom-extensions
    newVersion: 60-SNAPSHOT

How I run it: mvn org.openrewrite.maven:rewrite-maven-plugin:5.17.1:run -Drewrite.activeRecipes=info.magnolia.rewrite.UseExtensionsPoms

CI agent has Maven 3.9.6 and JDK 11.0.21+9. I'm now hours into this and still completely puzzled, so I figured I'd create this, at least to signal the possible problem with the upstream change above.

Sample pom:

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
  <modelVersion>4.0.0</modelVersion>
  <parent>
    <groupId>info.magnolia.services.maven.poms</groupId>
    <artifactId>magnolia-services-incubator-pom</artifactId>
    <version>2.3</version>
  </parent>

  <groupId>info.magnolia.ai</groupId>
  <artifactId>magnolia-openai-automations</artifactId>
  <version>1.0.8-SNAPSHOT</version>
</project>

[ammachado]

I had a similar issue. I have a set of recipes that includes a ChangeParentPom, but when I ran it, all files except pom.xml were changed.

In my case, the issue was related to a custom settings.xml file that was using <mirrorOf>*,!a,!b</mirrorOf> and the repositories did not have the corresponding <id>a</id> and <id>b</id> tags.

Hope that helps.

[maxime-michel]

Thanks, that's interesting and I've been running some tests with settings this morning. No luck so far however. How did you find out that this was the problem, though?

[ammachado]

I was having inconsistent wall-clock run times for the same set of recipes, during the day and on different machines (ranging from 33s to 1h45m). You can add -Drewrite.metricsUrl=LOG to your maven command line and get some statistics on what's happening (it wasn't working, the patch you mentioned fixed it). In my case, the numbers related to Maven downloads were higher.

[maxime-michel]

Alright, this is a little embarrassing but here we go. After tearing down my Maven settings, running the recipe locally and remotely many times, in Docker, etc. I ended up understanding that the main difference between my local env. and my CI is that… the target pom for this recipe was not published properly.

Outside of this error on my end, I must say that I was quite misled by OpenRewrite. Now that I can come up with clear reproduction steps, I would like to submit an improvement. Should it be here or with OpenRewrite directly?

[timtebeek]

Hi @maxime-michel ; thanks for wanting to improve the experience in the face of unexpected issues; what kind of change would you think would help here? I think we ought to have logged something already if a pom or jar failed to download, but can't determine that from the above.

[maxime-michel]

Hey @timtebeek, thanks for getting back to me. Fully agree with you, my last message wasn't clear. I wanted to come back to this issue but got caught up with other tasks.

In any case, in my setup at least, the issue boils down to OpenRewrite not failing nor issuing a warning in the case where the dependency isn't available. I can reproduce the case fairly easily where the maven-dependency-plugin will raise a red flag immediately trying to grab the artifact, whereas OpenRewrite (or at least the ChangeParentPom recipe) will just ignore its absence, which can lead users in unproductive debugging directions, as it is a natural Maven behaviour to fail explicitly in the case of unresolvable deps.

[timtebeek]

Indeed we still try to proceed when there's issues with the project setup, which might be uncommon, but allows us to support a wider range of projects and modernizations even in the light of perceived small issues. In this case I would have imagined we would have at least logged a warning about failing to resolve dependencies, which might lead to missing types. Did you see anything like that?

[maxime-michel]

Nope. So just to recap my findings; according to me, at least in my setup, if you use said recipe like so:

- org.openrewrite.maven.ChangeParentPom:
    oldGroupId: <CURRENT_PROJECT_GID>
    newGroupId: abc
    oldArtifactId: <CURRENT_PROJECT_AID>
    newArtifactId: xyz
    newVersion: 1.2.3

Where mvn org.apache.maven.plugins:maven-dependency-plugin:RELEASE:get -Dartifact=abc:xyz:1.2.3:pom results in:

[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  5.208 s
[INFO] Finished at: 2024-01-15T11:03:23+01:00
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-dependency-plugin:3.6.1:get (default-cli) on project cloudinary-parent: Couldn't download artifact: org.eclipse.aether.resolution.DependencyResolutionException: The following artifacts could not be resolved: abc:xyz:pom:1.2.3 (absent): abc:xyz:pom:1.2.3 was not found in https://… during a previous attempt. This failure was cached in the local repository and resolution is not reattempted until the update interval of magnolia.nexus has elapsed or updates are forced -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException

You will, instead of a warning, see a perfectly fine output like:

[INFO] <<< rewrite:5.17.1:run (default-cli) < process-test-classes @ cloudinary-media-widget-integration <<<
[INFO]
[INFO]
[INFO] --- rewrite:5.17.1:run (default-cli) @ cloudinary-media-widget-integration ---
[INFO] Using active recipe(s) [info.magnolia.rewrite.MigrateToExtension]
[INFO] Using active styles(s) []
[INFO] Validating active recipes...
[INFO] Project [Cloudinary Magnolia Module] Resolving Poms...
[INFO] Project [Cloudinary Magnolia Module] Parsing source files
[INFO] Project [Magnolia External DAM Cloudinary connector module] Parsing source files
[INFO] Project [cloudinary-media-widget-integration Magnolia Module] Parsing source files
[INFO] Running recipe(s)...
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary for Cloudinary Magnolia Module 1.2.2-SNAPSHOT:
[INFO]
[INFO] Cloudinary Magnolia Module ......................... SUCCESS [  0.914 s]
[INFO] Magnolia External DAM Cloudinary connector module .. SUCCESS [  0.422 s]
[INFO] cloudinary-media-widget-integration Magnolia Module  SUCCESS [ 10.711 s]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  12.212 s
[INFO] Finished at: 2024-01-15T11:09:26+01:00
[INFO] ------------------------------------------------------------------------

[timtebeek]

Good to know! I guess we have a parity issue between the Maven and Gradle plugin then; in the Gradle plugin when we fail to resolve dependencies we log a warning about potentially missing type information. Looks like the same would be hepful for the Maven plugin.

[ammachado]

@timtebeek this is still happening on 5.21.0, the recipes run and they don't apply changes to pom files only.

[timtebeek]

Thanks to @ammachado the latest snapshot of the Maven plugin contains a listener to help troubleshoot any download issues. Feel free to give that a try and report back here with your findings. I'll keep this issue open for a while, but we'd need input to make this actionable.

[timtebeek]

And now also available in this release: https://github.com/openrewrite/rewrite-maven-plugin/releases/tag/v5.23.1

[maxime-michel]

Thanks for not dropping the ball on this issue! I did give it a quick try but unfortunately can't report a tremendous improvement. Using the following rewrite.yml:

---
type: specs.openrewrite.org/v1beta/recipe
name: com.yourorg.ChangeParentPomExample
displayName: Change Maven parent example
recipeList:
  - org.openrewrite.maven.ChangeParentPom:
      oldGroupId: <CURRENT_GID>
      newGroupId: abc
      oldArtifactId: <CURRENT_AID>
      newArtifactId: xyz
      newVersion: 1.2.3

And this one-liner: mvn -X org.openrewrite.maven:rewrite-maven-plugin:5.23.1:run -Drewrite.activeRecipes=com.yourorg.ChangeParentPomExample

The build didn't fail and the verbose logs didn't even include one single mention of this non-existent abc:xyz:123 parent pom. 🤔

[timtebeek]

That all looks ok to me; and is it still the case that this works fine on OS X, but is only an issue on your CI agent?

[maxime-michel]

I tried that on my local OS X machine only, however, this CI agent / OS X difference was only a beginning hypothesis, the problem later turned out to not be related to that at all, as far as I can see at least. In any case, it should be easy enough for anybody to try this out on any Maven project thanks to the steps I outlined in my last message.

[maxime-michel]

Hey, I stumbled on this again. Running org.openrewrite.maven.ChangeParentPom on a module, I saw in the logs:

[DEBUG] Downloaded org.bouncycastle:bcutil-jdk18on:1.78.1 from <REDACTED>
[DEBUG] org.openrewrite.maven.MavenDownloadingExceptions
    at org.openrewrite.maven.MavenDownloadingExceptions.append (MavenDownloadingExceptions.java:44)
    at org.openrewrite.maven.tree.MavenResolutionResult.resolveDependencies (MavenResolutionResult.java:179)
    at org.openrewrite.maven.MavenParser.parseInputs (MavenParser.java:116)
    at org.openrewrite.Parser.parse (Parser.java:59)
    at org.openrewrite.maven.MavenMojoProjectParser.parseMaven (MavenMojoProjectParser.java:557)
    at org.openrewrite.maven.MavenMojoProjectParser.listSourceFiles (MavenMojoProjectParser.java:149)
    at org.openrewrite.maven.AbstractRewriteMojo.loadSourceSet (AbstractRewriteMojo.java:258)
    at org.openrewrite.maven.AbstractRewriteMojo.listResults (AbstractRewriteMojo.java:240)
    at org.openrewrite.maven.AbstractRewriteRunMojo.execute (AbstractRewriteRunMojo.java:62)
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:126)
    at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute2 (MojoExecutor.java:328)
    at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute (MojoExecutor.java:316)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:212)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:174)
    at org.apache.maven.lifecycle.internal.MojoExecutor.access$000 (MojoExecutor.java:75)
    at org.apache.maven.lifecycle.internal.MojoExecutor$1.run (MojoExecutor.java:162)
    at org.apache.maven.plugin.DefaultMojosExecutionStrategy.execute (DefaultMojosExecutionStrategy.java:39)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:159)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:105)
    at io.takari.maven.builder.smart.SmartBuilderImpl.buildProject (SmartBuilderImpl.java:209)
    at io.takari.maven.builder.smart.SmartBuilderImpl$ProjectBuildTask.run (SmartBuilderImpl.java:81)
    at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:539)
    at java.util.concurrent.FutureTask.run (FutureTask.java:264)
    at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1136)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:635)
    at java.lang.Thread.run (Thread.java:833)
    Suppressed: org.openrewrite.maven.MavenDownloadingException: jakarta.persistence:jakarta.persistence-api:${jakarta-persistence-api.version} failed. Could not resolve property
        at org.openrewrite.maven.tree.ResolvedPom.resolveDependencies (ResolvedPom.java:828)
        at org.openrewrite.maven.tree.ResolvedPom.resolveDependencies (ResolvedPom.java:754)
        at org.openrewrite.maven.tree.MavenResolutionResult.resolveDependencies (MavenResolutionResult.java:174)
        at org.openrewrite.maven.MavenParser.parseInputs (MavenParser.java:116)
        at org.openrewrite.Parser.parse (Parser.java:59)
        at org.openrewrite.maven.MavenMojoProjectParser.parseMaven (MavenMojoProjectParser.java:557)
        at org.openrewrite.maven.MavenMojoProjectParser.listSourceFiles (MavenMojoProjectParser.java:149)
        at org.openrewrite.maven.AbstractRewriteMojo.loadSourceSet (AbstractRewriteMojo.java:258)
        at org.openrewrite.maven.AbstractRewriteMojo.listResults (AbstractRewriteMojo.java:240)
        at org.openrewrite.maven.AbstractRewriteRunMojo.execute (AbstractRewriteRunMojo.java:62)
        at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:126)
        at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute2 (MojoExecutor.java:328)
        at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute (MojoExecutor.java:316)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:212)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:174)
        at org.apache.maven.lifecycle.internal.MojoExecutor.access$000 (MojoExecutor.java:75)
        at org.apache.maven.lifecycle.internal.MojoExecutor$1.run (MojoExecutor.java:162)
        at org.apache.maven.plugin.DefaultMojosExecutionStrategy.execute (DefaultMojosExecutionStrategy.java:39)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:159)
        at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:105)
        at io.takari.maven.builder.smart.SmartBuilderImpl.buildProject (SmartBuilderImpl.java:209)
        at io.takari.maven.builder.smart.SmartBuilderImpl$ProjectBuildTask.run (SmartBuilderImpl.java:81)
        at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:539)
        at java.util.concurrent.FutureTask.run (FutureTask.java:264)
        at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1136)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:635)
        at java.lang.Thread.run (Thread.java:833)

This is much better than before, as I now have a hint. However, the build went through overnight and succeeded! Meaning I thought I'd setup OpenRewrite to perform certain tasks, it's successful and I still end with the change not performed. I looked at the Maven plugin configuration page but couldn't find any option to make the presence of such an exception fail the build. Could this be further improved?

[maxime-michel]

BTW the above error is unfortunately not even in our own code.

[timtebeek]

I believe this has been addressed with this contribution:

• adjusted MavenMojoProjectParser#logParseErrors to also log poms which… #833

Whenever there are failures to parse pom.xml files you should now see those in the regular (non debug) output instead, to indicate that there are issues to fix before we're able to reliably make code changes.

Hope that works well for you too!

[maxime-michel]

Well, thanks for coming back to this, however, I am still of the opinion that in the case of erroneous poms, it should be possible, if not by default, at least with a flag such as failOnError=true, to prevent the build from going forwards. One might not necessarily spot errors in the logs, and refactorings might also be run by nightly jobs.

[timtebeek]

Thanks for the feedback! If you'd like to complete block recipe runs on any parse error then I suppose that'd be doable by touching some of those same lines and instead of logging throw an exception. Welcome to open a draft that reads such an argument to discuss this there.

[timtebeek]

Well, thanks for coming back to this, however, I am still of the opinion that in the case of erroneous poms, it should be possible, if not by default, at least with a flag such as failOnError=true, to prevent the build from going forwards. One might not necessarily spot errors in the logs, and refactorings might also be run by nightly jobs.

Hi again! We also found that logging isn't working out great on a larger scale, so we've pushed a follow up change to fail by default f592159...59404e5

Note the use of MojoFailureException, which still allows users to ignore partial failures if they really want to, and how we've pulled forward this feedback to where we parse the Maven pom files, as opposed to reporting these failures at the end. I hope that helps!

[maxime-michel]

Awesome, thank you! This is still pretty high up in my list but it keeps getting pushed down. Trying this out should be easy, however, I'll let you know soon.

[maxime-michel]

Well, unfortunately, I have mixed results to share. First of all, I don't remember where exactly I was able to trigger the error I shared on May 3rd, so can't attempt reproducing that.

Second issue is that the recipe which should fail due to a non-existing target parent pom which I shared on February 22nd is still not failing with 5.40.2.