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

Forked javac annotation processing error stack trace not logged for non-English locales #336

Closed
kriegaex opened this issue Dec 16, 2023 · 9 comments · Fixed by #337
Closed
Labels

Comments

@kriegaex
Copy link
Contributor

kriegaex commented Dec 16, 2023

I first thought that I am dealing with a problem in Maven Compiler Plugin, so I created MCOMPILER-566 earlier today. Copying the information from there to here:

When analysing MCOMPILER-424, at some point I wanted to know what happens if I set fork=true or forceJavacCompilerUse=true. The result was bad: No matter if I compile with mvn -e -X or verbose=true, I only see a CompilationFailureException: Compilation failure. There seems to be no way to actually see the underlying root cause. I have to compile in process via Plexus JavaxToolsCompiler to see the AnnotationTypeMismatchException from this comment.

It is not helpful to know that compilation failed, but not why.

Intermediate result: I added some debug statements into org.codehaus.plexus.compiler.javac.JavacCompiler::compileOutOfProcess:

returnCode = CommandLineUtils.executeCommandLine(cli, out, out);
System.out.println("### plexus javac return code: " + returnCode);
System.out.println("### plexus javac output:\n" + out.getOutput());
messages = parseModernStream(returnCode, new BufferedReader(new StringReader(out.getOutput())));
System.out.println("### plexus javac messages: " + messages);

The Maven console log when running with the latest Maven Compiler and latest Plexus Compiler (sorry for interspersed German messages due to locale auto detection):

[INFO] Compiling 1 source file with javac [forked debug release 17] to target\classes
### plexus javac return code: 3
### plexus javac output:
Processor ran!
[org.example.MyFirstAnnotation]
[errorRaised=false, rootElements=[org.example.AnnotatedClass], processingOver=false]
Warnung: No SupportedSourceVersion annotation found on org.example.Processor, returning RELEASE_6.
Warnung: Unterst�tzte Quellversion "RELEASE_6" von Annotationsprozessor "org.example.Processor" kleiner als -source "17"
2 Warnungen


Ein Annotationsprozessor hat eine nicht abgefangene Ausnahme ausgel�st.
Details finden Sie im folgenden Stacktrace.
java.lang.annotation.AnnotationTypeMismatchException: Incorrectly typed data found for annotation element public abstract org.example.MySecondAnnotation org.example.MyFirstAnnotation.secondAnnotation() (Found data of type org.example.MySecondAnnotation)
	at jdk.compiler/com.sun.tools.javac.model.AnnotationProxyMaker$ValueVisitor$1AnnotationTypeMismatchExceptionProxy.generateException(AnnotationProxyMaker.java:271)
	at java.base/sun.reflect.annotation.AnnotationInvocationHandler.invoke(AnnotationInvocationHandler.java:89)
	at jdk.proxy3/jdk.proxy3.$Proxy3.secondAnnotation(Unknown Source)
	at org.example.Processor.process(Processor.java:23)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment.callProcessor(JavacProcessingEnvironment.java:1021)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment.discoverAndRunProcs(JavacProcessingEnvironment.java:937)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment$Round.run(JavacProcessingEnvironment.java:1265)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment.doProcessing(JavacProcessingEnvironment.java:1380)
	at jdk.compiler/com.sun.tools.javac.main.JavaCompiler.processAnnotations(JavaCompiler.java:1271)
	at jdk.compiler/com.sun.tools.javac.main.JavaCompiler.compile(JavaCompiler.java:948)
	at jdk.compiler/com.sun.tools.javac.main.Main.compile(Main.java:319)
	at jdk.compiler/com.sun.tools.javac.main.Main.compile(Main.java:178)
	at jdk.compiler/com.sun.tools.javac.Main.compile(Main.java:64)
	at jdk.compiler/com.sun.tools.javac.Main.main(Main.java:50)

As you can see, Plexus JavacCompiler gets all the output from javac, but then somehow discards it while parsing it in JavacCompiler::parseModernStream. I have not debugged into that part yet, but it looks like a Plexus Compiler Javac bug.

BTW, this...

Ein Annotationsprozessor hat eine nicht abgefangene Ausnahme ausgelöst.
Details finden Sie im folgenden Stacktrace.

translates to:

An annotation processor threw an uncaught exception.
Consult the following stack trace for details.
@kriegaex
Copy link
Contributor Author

kriegaex commented Dec 16, 2023

OK, I debugged into JavacCompiler::parseModernStream and found this:

} else if (line.startsWith("An annotation processor threw an uncaught exception.")) {
CompilerMessage annotationProcessingError = parseAnnotationProcessorStream(input);
errors.add(annotationProcessingError);
}

I.e., the output parser actually contains hard-coded strings from the English locale. Therefore, I tried this in Maven Compiler:

