Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

POM Parse Errors are under-reported by Maven plugin #4353

Closed
nmck257 opened this issue Jul 24, 2024 · 3 comments
Closed

POM Parse Errors are under-reported by Maven plugin #4353

nmck257 opened this issue Jul 24, 2024 · 3 comments
Assignees
@nmck257
Labels
bug Something isn't working

Comments

@nmck257
Copy link
Collaborator

nmck257 commented Jul 24, 2024

This might end up as a change in the plugin itself, but, starting the issue here in case we want to tweak the parsing exception handling.
I wanted to get some design alignment; gonna put my thoughts at the bottom.

What version of OpenRewrite are you using?

I am using

  • OpenRewrite v8.29.0
  • Maven plugin v5.35.0

What is the smallest, simplest way to reproduce the problem?

Create a pom.xml like this:

<?xml version="1.0" encoding="UTF-8"?>
<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>
                    
    <groupId>com.sample</groupId>
    <artifactId>sample</artifactId>
    <version>1.0.0-SNAPSHOT</version>
    <packaging>jar</packaging>
                    
    <properties>
        <aws-sdk-java.versin>1.11.658</aws-sdk-java.versin>
    </properties>
    <dependencies>
        <dependency>
            <groupId>com.amazonaws</groupId>
            <artifactId>aws-java-sdk-s3</artifactId>
            <version>${aws-sdk-java.version}</version>
        </dependency>
        <dependency>
            <groupId>com.amazonaws</groupId>
            <artifactId>aws-java-sdk-s3</artifactId>
            <version>1.12.646</version>
        </dependency>
    </dependencies>
</project>

And run any old recipe in debug mode:

mvn -X org.openrewrite.maven:rewrite-maven-plugin:5.35.0:run -Drewrite.activeRecipes=org.openrewrite.maven.cleanup.DependencyManagementDependencyRequiresVersion

And see logs like this:

[INFO] Using active recipe(s) [org.openrewrite.maven.cleanup.DependencyManagementDependencyRequiresVersion]
[INFO] Using active styles(s) []
[DEBUG] Dependency collection stats {ConflictMarker.analyzeTime=1760714, ConflictMarker.markTime=648347, ConflictMarker.nodeCount=1197, ConflictIdSorter.graphTime=720622, ConflictIdSorter.topsortTime=105634, ConflictIdSorter.conflictIdCount=102, ConflictIdSorter.conflictIdCycleCount=0, ConflictResolver.totalTime=9998905, ConflictResolver.conflictItemCount=289, DfDependencyCollector.collectTime=801171899, DfDependencyCollector.transformTime=13292813}
[DEBUG] No rewrite configuration found at I:\ds\projects\tmp\dummy-pom\rewrite.yml
[INFO] Validating active recipes...
[INFO] Project [sample] Resolving Poms...
[DEBUG] 
org.openrewrite.maven.MavenDownloadingExceptions
    at org.openrewrite.maven.MavenDownloadingExceptions.append (MavenDownloadingExceptions.java:44)
    at org.openrewrite.maven.tree.MavenResolutionResult.resolveDependencies (MavenResolutionResult.java:180)
    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:552)
    at org.openrewrite.maven.MavenMojoProjectParser.listSourceFiles (MavenMojoProjectParser.java:144)
    at org.openrewrite.maven.AbstractRewriteBaseRunMojo.loadSourceSet (AbstractRewriteBaseRunMojo.java:135)
    at org.openrewrite.maven.AbstractRewriteBaseRunMojo.listResults (AbstractRewriteBaseRunMojo.java:117)
    at org.openrewrite.maven.AbstractRewriteRunMojo.execute (AbstractRewriteRunMojo.java:63)
    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 org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:73)
    at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:53)
    at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:118)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:261)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:173)
    at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:101)
    at org.apache.maven.cli.MavenCli.execute (MavenCli.java:903)
    at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:280)
    at org.apache.maven.cli.MavenCli.main (MavenCli.java:203)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invoke (DirectMethodHandleAccessor.java:103)
    at java.lang.reflect.Method.invoke (Method.java:580)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:255)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:201)
    at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:361)
    at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:314)
    Suppressed: org.openrewrite.maven.MavenDownloadingException: Could not resolve property
        at org.openrewrite.maven.tree.ResolvedPom.resolveDependencies (ResolvedPom.java:904)
        at org.openrewrite.maven.tree.ResolvedPom.resolveDependencies (ResolvedPom.java:829)
        at org.openrewrite.maven.tree.MavenResolutionResult.resolveDependencies (MavenResolutionResult.java:175)
        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:552)
        at org.openrewrite.maven.MavenMojoProjectParser.listSourceFiles (MavenMojoProjectParser.java:144)
        at org.openrewrite.maven.AbstractRewriteBaseRunMojo.loadSourceSet (AbstractRewriteBaseRunMojo.java:135)
        at org.openrewrite.maven.AbstractRewriteBaseRunMojo.listResults (AbstractRewriteBaseRunMojo.java:117)
        at org.openrewrite.maven.AbstractRewriteRunMojo.execute (AbstractRewriteRunMojo.java:63)
        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 org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:73)
        at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:53)
        at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:118)
        at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:261)
        at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:173)
        at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:101)
        at org.apache.maven.cli.MavenCli.execute (MavenCli.java:903)
        at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:280)
        at org.apache.maven.cli.MavenCli.main (MavenCli.java:203)
        at jdk.internal.reflect.DirectMethodHandleAccessor.invoke (DirectMethodHandleAccessor.java:103)
        at java.lang.reflect.Method.invoke (Method.java:580)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:255)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:201)
        at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:361)
        at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:314)
