Worker Spawn Runner throws "Worker process did not return a WorkResponse" with empty error message

[ThomasCJY]

Background
This is a follow-up for #11691. Previously, after enabling spawn worker for android resource merging actions, the error logs cannot be correctly displayed in console so I made this change to fix this issue. However, a recent update which is included in the 3.1.0+ bazel releases introduced another regression where all the std output and std err has been hijacked for spawn workers and worker response will always be null. This can be reproduced on this test branch:

Test branch (link)

Repro steps

1. bazelisk build //src/test:main_activity_test check the output.
   • default version is 3.4.1, where logs will be empty
2. update bazel version to be 3.0.0. Retry step 1. See the error output is different where stdout is printed.
   • You need to cherry-pick [Log] Surface error log file for manifest merging issue #11691 to have the full error message displayed
3. Remove build --config=android_workers from .bazelrc, retry step 1. Check the correct error message.

The output for step 1 looks like this, where both stdout and stderr are empty.

ERROR: /Users/jchen/01_Code/rules_jvm_external/examples/android_local_test/src/test/BUILD:6:19 Merging manifest for //src/test:main_activity_test failed: Worker process did not return a WorkResponse:

---8<---8<--- Start of log, file at /private/var/tmp/_bazel_jchen/0f8337efc7290202461be411a0f2bc48/bazel-workers/worker-7-ManifestMerger.log ---8<---8<---
(empty)
---8<---8<--- End of log ---8<---8<---

The output for step 2 will have stdout. We can apply #11691 to show the error log.

---8<---8<--- Start of log ---8<---8<---
Warning: 
See http://g.co/androidstudio/manifest-merger for more information about the manifest merger.
anifest merger.
---8<---8<--- Start of log ---8<---8<---

Ideally, after applying #11691 and fixed the regression, we would get:

---8<---8<--- Start of log ---8<---8<---
Error: /private/var/tmp/_bazel_jchen/0f8337efc7290202461be411a0f2bc48/sandbox/darwin-sandbox/83/execroot/__main__/src/test/AndroidManifest.xml:6:5-74 Error:
        uses-sdk:minSdkVersion 11 cannot be smaller than version 16 declared in library [@maven//:com_google_android_gms_play_services_ads_base] /var/folders/89/gngzz1cn74n0yt9fxth8czhw0000gp/T/manifest_merge_tmp345140065745544520/bazel-out/darwin-fastbuild/bin/external/maven/com_google_android_gms_play_services_ads_base_processed_manifest/AndroidManifest.xml
        Suggestion: use tools:overrideLibrary="com.google.android.gms.ads_base" to force usage
Aug 13, 2020 2:58:13 PM com.google.devtools.build.android.ManifestMergerAction main
SEVERE: Error during merging manifests
com.google.devtools.build.android.AndroidManifestProcessor$ManifestProcessingException: Manifest merger failed : uses-sdk:minSdkVersion 11 cannot be smaller than version 16 declared in library [@maven//:com_google_android_gms_play_services_ads_base] /var/folders/89/gngzz1cn74n0yt9fxth8czhw0000gp/T/manifest_merge_tmp345140065745544520/bazel-out/darwin-fastbuild/bin/external/maven/com_google_android_gms_play_services_ads_base_processed_manifest/AndroidManifest.xml
        Suggestion: use tools:overrideLibrary="com.google.android.gms.ads_base" to force usage
        at com.google.devtools.build.android.AndroidManifestProcessor.mergeManifest(AndroidManifestProcessor.java:186)
        at com.google.devtools.build.android.ManifestMergerAction.main(ManifestMergerAction.java:217)
        at com.google.devtools.build.android.ResourceProcessorBusyBox$Tool$5.call(ResourceProcessorBusyBox.java:93)
        at com.google.devtools.build.android.ResourceProcessorBusyBox.processRequest(ResourceProcessorBusyBox.java:233)
        at com.google.devtools.build.android.ResourceProcessorBusyBox.main(ResourceProcessorBusyBox.java:177)
---8<---8<--- Start of log ---8<---8<---

[meisterT]

cc @larsrc-google

[nkoroste]

This is super helpful for debugging, thanks @ThomasCJY

[tetromino]

I can see two steps towards fixing this.

1. Remove the stderr redirect to buffer in ResourceProcessorBusyBox, but keep the stdout redirect (because printing arbitrary error messages to stdout violates the worker protocol).
2. Take better care to dump the buffer in the correct format on worker failure.

Would fix no. 1 by itself - which is quite simple - be sufficient for you?

[tetromino]

cc @susinmotion

[ThomasCJY]

@tetromino yeah fixing no.1 will be sufficient in the current stage. Thanks!

[larsrc-google]

https://stackoverflow.com/questions/3340342/writing-to-the-real-stdout-after-system-setout talks about how to properly redirect stdout, it looks like what the current code does is incorrect.

I like the idea of redirecting stdout, though, and will add it to WorkRequestHandler.

[nkoroste]

I can't seem to repro this in Bazel 5.1.1 - not sure if anything changed?

[lukaciko]

We still see this issue with Bazel 5.1.1. The issue goes away when not using a persistent worker. I can give more info if needed.