<compilerArgs>
  <arg>-J-Duser.language=en_us</arg>
</compilerArgs>

And now the forked Javac actually reports:

[INFO] Compiling 1 source file with javac [forked debug release 17] to target\classes
[INFO] -------------------------------------------------------------
[ERROR] COMPILATION ERROR : 
[INFO] -------------------------------------------------------------
[ERROR] java.lang.annotation.AnnotationTypeMismatchException: Incorrectly typed data found for annotation element public abstract org.example.MySecondAnnotation org.example.MyFirstAnnotation.secondAnnotation() (Found data of type org.example.MySecondAnnotation)
	at jdk.compiler/com.sun.tools.javac.model.AnnotationProxyMaker$ValueVisitor$1AnnotationTypeMismatchExceptionProxy.generateException(AnnotationProxyMaker.java:271)
	at java.base/sun.reflect.annotation.AnnotationInvocationHandler.invoke(AnnotationInvocationHandler.java:89)
	at jdk.proxy3/jdk.proxy3.$Proxy3.secondAnnotation(Unknown Source)
	at org.example.Processor.process(Processor.java:23)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment.callProcessor(JavacProcessingEnvironment.java:1021)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment.discoverAndRunProcs(JavacProcessingEnvironment.java:937)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment$Round.run(JavacProcessingEnvironment.java:1265)
	at jdk.compiler/com.sun.tools.javac.processing.JavacProcessingEnvironment.doProcessing(JavacProcessingEnvironment.java:1380)
	at jdk.compiler/com.sun.tools.javac.main.JavaCompiler.processAnnotations(JavaCompiler.java:1271)
	at jdk.compiler/com.sun.tools.javac.main.JavaCompiler.compile(JavaCompiler.java:948)
	at jdk.compiler/com.sun.tools.javac.main.Main.compile(Main.java:319)
	at jdk.compiler/com.sun.tools.javac.main.Main.compile(Main.java:178)
	at jdk.compiler/com.sun.tools.javac.Main.compile(Main.java:64)
	at jdk.compiler/com.sun.tools.javac.Main.main(Main.java:50)
[INFO] 1 error
[INFO] -------------------------------------------------------------

That solves the problem for me, but the situation is not nice. I actually do not need German Javac output, because I am fluent in English, but I also do not override the locale manually in each project, shell and IDE on all my computers, on which of course the OS locale defaults to my native language German.

@kriegaex
Copy link
Contributor Author

kriegaex commented Dec 16, 2023

My suggestion is to change the parser in such a way that it does not silently discard messages it does not recognise, but at least reports them, if warnings or errors occur. We have seen already, that Javac return code 3 is recognised, i.e. JavacCompiler does know that something is wrong. Information hiding is not the right strategy here.

@kriegaex
Copy link
Contributor Author

kriegaex commented Dec 16, 2023

Here is the English Javac resource file from OpenJDK. On top of that, by default there are ones for Chinese, Japanese and German as well. I.e., ironically the international users with the best locale-specific JDK user experience will have the worst in Maven Compiler and Plexus.

Here is the same string from the German resource file.

If there is any good way to retrieve those messages for the current locale during runtime, maybe it would be a good idea to use them. I tried something like:

import com.sun.tools.javac.util.JavacMessages;

import java.util.Locale;

public class Dummy {
  public static void main(String[] args) {
    System.out.println(
      new JavacMessages("com.sun.tools.javac.resources.javac", Locale.getDefault())
        .getLocalizedString("javac.msg.proc.annotation.uncaught.exception").trim()
    );
  }
}

Unfortunately, both compiling and running the program needs --add-exports jdk.compiler/com.sun.tools.javac.util=ALL-UNNAMED. But then, it prints this for me:

$ java --add-exports jdk.compiler/com.sun.tools.javac.util=ALL-UNNAMED -cp target/classes Dummy
Ein Annotationsprozessor hat eine nicht abgefangene Ausnahme ausgelöst.
Details finden Sie im folgenden Stacktrace.

$ java -Duser.language=en_us --add-exports jdk.compiler/com.sun.tools.javac.util=ALL-UNNAMED -cp target/classes Dummy
An annotation processor threw an uncaught exception.
Consult the following stack trace for details.

Please note, that this difference manifests itself on JDK 21, not on JDK 17. Back then, there was no German resource file yet.

@kriegaex
Copy link
Contributor Author

kriegaex commented Dec 16, 2023

Another piece of information is that the properties files from the OpenJDK source code are compiled into classes. You can find them in classes named e.g. com.sun.tools.javac.resources.javacand com.sun.tools.javac.resources.javac_de:

image

Sorry for posting a lot of info, but I want to contribute as much as possible, before I am totally out of context and focusing on something else entirely again.

@slawekjaranowski
Copy link
Member

What do you think to always set language en for forked compiler?