[DEBUG] Project [sample] Base directory : 'I:\ds\projects\tmp\dummy-pom'
[DEBUG] Project [sample]   Collected Maven POM : 'I:\ds\projects\tmp\dummy-pom\pom.xml'
[DEBUG] Project [sample]   Maven Source : 'I:\ds\projects\tmp\dummy-pom\pom.xml'
[INFO] Project [sample] Parsing source files
[DEBUG] Project [sample] Scanned 0 resource files in main scope.
[DEBUG] Project [sample] Scanned 0 resource files in test scope.
[DEBUG] Project [sample] Parsed 1 additional files found within the project.
[INFO] Running recipe(s)...
[DEBUG] Using SLF4J as the default logging framework
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  17.396 s
[INFO] Finished at: 2024-07-24T11:52:11-04:00
[INFO] ------------------------------------------------------------------------

The key detail is that the stack trace is a debug log, and there are no other (info) statements even acknowledging the issue.
Conversely, other types of parsing issues do reliably print visible logs, eg:

[WARNING] There were problems parsing some source files
[WARNING] There were problems parsing src\main\resources\junk.yml
[WARNING] org.yaml.snakeyaml.parser.ParserException: while parsing a block mapping
 in 'reader', line 1, column 1:
    temp:
    ^
expected <block end>, but found '-'
 in 'reader', line 5, column 1:
    - junk"
    ^

  org.yaml.snakeyaml.parser.ParserImpl$ParseBlockMappingKey.produce(ParserImpl.java:654)
  org.yaml.snakeyaml.parser.ParserImpl.peekEvent(ParserImpl.java:161)
  org.yaml.snakeyaml.parser.ParserImpl.getEvent(ParserImpl.java:170)
[INFO] Running recipe(s)...

A unit test case can reproduce the same core parsing exception, though the ExecutionContext error listener is naturally different:

@Test
void foo() {
    rewriteRun(
        pomXml("""
                <?xml version="1.0" encoding="UTF-8"?>
                <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>
                                    
                    <groupId>com.sample</groupId>
                    <artifactId>sample</artifactId>
                    <version>1.0.0-SNAPSHOT</version>
                    <packaging>jar</packaging>
                                    
                    <properties>
                        <aws-sdk-java.versin>1.11.658</aws-sdk-java.versin>
                    </properties>
                    <dependencies>
                        <dependency>
                            <groupId>com.amazonaws</groupId>
                            <artifactId>aws-java-sdk-s3</artifactId>
                            <version>${aws-sdk-java.version}</version>
                        </dependency>
                        <dependency>
                            <groupId>com.amazonaws</groupId>
                            <artifactId>aws-java-sdk-s3</artifactId>
                            <version>1.12.646</version>
                        </dependency>
                    </dependencies>
                </project>
                """)
    );
}

