Improve AndroidToolTask Error Reporting #7012

dellis1972 · 2022-05-19T09:49:12Z

Our build system currently isn't great at reporting Java tooling errors. Users are constantly required to turn on diagnostic
logging in order to see what causes the probem. They currently see output like this

Xamarin.Android.Common.targets: … error MSB6006: “java.exe” exited with code 1

Which is not helpful. So the problem was that in the ProcessOutput method there was an if statement to detect
java errors. If it found one, it would log that exception and then abort the processing of the output. This resulted in
only the first line of the error being logged as an actual error. The rest would be logged as typical output.

So if we detect an error we should continue to process the output so that we get the entire thing. The resulting error
will look like this in Visual Studio.

It will contain ALL the data from the error message. But also some additional information to help users unpack the
mapped directories in the lp folder.

jonathanpeppers

Is there a test we could add to just assert the error message is better now?

Maybe assert the assembly name from the AssemblyIdentityMap, and which we didn't have before?

src/Xamarin.Android.Build.Tasks/Tasks/JavaToolTask.cs

dellis1972 · 2022-05-26T14:40:16Z

Is there a test we could add to just assert the error message is better now?

Maybe assert the assembly name from the AssemblyIdentityMap, and which we didn't have before?

I could try to write a test which produces the same error message and add that.

jonpryor · 2022-05-27T00:34:33Z

@dellis1972 wrote:

The resulting error will look like this in Visual Studio.

That's, uh, kinda unreadable, as it looks like all newlines are removed. Particularly odd is all the occurrences of (TaskId:207), which should each be on their own line.

Is there a good way to preserve newlines, so that the error message is more readable?

src/Xamarin.Android.Build.Tasks/Tasks/JavaToolTask.cs

dellis1972 · 2022-05-30T10:25:49Z

@dellis1972 wrote:

The resulting error will look like this in Visual Studio.

That's, uh, kinda unreadable, as it looks like all newlines are removed. Particularly odd is all the occurrences of (TaskId:207), which should each be on their own line.

Is there a good way to preserve newlines, so that the error message is more readable?

@jonpryor I applied the changes and these are the actual results.

With the Error list collapsed.

With the Error List expanded.

src/Xamarin.Android.Build.Tasks/Tasks/JavaToolTask.cs

jonpryor · 2022-05-31T18:37:13Z

Proposed commit message:

Proposed commit message:

```markdown
[Xamarin.Android.Build.Tasks] JavaToolTask Error Reporting (#7012)

Fixes: https://github.com/xamarin/xamarin-android/issues/7009

Context: https://github.com/xamarin/monodroid/commit/b60c77feb371ba4e3b4f1aea4d8dfd4edcedcac0

Let's create a `java`-related error message!

 1. Create an `android` app:

        dotnet new -n bad_error

 2. Edit `bad_error.csproj` to change
    `$(SupportedOSPlatformVersion)`=23, and add this item group:

        <ItemGroup>
          <PackageReference Include="Xamarin.AndroidX.Wear" Version="1.2.0.5" />
          <PackageReference Include="Xamarin.Android.Wear" Version="2.2.0" />
          <PackageReference Include="Xamarin.AndroidX.PercentLayout" Version="1.0.0.14" />
          <PackageReference Include="Xamarin.AndroidX.Legacy.Support.Core.UI" Version="1.0.0.14" />
        </ItemGroup>

 3. Build

        dotnet build bad_error/bad_error.csproj

It should fail to build:

	error : java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException:
	Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar :
	android/support/v4/app/INotificationSideChannel$Stub.class

It is expected to fail.  The problem is that *why* it fails is
opaque, and thus it's very hard to know what the problem is so that
it can be fixed.

If you rebuild with diagnostic logging enabled:

	dotnet build -v diag bad_error/bad_error.csproj

We get additional, *useful*, contextual information:

	Task "D8"
	  Task Parameter:JavaMaximumHeapSize=1G
	  Task Parameter:OutputDirectory=obj/Debug/net7.0-android/android/bin/
	  Task Parameter:
	      JavaLibrariesToEmbed=
	          …/dotnet/packs/Microsoft.Android.Ref.32/33.0.0-preview.4.20/ref/net7.0/mono.android.jar
	          …
	  Task Parameter:JarPath=…/dotnet/packs/Microsoft.Android.Sdk.Darwin/33.0.0-preview.4.20/tools/r8.jar
	  …
	    processing ClassesZip, JavaLibrariesToEmbed...
	  $HOME/android-toolchain/jdk-11/bin/java -Xmx1G -classpath …/dotnet/packs/Microsoft.Android.Sdk.Darwin/33.0.0-preview.4.20/tools/r8.jar com.android.tools.r8.D8 --debug --min-api 23 --output obj/Debug/net7.0-android/android/bin/ …
	  Error in obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class:
	  Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  Compilation failed
	  Exception in thread "main" java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  	at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:98)
	  	at com.android.tools.r8.D8.main(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:4)
	  Caused by: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  	at Version.fakeStackEntry(Version_3.3.28.java:0)
	  	at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:75)
	  	…
	  Caused by: com.android.tools.r8.internal.f: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  	at com.android.tools.r8.internal.DT.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:14)
	  	…

*Now* we see what the error is:

	Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times:

The fundamental problem is that this entire process is "broken": we
shouldn't require that the project be rebuilt with diagnostic logging
enabled in order to *begin* to understand what the error was.

Part of why the original error message was so "unhelpful" was because
of an explicit attempt to produce a more "helpful" message; from
xamarin/monodroid@b60c77fe

> we need to pick out the exception and then ignore the rest of the
> infromation [sic]. We also need to produce more 'helpful' messages
> to the user for these kind of exceptions. 

In retrospect, attempting to "trim out extraneous information" was a
mistake, as it's very hard to know what is and isn't extraneous.

Improve `<JavaToolTask/>` so that we go the other way: capture *all*
output from `java`, and when an error is detected, dump out all the
output from the `java` command.  This way, instead of:

	error : java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException: …

we can provide a more complete error message *without* needing to
enable diagnostic logs:

	  error JAVA0000: Error in obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class:
	  error JAVA0000: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  error JAVA0000: Compilation failed
	  error JAVA0000: Exception in thread "main" java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  error JAVA0000: 	at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:98)
	  error JAVA0000: 	at com.android.tools.r8.D8.main(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:4)
	  error JAVA0000: Caused by: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  error JAVA0000: 	at Version.fakeStackEntry(Version_3.3.28.java:0)
	  error JAVA0000: 	at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:75)
	  error JAVA0000: 	…
	  error JAVA0000: Caused by: com.android.tools.r8.internal.f: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class
	  error JAVA0000: 	at com.android.tools.r8.internal.DT.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:14)
	  error JAVA0000: 	…

Unfortunately, this error message is still cryptic: what does
`obj/Debug/net7.0-android/lp/59/jl/classes.jar` come from?
What about `obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar`?

At the end of the full `java` output, dump a mapping of the
encountered `…/lp/…` paths to where they came from:

	error JAVA0000: Directory `obj/Debug/net7.0-android/lp/59` is from `androidx.interpolator.interpolator.aar`
	error JAVA0000: Directory `obj/Debug/net7.0-android/lp/4` is from `Xamarin.Android.Support.Compat.dll`

jonpryor · 2022-05-31T19:27:28Z

TODO: figure out why no error code is emitted.

dellis1972 · 2022-06-01T20:32:37Z

TODO: figure out why no error code is emitted.

I figured it out. The DefaultErrorCode was null. I've added a new JAVA0000 code for ALL Java Tool based errors we get (similar to JAVAC0000).

Fixes: dotnet#7009 Context: xamarin/monodroid@b60c77f Let's create a `java`-related error message! 1. Create an `android` app: dotnet new -n bad_error 2. Edit `bad_error.csproj` to change `$(SupportedOSPlatformVersion)`=23, and add this item group: <ItemGroup> <PackageReference Include="Xamarin.AndroidX.Wear" Version="1.2.0.5" /> <PackageReference Include="Xamarin.Android.Wear" Version="2.2.0" /> <PackageReference Include="Xamarin.AndroidX.PercentLayout" Version="1.0.0.14" /> <PackageReference Include="Xamarin.AndroidX.Legacy.Support.Core.UI" Version="1.0.0.14" /> </ItemGroup> 3. Build dotnet build bad_error/bad_error.csproj It should fail to build: error : java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar : android/support/v4/app/INotificationSideChannel$Stub.class It is expected to fail. The problem is that *why* it fails is opaque, and thus it's very hard to know what the problem is so that it can be fixed. If you rebuild with diagnostic logging enabled: dotnet build -v diag bad_error/bad_error.csproj We get additional, *useful*, contextual information: Task "D8" Task Parameter:JavaMaximumHeapSize=1G Task Parameter:OutputDirectory=obj/Debug/net7.0-android/android/bin/ Task Parameter: JavaLibrariesToEmbed= …/dotnet/packs/Microsoft.Android.Ref.32/33.0.0-preview.4.20/ref/net7.0/mono.android.jar … Task Parameter:JarPath=…/dotnet/packs/Microsoft.Android.Sdk.Darwin/33.0.0-preview.4.20/tools/r8.jar … processing ClassesZip, JavaLibrariesToEmbed... $HOME/android-toolchain/jdk-11/bin/java -Xmx1G -classpath …/dotnet/packs/Microsoft.Android.Sdk.Darwin/33.0.0-preview.4.20/tools/r8.jar com.android.tools.r8.D8 --debug --min-api 23 --output obj/Debug/net7.0-android/android/bin/ … Error in obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class Compilation failed Exception in thread "main" java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:98) at com.android.tools.r8.D8.main(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:4) Caused by: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class at Version.fakeStackEntry(Version_3.3.28.java:0) at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:75) … Caused by: com.android.tools.r8.internal.f: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class at com.android.tools.r8.internal.DT.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:14) … *Now* we see what the error is: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: The fundamental problem is that this entire process is "broken": we shouldn't require that the project be rebuilt with diagnostic logging enabled in order to *begin* to understand what the error was. Part of why the original error message was so "unhelpful" was because of an explicit attempt to produce a more "helpful" message; from xamarin/monodroid@b60c77fe > we need to pick out the exception and then ignore the rest of the > infromation [sic]. We also need to produce more 'helpful' messages > to the user for these kind of exceptions. In retrospect, attempting to "trim out extraneous information" was a mistake, as it's very hard to know what is and isn't extraneous. Improve `<JavaToolTask/>` so that we go the other way: capture *all* output from `java`, and when an error is detected, dump out all the output from the `java` command. This way, instead of: error : java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException: … we can provide a more complete error message *without* needing to enable diagnostic logs: error XA1234: Error in obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class: error XA1234: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class error XA1234: Compilation failed error XA1234: Exception in thread "main" java.lang.RuntimeException: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class error XA1234: at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:98) error XA1234: at com.android.tools.r8.D8.main(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:4) error XA1234: Caused by: com.android.tools.r8.CompilationFailedException: Compilation failed to complete, origin: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class error XA1234: at Version.fakeStackEntry(Version_3.3.28.java:0) error XA1234: at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:75) error XA1234: … error XA1234: Caused by: com.android.tools.r8.internal.f: Type android.support.v4.app.INotificationSideChannel$Stub is defined multiple times: obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class, obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class error XA1234: at com.android.tools.r8.internal.DT.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:14) error XA1234: … Unfortunately, this error message is still cryptic: what does `obj/Debug/net7.0-android/lp/59/jl/classes.jar` come from? What about `obj/Debug/net7.0-android/lp/4/jl/bin/classes.jar`? At the end of the full `java` output, dump a mapping of the encountered `…/lp/…` paths to where they came from: error XA1234: Directory `obj/Debug/net7.0-android/lp/59` is from `androidx.interpolator.interpolator.aar` error XA1234: Directory `obj/Debug/net7.0-android/lp/4` is from `Xamarin.Android.Support.Compat.dll`

dellis1972 force-pushed the Issue7009 branch 6 times, most recently from 729d7fb to c4f662b Compare May 25, 2022 10:33

dellis1972 changed the title ~~try this~~ Improve AndroidToolTask Error Reporting May 26, 2022

dellis1972 marked this pull request as ready for review May 26, 2022 11:29

dellis1972 requested a review from jonathanpeppers as a code owner May 26, 2022 11:29

jonathanpeppers reviewed May 26, 2022

View reviewed changes

src/Xamarin.Android.Build.Tasks/Tasks/JavaToolTask.cs Show resolved Hide resolved

dellis1972 force-pushed the Issue7009 branch from fa76abf to 68b767b Compare May 26, 2022 15:25

jonpryor reviewed May 27, 2022

View reviewed changes

src/Xamarin.Android.Build.Tasks/Tasks/JavaToolTask.cs Outdated Show resolved Hide resolved

dellis1972 force-pushed the Issue7009 branch from 68b767b to ff959e2 Compare May 27, 2022 09:24

jonpryor reviewed May 27, 2022

View reviewed changes

src/Xamarin.Android.Build.Tasks/Tasks/JavaToolTask.cs Outdated Show resolved Hide resolved

dellis1972 force-pushed the Issue7009 branch from ff959e2 to 9879dbb Compare May 30, 2022 12:28

dellis1972 requested review from jonathanpeppers and jonpryor May 31, 2022 10:19

jonathanpeppers approved these changes May 31, 2022

View reviewed changes

jonpryor reviewed May 31, 2022

View reviewed changes

src/Xamarin.Android.Build.Tasks/Tasks/JavaToolTask.cs Outdated Show resolved Hide resolved

dellis1972 force-pushed the Issue7009 branch from 43600f6 to d877149 Compare June 1, 2022 12:59

dellis1972 force-pushed the Issue7009 branch from 8186d6f to 0440e13 Compare June 6, 2022 09:10

dellis1972 force-pushed the Issue7009 branch from 0440e13 to 368dca3 Compare June 6, 2022 09:17

dellis1972 requested a review from jonathanpeppers June 7, 2022 10:18

dellis1972 requested a review from jonpryor June 7, 2022 10:18

jonpryor merged commit b002dc3 into dotnet:main Jun 7, 2022

dellis1972 deleted the Issue7009 branch June 7, 2022 15:15

jpobst mentioned this pull request Aug 9, 2022

Better report java.exe exited with code 1 error messages #6380

Closed

github-actions bot locked and limited conversation to collaborators Jan 24, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Improve AndroidToolTask Error Reporting #7012

Improve AndroidToolTask Error Reporting #7012

Uh oh!

dellis1972 commented May 19, 2022 •

edited

Loading

Uh oh!

jonathanpeppers left a comment

Uh oh!

Uh oh!

dellis1972 commented May 26, 2022

Uh oh!

jonpryor commented May 27, 2022

Uh oh!

Uh oh!

Uh oh!

dellis1972 commented May 30, 2022

Uh oh!

Uh oh!

jonpryor commented May 31, 2022 •

edited

Loading

Uh oh!

jonpryor commented May 31, 2022

Uh oh!

dellis1972 commented Jun 1, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Improve AndroidToolTask Error Reporting #7012

Improve AndroidToolTask Error Reporting #7012

Uh oh!

Conversation

dellis1972 commented May 19, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jonathanpeppers left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

dellis1972 commented May 26, 2022

Uh oh!

jonpryor commented May 27, 2022

Uh oh!

Uh oh!

Uh oh!

dellis1972 commented May 30, 2022

Uh oh!

Uh oh!

jonpryor commented May 31, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jonpryor commented May 31, 2022

Uh oh!

dellis1972 commented Jun 1, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

dellis1972 commented May 19, 2022 •

edited

Loading

jonpryor commented May 31, 2022 •

edited

Loading