We can assume that users english level is enough to understand error messages.
Another tools don't have a translated messages.

@kriegaex
Copy link
Contributor Author

kriegaex commented Dec 16, 2023

Another tools don't have a translated messages.

That is not quite true. Look at these classes from JDK 21, among others:

image

image

Not all of them are tool classes, but quite a few of them.

We can assume that users english level is enough to understand error messages.

That is true, I would also assume that.

What do you think to always set language en for forked compiler?

It would be a breaking change, if other users have been relying on and maybe even asserting on (e.g. in integration tests) locale-specific messages. It would have to be clearly documented at the very least. I personally could live with it, but I cannot speak on behalf of millions of developers around the world.

If you decide to implement it that way, it would make sense to be consistent with the other plexus compilers, too (ECJ, AspectJ and whatever else there might be).

@kriegaex
Copy link
Contributor Author

BTW, for the non-forked compiler I also expect the messages to be locale-specific. There, we simply seem to be luckier in this case, because MCOMPILER has to catch and handle the exception.

@kriegaex
Copy link
Contributor Author

kriegaex commented Dec 17, 2023

Actually, this would also work, but it is also heuristics, just like the rest of the method:

diff --git a/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java b/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java
--- a/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java	(revision Staged)
+++ b/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java	(date 1702784914893)
@@ -677,7 +677,10 @@
                 errors.add(new CompilerMessage(buffer.toString(), CompilerMessage.Kind.ERROR));
                 return errors;
             } else if (line.startsWith("An annotation processor threw an uncaught exception.")) {
-                CompilerMessage annotationProcessingError = parseAnnotationProcessorStream(input);
+                CompilerMessage annotationProcessingError = parseAnnotationProcessorStream(input, null);
+                errors.add(annotationProcessingError);
+            } else if (line.startsWith("java.lang.annotation.")) {
+                CompilerMessage annotationProcessingError = parseAnnotationProcessorStream(input, line);
                 errors.add(annotationProcessingError);
             }
 
@@ -714,9 +717,11 @@
         }
     }
 