yields this exception:

java.lang.AssertionError: Failed to parse sources or run recipe
	at org.openrewrite.test.RewriteTest.lambda$defaultExecutionContext$15(RewriteTest.java:633)
	at org.openrewrite.maven.MavenParser.parseInputs(MavenParser.java:127)
	at org.openrewrite.test.RewriteTest.rewriteRun(RewriteTest.java:284)
	at org.openrewrite.test.RewriteTest.rewriteRun(RewriteTest.java:133)
	at org.openrewrite.test.RewriteTest.rewriteRun(RewriteTest.java:128)
	at SandboxTest.foo(SandboxTest.java:9)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
Caused by: org.openrewrite.maven.MavenDownloadingExceptions
	at org.openrewrite.maven.MavenDownloadingExceptions.append(MavenDownloadingExceptions.java:44)
	at org.openrewrite.maven.tree.MavenResolutionResult.resolveDependencies(MavenResolutionResult.java:180)
	at org.openrewrite.maven.MavenParser.parseInputs(MavenParser.java:116)
	... 7 more
	Suppressed: org.openrewrite.maven.MavenDownloadingException: Could not resolve property
		at org.openrewrite.maven.tree.ResolvedPom.resolveDependencies(ResolvedPom.java:904)
		at org.openrewrite.maven.tree.ResolvedPom.resolveDependencies(ResolvedPom.java:829)
		at org.openrewrite.maven.tree.MavenResolutionResult.resolveDependencies(MavenResolutionResult.java:175)
		... 8 more

Note that I'm not particularly concerned with the underlying parsing exception shown in this example (eg openrewrite getting confused about redundant dependency declarations which rely on properties), but, we may want to fix that at some point too :)

Are you interested in contributing a fix to OpenRewrite?

Yes, but I'd like a second opinion on the exact solution.

In the current experience, when debug logging is not enabled, an unparseable yaml file (eg) gets a brief log statement, and the recipe proceeds with all the files it can parse. That feels reasonable. If we can't resolve a pom, we log nothing and silently proceed -- but the impact is higher, as failure to produce the maven resolution result will also cause issues in java recipes which rely on that maven metadata, and those can now fail in strange ways (in addition to being unable to transform the pom itself). That feels bad.

One option is adjusting the log severity. Currently, the ExecutionContext onError listener for the Maven plugin logs everything to DEBUG. That could be increased to INFO or higher? And/or we could introduce an onWarning listener to ExecutionContext to allow a bit more granularity in recipe process' error reporting? That might be broadly useful?

Another option could be tweaking the plugin's MavenMojoProjectParser such that similar logParseErrors logic runs at the "Resolving poms..." stage, too.

I'm not sure to what extent other recipe entry points (eg gradle plugin) have a similar opportunity.
Thoughts?
@nmck257 nmck257 added the bug Something isn't working label Jul 24, 2024
@timtebeek timtebeek moved this to Backlog in OpenRewrite Jul 24, 2024
@timtebeek
Copy link
Contributor

Oh wow; I'd have expected Maven would balk at that aws-sdk-java.versin vs aws-sdk-java.version, but I guess not. Then indeed probably best to surface that we failed to parse the XML and produce a meaningful Maven model.

Having learned from these two I'd prefer something subtle versus showing a complete stacktrace, even if this failure is a higher priority.

Something that briefly acknowledges that the Maven pom.xml failed to produce a Maven model, and the implications on recipe runs should help stay ahead of such issues.

@nmck257
Copy link
Collaborator Author

nmck257 commented Jul 26, 2024

Yeah, that's seeming reasonable -- will see if I can get a PR up next week

@nmck257 nmck257 mentioned this issue Aug 7, 2024
Merged
3 tasks
@timtebeek
Copy link
Contributor

@github-project-automation github-project-automation bot moved this from Backlog to Done in OpenRewrite Aug 9, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@nmck257 nmck257

Labels
bug Something isn't working
Projects
OpenRewrite
Archived in project
Milestone
No milestone
Development

No branches or pull requests
2 participants
@timtebeek @nmck257