angular icon indicating copy to clipboard operation
angular copied to clipboard

Worker process did not return a WorkResponse

Open mhaertwig opened this issue 1 year ago • 12 comments

Which @angular/* package(s) are the source of the bug?

bazel

Is this a regression?

Yes

Description

When building our library with bazel we're getting the following error during the ng_package rule:

https://github.com/sbb-design-systems/sbb-angular/runs/7335481766?check_suite_focus=true

[470 / 476] Compiling Angular templates (full devmode) //src/angular/autocomplete:autocomplete; 0s remote-cache, worker ... (3 actions, 2 running)
ERROR: /home/runner/work/sbb-angular/sbb-angular/src/journey-maps/BUILD.bazel:38:11: Bundling types (src/journey-maps/journey-maps_public_index.d.ts) failed: Worker process did not return a WorkResponse:
---8<---8<--- Start of log, file at /home/runner/.cache/bazel/_bazel_runner/ffb965d3[66](https://github.com/sbb-design-systems/sbb-angular/runs/7335481766?check_suite_focus=true#step:7:67)b78d9d290bb95018fa337f/bazel-workers/worker-5-BundlingTypes.log ---8<---8<---
(empty)
---8<---8<--- End of log ---8<---8<---

(see e.g. this link).

This happens since about two weeks when updating dependencies (e.g. rxjs to v7.5.6 or zone.js to v0.11.7). Sometimes this error can be solved by re-building and sometimes the bug occurs only after some builds. Therefore I'm not really able to narrow this bug more down.

Thanks for your help!

Please provide the exception or error you saw

[470 / 476] Compiling Angular templates (full devmode) //src/angular/autocomplete:autocomplete; 0s remote-cache, worker ... (3 actions, 2 running)
ERROR: /home/runner/work/sbb-angular/sbb-angular/src/journey-maps/BUILD.bazel:38:11: Bundling types (src/journey-maps/journey-maps_public_index.d.ts) failed: Worker process did not return a WorkResponse:
---8<---8<--- Start of log, file at /home/runner/.cache/bazel/_bazel_runner/ffb965d366b78d9d290bb95018fa337f/bazel-workers/worker-5-BundlingTypes.log ---8<---8<---
(empty)
---8<---8<--- End of log ---8<---8<---
INFO: Elapsed time: 230.387s, Critical Path: 39.13s
INFO: 559 processes: 28 disk cache hit, 432 internal, 37 linux-sandbox, 1 local, 61 worker.
FAILED: Build did NOT complete successfully
FAILED: Build did NOT complete successfully
Error: Command failed: bazelisk build src/... --build_tag_filters=-release-package,-prod-showcase
    at checkExecSyncError (node:child_process:828:11)
    at execSync (node:child_process:899:15)
    at exec (/home/runner/work/sbb-angular/sbb-angular/scripts/build.ts:191:26)
    at buildAllTargets (/home/runner/work/sbb-angular/sbb-angular/scripts/build.ts:55:3)
    at Object.handler (/home/runner/work/sbb-angular/sbb-angular/scripts/build.ts:30:22)
    at /home/runner/work/sbb-angular/sbb-angular/node_modules/yargs/build/index.cjs:1:8891
    at j (/home/runner/work/sbb-angular/sbb-angular/node_modules/yargs/build/index.cjs:1:4956)
    at M.handleValidationAndGetResult (/home/runner/work/sbb-angular/sbb-angular/node_modules/yargs/build/index.cjs:1:8860)
    at M.applyMiddlewareAndGetResult (/home/runner/work/sbb-angular/sbb-angular/node_modules/yargs/build/index.cjs:1:9502) {
  status: 1,
  signal: null,
  output: [ null, null, null ],
  pid: 2271,
  stdout: null,
  stderr: null
}
Error: Process completed with exit code 1.

Please provide the environment you discovered this bug in (run ng version)

Angular CLI: 14.1.0
Node: 16.16.0
Package Manager: yarn 1.22.18 
OS: linux x64

Angular: 14.1.0
... animations, bazel, cdk, cli, common, compiler, compiler-cli
... core, elements, forms, language-service, localize
... platform-browser, platform-browser-dynamic, platform-server
... router

Package                          Version
----------------------------------------------------------     
@angular-devkit/architect        0.1401.0                      
@angular-devkit/build-angular    14.1.0                        
@angular-devkit/core             14.1.0                        
@angular-devkit/schematics       14.1.0                        
@angular-devkit/schematics-cli   14.1.0
@angular/dev-infra-private       0.0.0-4b8b706a0cd6ae9bc542fe74417040375239aeeb
@bazel/bazelisk                  1.12.0
@bazel/buildifier                5.1.0
@bazel/buildozer                 5.1.0
@bazel/concatjs                  5.5.2
@bazel/esbuild                   5.5.2
@bazel/ibazel                    v0.16.2
@bazel/jasmine                   5.5.2
@bazel/protractor                5.5.2
@bazel/rollup                    5.5.2
@bazel/runfiles                  5.5.2
@bazel/worker                    5.5.2
@schematics/angular              14.1.0
rxjs                             7.5.5
typescript                       4.7.2

Anything else?

No response

mhaertwig avatar Jul 25 '22 14:07 mhaertwig

This can happen when Microsoft API extractor prints to stdout and conflicts with the Bazel worker IPC also using stdout.

Potentially there are some warnings with type bundling. You can try running the type bundling without workers to unveil these

devversion avatar Jul 26 '22 17:07 devversion

Thank you for your answer! Could you give us a hint on how to do that?

kyubisation avatar Jul 26 '22 20:07 kyubisation

You can turn off the workers for type bundling by using --strategy=BundlingTypes=remote,sandboxed,local. Once you set that up and perform a build locally, you potentially will see some warnings/console output in between.

The odd thing is that it happens randomly. The key part is that we need to figure out if the types bundling worker (or Microsoft's API extractor) accidentally prints to stdout

devversion avatar Jul 27 '22 07:07 devversion

@mhaertwig I want to clarify that the disabling of worker mode is recommended only for debugging, to figure out what leaks to the stdout and breaks the IPC. Long-term I would definitely recommend keeping the workers, especially for packages with many entry-points this should pay-off (that's part of the reason we supported workers here)

Please report back to the issue if you see some log output, otherwise this issue will float around and we should close it I think

devversion avatar Jul 27 '22 14:07 devversion

@devversion Thanks a lot for the help and explanation! Our build is now working and I am closing this issue.

We decided to temporarily turn off the workers to fix our build and deactivate this quick-fix again after having solved the warnings.

mhaertwig avatar Jul 28 '22 09:07 mhaertwig

@mhaertwig Do you have a commit or something you could share? Technically nothing should pollute stdout from API extractor since we provided a custom logging utility, but if something leaks through, then that's a bug we should try to fix

devversion avatar Jul 28 '22 11:07 devversion

@devversion I'll make more in-depth analyses next week and will inform you about my findings.

mhaertwig avatar Jul 28 '22 12:07 mhaertwig

@mhaertwig Awesome, thanks! Let me know if I can help

devversion avatar Jul 28 '22 12:07 devversion

You can turn off the workers for type bundling by using --strategy=BundlingTypes=remote,sandboxed,local. Once you set that up and perform a build locally, you potentially will see some warnings/console output in between.

@devversion The build works fine with --strategy=BundlingTypes=remote,sandboxed,local but unfortunately I don't see any additional logging output in the console.

  • Here's an example output of a failing build: error.log
  • And here's a build with strategy=BundlingTypes... set: no_error.log

I've tried different build flags and increased the log level but could not find any stdout from the API extractor that could break the build. Do you maybe have an advice what else I could try?

Thanks a lot.

mhaertwig avatar Aug 03 '22 10:08 mhaertwig

@mhaertwig Okay, I have new information. If there is no log output polluting stdout, then a similar scenario can be reproduced if e.g. the worker script/or Microsoft API extractor would call process.exit(1). If such cases, the worker just exits immediately but does never respond with the WorkResponse, nor is the stdout/stderr transported/captured.

So maybe something like this happens. Potentially there is an error logged in the worker, but the script just exits immediately before the log output/error messages can be transported back to Bazel through the stdout WorkResponse proto.

devversion avatar Aug 03 '22 11:08 devversion

Worker debug mode can be enabled with sed -i "s#DEBUG = false#DEBUG = true#" node_modules/@bazel/worker/src/worker.js (when added as a postinstall for example). unfortunately though there still wouldn't be any log output when the worker processes immediately exit with process.exit

Maybe an idea would be to hop into node_modules/@bazel/worker/src/worker.js and capturing/writing the log output from stderr to a file that you can inspect when it randomly fails.

devversion avatar Aug 03 '22 11:08 devversion

I think the best you can do is add something like the following to the process.stderr.write patch in worker.js

require('fs').writeFileSync('/tmp/worker-log.txt', output, 'utf8');

And if you can then reproduce the failure locally, just print the /tmp/worker-log.txt file to see if there is anything inside it. I was able to see something but I'm not quite sure it's the root cause or an artifact from debugging:

/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/google-protobuf/google-protobuf.js:87
goog.object.getAllPropertyNames=function(a,b,c){if(!a)return[];if(!Object.getOwnPropertyNames||!Object.getPrototypeOf)return goog.object.getKeys(a);for(var d={};a&&(a!==Object.prototype||b)&&(a!==Function.prototype||c);){for(var e=Object.getOwnPropertyNames(a),f=0;f<e.length;f++)d[e[f]]=!0;a=Object.getPrototypeOf(a)}return goog.object.getKeys(d)};goog.object.getSuperClass=function(a){return(a=Object.getPrototypeOf(a.prototype))&&a.constructor};goog.debug={};goog.debug.Error=function(a){if(Error.captureStackTrace)Error.captureStackTrace(this,goog.debug.Error);else{var b=Error().stack;b&&(this.stack=b)}a&&(this.message=String(a));this.reportErrorToServer=!0};goog.inherits(goog.debug.Error,Error);goog.debug.Error.prototype.name="CustomError";goog.dom={};goog.dom.NodeType={ELEMENT:1,ATTRIBUTE:2,TEXT:3,CDATA_SECTION:4,ENTITY_REFERENCE:5,ENTITY:6,PROCESSING_INSTRUCTION:7,COMMENT:8,DOCUMENT:9,DOCUMENT_TYPE:10,DOCUMENT_FRAGMENT:11,NOTATION:12};goog.asserts={};goog.asserts.ENABLE_ASSERTS=goog.DEBUG;goog.asserts.AssertionError=function(a,b){goog.debug.Error.call(this,goog.asserts.subs_(a,b));this.messagePattern=a};goog.inherits(goog.asserts.AssertionError,goog.debug.Error);goog.asserts.AssertionError.prototype.name="AssertionError";goog.asserts.DEFAULT_ERROR_HANDLER=function(a){throw a;};goog.asserts.errorHandler_=goog.asserts.DEFAULT_ERROR_HANDLER;
                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        ^
AssertionError: Failure: Invalid byte length!
    at new goog.asserts.AssertionError (/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/google-protobuf/google-protobuf.js:87:1065)
    at Object.goog.asserts.fail (/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/google-protobuf/google-protobuf.js:90:89)
    at jspb.BinaryDecoder.readBytes (/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/google-protobuf/google-protobuf.js:369:276)
    at jspb.BinaryReader.readBytes (/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/google-protobuf/google-protobuf.js:395:405)
    at Function.deserialize (/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/@bazel/worker/src/worker_protocol.js:70:53)
    at /usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/@bazel/worker/src/worker_protocol.js:181:127
    at jspb.BinaryReader.readMessage (/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/google-protobuf/google-protobuf.js:385:329)
    at Function.deserialize (/usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/@bazel/worker/src/worker_protocol.js:181:36)
    at /usr/local/google/home/pgschwendtner/.cache/bazel/_bazel_pgschwendtner/d04a0e0cf549b212ace7f74876dda8dd/execroot/sbb_angular/node_modules/@bazel/worker/src/worker.js:97:73
    at Generator.next (<anonymous>)

devversion avatar Aug 03 '22 12:08 devversion

Thanks a lot! I can confirm the above error occurs exactly at the moment the build breaks.

I am currently adding debug statements everywhere to find out what causes the bug. I'll keep you updated.

mhaertwig avatar Aug 03 '22 15:08 mhaertwig

Thanks for confirming. Interestingly this code seems to break before the actual type bundle worker logic runs. It seems to fail when parsing the WorkRequest delivered through stdin. Either:

  • Bazel is sending an incomplete proto buffer
  • @bazel/worker is parsing incorrectly (e.g. buffer is incomplete)
  • @bazel/worker uses a different version of the proto

I would need to investigate further, but I think we are getting closer.

devversion avatar Aug 03 '22 15:08 devversion

I started analyzing the stdin buffer to narrow the bug more down. Finally I found this code, removed it and all its usages.

I don't want to get too excited yet but the error did not occur since several builds. Could this be the reason?

mhaertwig avatar Aug 04 '22 15:08 mhaertwig

Oh interesting. Do you have more details on why you think this might mess with the stdin proto/buffer? Last time I checked the protobuf reading through stdin failed when it tried to read the Input#digest of the Bazel input.

devversion avatar Aug 04 '22 15:08 devversion

To be honest I have no idea and currently do some try and error to find the reason for the failing build.

I've wrapped the deserialize function in line 97 of the worker.js in a try / catch block and printed the content of the corresponding chunk to a file. The above linked file was on top of this chunk. Therefore I deleted it and replaced all Point types with any. After that the build worked again. However, I am really not sure if my changes are responsible for that or if it's just temporary and the pipeline will fail again, soon.

mhaertwig avatar Aug 04 '22 15:08 mhaertwig

If it works like that, then this is good additional info for the worker issue. I would need to look more into this and also inspect the buffer. Potentially there is a bug with @bazel/worker.

devversion avatar Aug 05 '22 07:08 devversion

The above linked workaround was not the reason for the failing build. I have no further ideas and use your --strategy=BundlingTypes=remote,sandboxed,local fix as a temporary solution.

It would be great if you find the time have a deeper look into this issue. Let me know if I can help you somehow.

mhaertwig avatar Aug 08 '22 10:08 mhaertwig

I likely won't have time to dive into this soon. Glad the workaround is working though.

devversion avatar Aug 09 '22 18:08 devversion