-    private static CompilerMessage parseAnnotationProcessorStream(final BufferedReader input) throws IOException {
+    private static CompilerMessage parseAnnotationProcessorStream(
+            final BufferedReader input, final String firstLineOfStackTrace) throws IOException {
         String line = input.readLine();
         final StringBuilder buffer = new StringBuilder();
+        if (firstLineOfStackTrace != null) buffer.append(firstLineOfStackTrace);
 
         while (line != null) {
             if (!line.startsWith("Consult the following stack trace for details.")) {

Possibly, something similar could be done for the javac.msg.bug ("An exception has occurred in the compiler") branch.

Maybe some generic way to detect stack traces would be helpful, but for that purpose multi-line buffering and inspection would be necessary. It is also regrettable that the presence of the known error code is not exploited more. When knowing already that there is an error, but not finding the information we are looking for, maybe it would be better to dump more of it instead of just swallowing it, just like I said before.

@kriegaex
Copy link
Contributor Author

kriegaex commented Dec 17, 2023

Maybe some generic way to detect stack traces would be helpful

I thought about something like this, if it does not exist yet in Plexus or one of the tools it depends on:

diff --git a/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java b/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java
--- a/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java	(revision Staged)
+++ b/plexus-compilers/plexus-compiler-javac/src/main/java/org/codehaus/plexus/compiler/javac/JavacCompiler.java	(date 1702791698366)
@@ -65,6 +65,7 @@
 import java.util.Properties;
 import java.util.StringTokenizer;
 import java.util.concurrent.ConcurrentLinkedDeque;
+import java.util.regex.Pattern;
 
 import org.codehaus.plexus.compiler.AbstractCompiler;
 import org.codehaus.plexus.compiler.CompilerConfiguration;
@@ -627,6 +628,11 @@
         return new CompilerResult(success, messages);
     }
 
+    private static final Pattern STACK_TRACE_FIRST_LINE =
+            Pattern.compile("^(?:[\\w+.-]+\\.)\\w*?(?:Exception|Error|Throwable):\\s.*$");
+    private static final Pattern STACK_TRACE_OTHER_LINE =
+            Pattern.compile("^(?:Caused by:\\s.*|\\s*at .*|\\s*\\.\\.\\.\\s\\d+\\smore)$");
+
     /**
      * Parse the output from the compiler into a list of CompilerMessage objects
      *
@@ -643,6 +649,7 @@
         StringBuilder buffer = new StringBuilder();
 
         boolean hasPointer = false;
+        int stackTraceLineCount = 0;
 
         while (true) {
             line = input.readLine();
@@ -659,11 +666,27 @@
                     } else if (hasPointer) {
                         // A compiler message remains in buffer at end of parse stream
                         errors.add(parseModernError(exitCode, bufferAsString));
+                    } else if (stackTraceLineCount > 0) {
+                        // Extract stack trace from end of buffer
+                        String[] lines = bufferAsString.split("\\R");
+                        int linesTotal = lines.length;
+                        buffer = new StringBuilder();
+                        for (int i = linesTotal - stackTraceLineCount; i < linesTotal; i++) {
+                            buffer.append(lines[i]).append(EOL);
+                        }
+                        errors.add(new CompilerMessage(buffer.toString(), CompilerMessage.Kind.ERROR));
                     }
                 }
                 return errors;
             }
 
+            if (stackTraceLineCount == 0 && STACK_TRACE_FIRST_LINE.matcher(line).matches()
+                    || STACK_TRACE_OTHER_LINE.matcher(line).matches()) {
+                stackTraceLineCount++;
+            } else {
+                stackTraceLineCount = 0;
+            }
+
             // A compiler error occurred, treat everything that follows as part of the error.
             if (line.startsWith("An exception has occurred in the compiler")) {
                 buffer = new StringBuilder();
@@ -677,7 +700,7 @@
                 errors.add(new CompilerMessage(buffer.toString(), CompilerMessage.Kind.ERROR));
                 return errors;
             } else if (line.startsWith("An annotation processor threw an uncaught exception.")) {
-                CompilerMessage annotationProcessingError = parseAnnotationProcessorStream(input);
+                CompilerMessage annotationProcessingError = parseAnnotationProcessorStream(input, null);
                 errors.add(annotationProcessingError);
             }
 
@@ -714,9 +737,11 @@
         }
     }
 
-    private static CompilerMessage parseAnnotationProcessorStream(final BufferedReader input) throws IOException {
+    private static CompilerMessage parseAnnotationProcessorStream(
+            final BufferedReader input, final String firstLineOfStackTrace) throws IOException {
         String line = input.readLine();
         final StringBuilder buffer = new StringBuilder();
+        if (firstLineOfStackTrace != null) buffer.append(firstLineOfStackTrace);
 
         while (line != null) {
             if (!line.startsWith("Consult the following stack trace for details.")) {

Besides, I find the formatting rules for this dictatorial tool Spotless somewhat weird. If I do not add redundant braces in if-else, it looks even worse.

The stack trace parser might even make this part superfluous (not tested yet):

// A compiler error occurred, treat everything that follows as part of the error.
if (line.startsWith("An exception has occurred in the compiler")) {
    buffer = new StringBuilder();

    while (line != null) {
        buffer.append(line);
        buffer.append(EOL);
        line = input.readLine();
    }

    errors.add(new CompilerMessage(buffer.toString(), CompilerMessage.Kind.ERROR));
    return errors;
} else if (line.startsWith("An annotation processor threw an uncaught exception.")) {
    CompilerMessage annotationProcessingError = parseAnnotationProcessorStream(input, null);
    errors.add(annotationProcessingError);
}

If you are interested in this simple, heuristic stack trace parser, feel free to let me know, and I can create a PR.

kriegaex added a commit to dev-aspectj/plexus-compiler that referenced this issue Dec 18, 2023
Instead of two separate 'while' loops, one inline and one in an extra
method, parsing stack traces after finding error messages specific to
the English locale of the JDK, now there is generic stack trace parsing,
which works in these two cases independent of locale and also in others
previously not covered.

For backward compatibility, the Javac localized message 'javac.msg.bug'
("An exception has occurred in the compiler ... Please file a bug") is
salvaged in a locale-independent way, matching on error reporting URLs
always occurring in all JDK locales (English, Japanese, Chinese, German
as of JDK 21).

Fixes codehaus-plexus#336.
kriegaex added a commit to dev-aspectj/plexus-compiler that referenced this issue Dec 18, 2023
kriegaex added a commit to dev-aspectj/plexus-compiler that referenced this issue Dec 18, 2023
@kriegaex kriegaex changed the title Javac annotation processing error Forked javac annotation processing error silently swallowed for non-English locales Dec 18, 2023
@kriegaex kriegaex changed the title Forked javac annotation processing error silently swallowed for non-English locales Forked javac annotation processing error stack trace not logged for non-English locales Dec 18, 2023
slawekjaranowski pushed a commit that referenced this issue Dec 20, 2023
Instead of two separate 'while' loops, one inline and one in an extra
method, parsing stack traces after finding error messages specific to
the English locale of the JDK, now there is generic stack trace parsing,
which works in these two cases independent of locale and also in others
previously not covered.

For backward compatibility, the Javac localized message 'javac.msg.bug'
("An exception has occurred in the compiler ... Please file a bug") is
salvaged in a locale-independent way, matching on error reporting URLs
always occurring in all JDK locales (English, Japanese, Chinese, German
as of JDK 21).

Fixes #336
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants