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.

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

Document/enable error output - log failed recipe #198

Closed
koppor opened this issue Apr 30, 2023 · 12 comments
Closed

Document/enable error output - log failed recipe #198

koppor opened this issue Apr 30, 2023 · 12 comments
Assignees
Labels
enhancement New feature or request question Further information is requested

Comments

@koppor
Copy link
Contributor

koppor commented Apr 30, 2023

In the default configuration of the plugin, the output on my side is:

line 1:49 token recognition error at: '\'                                          
                                                                                   
> Task :rewriteRun                                                                 
line 1:0 mismatched input '<EOF>' expecting {'.', '!', '*', '..', Identifier}      
The recipe produced an error. Please report this to the recipe author.             
                                                                                   
> Task :rewriteRun FAILED                                                          
                                                                                   
FAILURE: Build failed with an exception.                                           
                                                                                   
* What went wrong:                                                                 
Execution failed for task ':rewriteRun'.                                           
> java.lang.NullPointerException                                                   

Would it be possible to output the name of the recipe in place?

@koppor
Copy link
Contributor Author

koppor commented Apr 30, 2023

Other output:

line 1:49 token recognition error at: '\'

> Task :rewriteRun FAILED
The recipe produced an error. Please report this to the recipe author.

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':rewriteRun'.
> org.openrewrite.internal.RecipeRunException

Maybe, the RecipeRunException contains some information about the receipt?

@timtebeek timtebeek added enhancement New feature or request question Further information is requested labels May 1, 2023
@timtebeek
Copy link
Contributor

Hi @koppor ! Thanks for reporting this here; I agree that we can probably do a better job of informing on the cause of a recipe failure, even in the face of unknown cases.

The RecipeRunException is indeed likely to contain the information that you're looking for; it's created here: https://github.com/openrewrite/rewrite/blob/1d7feba0fd580b0e7fc35281323c29890ae6d062/rewrite-core/src/main/java/org/openrewrite/TreeVisitor.java#L318C19-L324

From what I can find the message you've reported originates here:

public void run(ResultsContainer results) {
try {
if (results.isNotEmpty()) {
Throwable firstException = results.getFirstException();
if (firstException != null) {
logger.error("The recipe produced an error. Please report this to the recipe author.");
if(firstException instanceof RuntimeException) {
throw (RuntimeException)firstException;
} else {
throw new RuntimeException(firstException);
}
}

Seeing how RecipeRunException extends RuntimeException, I imagine that's where it's caught in recipe execution. I'm not sure if that's also the best place to log the context of the error, but thought to at least provide these details for now.

Do you see the RecipeRunException message when you run Gradle with stacktraces enabled?

@koppor
Copy link
Contributor Author

koppor commented Sep 18, 2023

Some time later, I have a similar issue.

At commit JabRef/jabref@e4c292b, update openwrite (JabRef/jabref#10392) and the bom (JabRef/jabref#10394), see NPE:

> java.lang.NullPointerException: Cannot invoke "java.util.List.iterator()" because "this.variantTypes" is null
$  ./gradlew -Dorg.gradle.jvmargs="-DXX:MaxJavaStackTraceDepth=-1" --full-stacktrace rewriteDryRun
org.gradle.api.tasks.TaskExecutionException: Execution failed for task ':rewriteDryRun'.
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.lambda$executeIfValid$1(ExecuteActionsTaskExecuter.java:149)
        at org.gradle.internal.Try$Failure.ifSuccessfulOrElse(Try.java:282)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeIfValid(ExecuteActionsTaskExecuter.java:147)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.execute(ExecuteActionsTaskExecuter.java:135)
        at org.gradle.api.internal.tasks.execution.FinalizePropertiesTaskExecuter.execute(FinalizePropertiesTaskExecuter.java:46)
        at org.gradle.api.internal.tasks.execution.ResolveTaskExecutionModeExecuter.execute(ResolveTaskExecutionModeExecuter.java:51)
        at org.gradle.api.internal.tasks.execution.SkipTaskWithNoActionsExecuter.execute(SkipTaskWithNoActionsExecuter.java:57)
        at org.gradle.api.internal.tasks.execution.SkipOnlyIfTaskExecuter.execute(SkipOnlyIfTaskExecuter.java:74)
        at org.gradle.api.internal.tasks.execution.CatchExceptionTaskExecuter.execute(CatchExceptionTaskExecuter.java:36)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.executeTask(EventFiringTaskExecuter.java:77)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.call(EventFiringTaskExecuter.java:55)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.call(EventFiringTaskExecuter.java:52)
        at org.gradle.internal.operations.DefaultBuildOperationRunner$CallableBuildOperationWorker.execute(DefaultBuildOperationRunner.java:204)
        at org.gradle.internal.operations.DefaultBuildOperationRunner$CallableBuildOperationWorker.execute(DefaultBuildOperationRunner.java:199)
        at org.gradle.internal.operations.DefaultBuildOperationRunner$2.execute(DefaultBuildOperationRunner.java:66)
        at org.gradle.internal.operations.DefaultBuildOperationRunner$2.execute(DefaultBuildOperationRunner.java:59)
        at org.gradle.internal.operations.DefaultBuildOperationRunner.execute(DefaultBuildOperationRunner.java:157)
        at org.gradle.internal.operations.DefaultBuildOperationRunner.execute(DefaultBuildOperationRunner.java:59)
        at org.gradle.internal.operations.DefaultBuildOperationRunner.call(DefaultBuildOperationRunner.java:53)
        at org.gradle.internal.operations.DefaultBuildOperationExecutor.call(DefaultBuildOperationExecutor.java:73)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter.execute(EventFiringTaskExecuter.java:52)
        at org.gradle.execution.plan.LocalTaskNodeExecutor.execute(LocalTaskNodeExecutor.java:42)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$InvokeNodeExecutorsAction.execute(DefaultTaskExecutionGraph.java:331)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$InvokeNodeExecutorsAction.execute(DefaultTaskExecutionGraph.java:318)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$BuildOperationAwareExecutionAction.lambda$execute$0(DefaultTaskExecutionGraph.java:314)
        at org.gradle.internal.operations.CurrentBuildOperationRef.with(CurrentBuildOperationRef.java:80)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$BuildOperationAwareExecutionAction.execute(DefaultTaskExecutionGraph.java:314)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$BuildOperationAwareExecutionAction.execute(DefaultTaskExecutionGraph.java:303)
        at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.execute(DefaultPlanExecutor.java:463)
        at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.run(DefaultPlanExecutor.java:380)
        at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
        at org.gradle.internal.concurrent.AbstractManagedExecutor$1.run(AbstractManagedExecutor.java:47)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base/java.lang.Thread.run(Thread.java:1623)
Caused by: java.lang.RuntimeException: java.lang.NullPointerException: Cannot invoke "java.util.List.iterator()" because "this.variantTypes" is null
        at org.openrewrite.gradle.DelegatingProjectParser.unwrapInvocationException(DelegatingProjectParser.java:155)
        at org.openrewrite.gradle.DelegatingProjectParser.dryRun(DelegatingProjectParser.java:106)
        at org.openrewrite.gradle.RewriteDryRunTask.run(RewriteDryRunTask.java:49)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
...
Caused by: java.lang.NullPointerException: Cannot invoke "java.util.List.iterator()" because "this.variantTypes" is null
        at org.openrewrite.staticanalysis.DeclarationSiteTypeVariance.validate(DeclarationSiteTypeVariance.java:72)
        at org.openrewrite.Recipe.validate(Recipe.java:283)
        at org.openrewrite.Recipe.validate(Recipe.java:286)
        at org.openrewrite.Recipe.validate(Recipe.java:286)
        at org.openrewrite.Recipe.validateAll(Recipe.java:319)
        at org.openrewrite.gradle.isolated.DefaultProjectParser.listResults(DefaultProjectParser.java:1120)
        at org.openrewrite.gradle.isolated.DefaultProjectParser.dryRun(DefaultProjectParser.java:325)
        at org.openrewrite.gradle.DelegatingProjectParser.lambda$dryRun$3(DelegatingProjectParser.java:107)
        at org.openrewrite.gradle.DelegatingProjectParser.unwrapInvocationException(DelegatingProjectParser.java:147)
        ... 122 more

I don't see a ReceipeRunException, but maybe it's hidden at the "122 more" ^^

@koppor
Copy link
Contributor Author

koppor commented Sep 18, 2023

BTW we are open to offer our (MIT-licensed) code as pre-release check. 😅 - OK, maybe our config is too complicated compared to a "normal" usage at moderne.io.

@koppor
Copy link
Contributor Author

koppor commented Sep 22, 2023

The new stacktrace shows the failed recipe:

Caused by: java.lang.NullPointerException: Cannot invoke "java.util.List.iterator()" because "this.variantTypes" is null
        at org.openrewrite.staticanalysis.DeclarationSiteTypeVariance.validate(DeclarationSiteTypeVariance.java:72)
        at org.openrewrite.Recipe.validate(Recipe.java:283)
        at org.openrewrite.Recipe.validate(Recipe.java:286)
        at org.openrewrite.Recipe.validate(Recipe.java:286)
        at org.openrewrite.Recipe.validateAll(Recipe.java:319)
        at org.openrewrite.gradle.isolated.DefaultProjectParser.listResults(DefaultProjectParser.java:1120)
        at org.openrewrite.gradle.isolated.DefaultProjectParser.dryRun(DefaultProjectParser.java:325)
        at org.openrewrite.gradle.DelegatingProjectParser.lambda$dryRun$3(DelegatingProjectParser.java:107)
        at org.openrewrite.gradle.DelegatingProjectParser.unwrapInvocationException(DelegatingProjectParser.java:147)
 ./gradlew --stacktrace rewriteDryRun

With

id 'org.openrewrite.rewrite' version '6.3.8'

@koppor
Copy link
Contributor Author

koppor commented Sep 22, 2023

I think, my wish is: Instead of crashing the whole build, the failing recipe should just be skipped!

BTW: Are you thinking of participating in #hacktoberfest?

@koppor
Copy link
Contributor Author

koppor commented Sep 22, 2023

OK, part of this error is a user error:

    @Option(displayName = "Variant types",
            description = "A list of well-known classes that have in/out type variance.",
            example = "java.util.function.Function<IN, OUT>")
    List<String> variantTypes;

This leads to another refinement:

The plugin should report that required parameters are not supplied instead of failing with a NPE.

@timtebeek
Copy link
Contributor

Sorry this took a while to get to @koppor ! One of those cases where the cause is only obvious once spotted and resolved. :/

We do validate active recipes it seems:

logger.lifecycle("Validating active recipes");
Collection<Validated<Object>> validated = recipe.validateAll(ctx, new ArrayList<>());
List<Validated.Invalid<Object>> failedValidations = validated.stream().map(Validated::failures)
.flatMap(Collection::stream).collect(toList());
if (!failedValidations.isEmpty()) {
failedValidations.forEach(failedValidation -> logger.error("Recipe validation error in {}: {}", failedValidation.getProperty(), failedValidation.getMessage(), failedValidation.getException()));
if (extension.getFailOnInvalidActiveRecipes()) {
throw new RuntimeException("Recipe validation errors detected as part of one or more activeRecipe(s). Please check error logs.");
} else {
logger.error("Recipe validation errors detected as part of one or more activeRecipe(s). Execution will continue regardless.");
}
}

We don't by default fail the recipe run when there are validation errors however

* Whether to throw an exception if an activeRecipe fails configuration validation.
* This may happen if the activeRecipe is improperly configured, or any downstream recipes are improperly configured.
* <p>
* For the time, this default is "false" to prevent one improperly recipe from failing the build.
* In the future, this default may be changed to "true" to be more restrictive.
*/
private boolean failOnInvalidActiveRecipes;

Do you indeed see the results you're looking for when you enable that option as seen here?

rewrite {
failOnInvalidActiveRecipes = true
activeRecipe("org.openrewrite.java.spring.boot2.SpringBoot1To2Migration")
}

@timtebeek
Copy link
Contributor

BTW: Are you thinking of participating in #hacktoberfest?

Hadn't looked into that yet, thanks for the reminder! Last year we added the hacktoberfest topic to openrewrite/rewrite already, as per maintainer instructions; I've similarly added that to openrewrite/rewrite-static-analysis just now. I think any issue tagged "good first issue" is a candidate for hacktoberfest as far as I'm concerned; let me know if you'd like to see more projects or issues tagged! We're definitely open to contributions.

@koppor
Copy link
Contributor Author

koppor commented Sep 26, 2023

We do validate active recipes it seems:

The exception was thrown at the validation IMHO:

Caused by: java.lang.NullPointerException: Cannot invoke "java.util.List.iterator()" because "this.variantTypes" is null
        at org.openrewrite.staticanalysis.DeclarationSiteTypeVariance.validate(DeclarationSiteTypeVariance.java:72)
        at org.openrewrite.Recipe.validate(Recipe.java:283)

The code you showed does not catch any NPE.

@timtebeek
Copy link
Contributor

Thanks! I'd missed that earlier. Now fixed in openrewrite/rewrite-static-analysis@44257d8

@timtebeek timtebeek self-assigned this Sep 26, 2023
@koppor
Copy link
Contributor Author

koppor commented Sep 28, 2023

Fix looks good.

I thought about a simple try-catch for NPE, but fixing the underlying issue is better! Yeah!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request question Further information is requested
Projects
Archived in project
Development

No branches or pull requests

2 participants