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

AndroidToolTask should capture all tool output #208

Closed
jonpryor opened this issue May 18, 2023 · 5 comments
Closed

AndroidToolTask should capture all tool output #208

jonpryor opened this issue May 18, 2023 · 5 comments
Assignees
@dellis1972 @pjcollins

Comments

@jonpryor
Copy link
Member

Context: dotnet/android@b002dc3
Context: dotnet/maui#14531

Once Upon A Time™ (about a year ago), if we got a java failure, the cause of the error could be unscrutable:

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

Why did it fail? To find out we'd invariably have to ask for a diagnostic build log, because only the diagnostic build log contained the full output of r8.jar, which would contain the "root" error:

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

java invocations are not the only place this "inscrutable error messaging" scenario comes up. Enter XA3006 (via dotnet/maui#14531):

error XA3006: Could not compile native assembly file: environment.arm64-v8a.ll
error XA3006: 
error XA3006:

How helpful! How actionable!

Yet again, we need to ask for diagnostic build log information (which became a problem on its own right…).

Enough!

Update AndroidToolTask so that it provides output logging infrastructure, a'la dotnet/android@b002dc38, such that all tool output is always captured (as well as logged via LogDebugMessage()), and when an error occurs, all captured output is part of the error message.

We can then update JavaToolTask and other subclasses to use this common infrastructure.
@pjcollins
Copy link
Member

pjcollins commented Jun 16, 2023 •
edited
Loading

I've been looking into this, but haven't found any immediate areas that need improvement. With respect to AndroidToolTask:

  • AndroidToolTask extends ToolTask, which already prints all output as Normal importance messages when tool execution does not complete successfully.
  • Our AndroidRunToolTask provides a common regex that can be used to capture and report issues when running an Android SDK tool.
  • As mentioned, the JavaToolTask already works in a similar manner to AndroidRunToolTask.

With respect to maui#14531, it doesn't appear that any of the provided diagnostic build logs contained additional stdout/stderr from the llc tool invocation that failed. The error messaging in the CompileNativeAssembly task was already improved in commit 77584e02 to log stdout from the tool when a failure occurs.

We could consider adding a common System.Diagnostic.Process wrapper with log on error logic that could be re-used by tasks that inherit from AndroidAsyncTask (abstract out this piece of CompileNativeAssembly for instance), and while that would be useful for the future it wouldn't immediately improve the task.

@dellis1972 do you have any other thoughts here? Maybe I am overlooking something?

@jonpryor
Copy link
Member Author

@pjcollins: ran across an instance where I think this applies: https://dev.azure.com/devdiv/DevDiv/_workitems/edit/1875239

The scenario: the <AndroidAdb/> task fails. What gets reported to the end-user is:

MSB6006: "adb.exe" exited with code 1.

To your earlier point

  • […ToolTask] already prints all output as Normal importance messages when tool execution does not complete successfully.

"Normal" message importance doesn't help us when issues are filed and the only "useful" output is the warning or error message contents. In order to obtain "Normal" message importance we would need to request that the customer (possibly) increase build verbosity (e.g. if it's "quiet" verbosity, "Normal" won't be logged!) and then re-run their build. This is extra complexity and customer interaction that would be nice to avoid.

@jonpryor
Copy link
Member Author

jonpryor commented Aug 29, 2023 •
edited
Loading

Alternatively, the issue with https://dev.azure.com/devdiv/DevDiv/_workitems/edit/1875239 is that <Exec/> is used and not <AndroidAdb/>. The underlying point remains, though: <AndroidAdb/> doesn't capture tool output, so if (when) adb errors out, there is no "trivial" way to present the adb output to the user.

This in turn implies that we should replace all <Exec Command="…adb…"/> usage with <AndroidAdb/> usage, e.g.:

@pjcollins
Copy link
Member

Good point about Normal message priority, I overlooked the fact that Minimal verbosity is likely commonly used. I agree that there are a couple of clear areas of improvement highlighted with this latest issue. I'll try to revisit this in the near-ish future.

@jonpryor jonpryor mentioned this issue Sep 7, 2023
Merged
pjcollins added a commit that referenced this issue Apr 4, 2024
@pjcollins
[AndroidToolTask] Log tool output as error
e713c33 
Context: #208

Updates AndroidToolTask to capture all standard output from the tool and
log it as an error if the task fails.
@pjcollins pjcollins mentioned this issue Apr 4, 2024
Merged
pjcollins added a commit that referenced this issue Apr 19, 2024
@pjcollins
[AndroidToolTask] Log tool output as error (#229)
1ea4e35 
Context: #208

Updates AndroidToolTask to capture all standard output from the tool and
log it as an error if the task fails.
@pjcollins pjcollins mentioned this issue Apr 19, 2024
Merged
pjcollins added a commit to dotnet/android that referenced this issue Apr 23, 2024
@pjcollins
[AndroidToolTask] Log tool output as error (#8861)
771ee1d 
`AndroidToolTask.Execute()` logs full tool output on error

Context: dotnet/android-tools#208
Context: b002dc3

Very often the *context* to understand a tool error isn't printed to
stderr, but is instead printed earlier to stdout.  For example,
consider this annotated `r8` output snippet from
b002dc38 (`[stderr]` and `[stdout]` are
annotations):

	% $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/ …
	[stdout] Error in obj/Debug/net7.0-android/lp/59/jl/classes.jar:android/support/v4/app/INotificationSideChannel$Stub.class:
	[stdout] 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
	[stdout] Compilation failed
	[stdout] 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
	[stdout] 	at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:98)
	[stdout] 	at com.android.tools.r8.D8.main(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:4)
	[stdout] 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
	[stdout] 	at Version.fakeStackEntry(Version_3.3.28.java:0)
	[stdout] 	at com.android.tools.r8.internal.Bj.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:75)
	[stdout] 	…
	[stdout] 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
	[stdout] 	at com.android.tools.r8.internal.DT.a(R8_3.3.28_2aaf796388b4e9f6bed752d926eca110512a53a3f09a8d755196089c1cfdf799:14)
	[stdout] 	…
	[stderr] 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

When originally processed, the *only* output included in the error
message was the the only line written to stderr:

	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

The fix in b002dc38 was to update
`<JavaToolTask/>` to capture *all* output from `java …`, and when an
error occurred, dump *all* of it.

Bump to dotnet/android-tools@1ea4e35eaf which updates
`AndroidToolTask` to do the same thing, "lowering" the logic
into a common base class of `<JavaToolTask/>`: capture all output
(stdout & stderr) from the tool, and when an error occurs, log *all*
of the captured output into an `XAccc0000` error message.

`ccc` is the `AndroidToolTask.TaskPrefix` property.

The `<Exec/>` tasks that ran `adb` directly have been replaced with
`<AndroidAdb/>` instances.  This task inherits from `AndroidToolTask`
and will now benefit from improved error logging.

Changes: dotnet/android-tools@05f9a90...1ea4e35
  * dotnet/android-tools@1ea4e35: [AndroidToolTask] Log tool output as error
  * dotnet/android-tools@c8a5b5b: Check for ANDROID_HOME Sdk location on Windows
@pjcollins
Copy link
Member

I think we can close this as fixed via:

1ea4e35
dotnet/android@771ee1d

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@dellis1972 dellis1972

@pjcollins pjcollins

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@jonpryor @dellis1972 @pjcollins