Remote worker execution sometimes fails with exit -1

[ulfjack]

I split this out from #3251. I get this exception:

java.io.IOException: Cannot run program "/tmp/remote.pTK0EkckA/build-0121c395-7267-4941-abb9-405621684cdf/external/bazel_tools/tools/jdk/ijar/ijar" (in directory "/tmp/remote.pTK0EkckA/build-0121c395-7267-4941-abb9-405621684cdf"): error=26, Text file busy
	at java.lang.ProcessBuilder.start(ProcessBuilder.java:1048)
	at com.google.devtools.build.lib.shell.JavaSubprocessFactory.create(JavaSubprocessFactory.java:116)
	at com.google.devtools.build.lib.shell.SubprocessBuilder.start(SubprocessBuilder.java:194)
	at com.google.devtools.build.lib.shell.Command.startProcess(Command.java:738)
	at com.google.devtools.build.lib.shell.Command.doExecute(Command.java:705)
	at com.google.devtools.build.lib.shell.Command.execute(Command.java:418)
	at com.google.devtools.build.remote.WatcherServer.execute(WatcherServer.java:250)
	at com.google.devtools.build.remote.WatcherServer.watch(WatcherServer.java:318)
	at com.google.watcher.v1.WatcherGrpc$MethodHandlers.invoke(WatcherGrpc.java:214)
	at io.grpc.stub.ServerCalls$1$1.onHalfClose(ServerCalls.java:148)
	at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:262)
	at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$2.runInContext(ServerImpl.java:572)
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:52)
	at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:117)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: error=26, Text file busy
	at java.lang.UNIXProcess.forkAndExec(Native Method)
	at java.lang.UNIXProcess.<init>(UNIXProcess.java:247)
	at java.lang.ProcessImpl.start(ProcessImpl.java:134)
	at java.lang.ProcessBuilder.start(ProcessBuilder.java:1029)
	... 16 more

I am highly confident that it's this bug:
https://bugs.openjdk.java.net/browse/JDK-8068370

I.e., the problem is that there's a race when multiple threads try to fork and exec binaries that were recently written to disk. The underlying problem is that Linux has no API to do this reliably (as far as we can tell). Workarounds are either to retry when it happens, to use a helper process to do the forking, or otherwise serialize the forking.

[ulfjack]

If this becomes more pressing, the best we can do is retry the subprocess execution, with the downside that that could hide other errors.

[ola-rozenfeld]

Wait, this is an IOException, not a CommandException or AbnormalTerminationException. That means after my fix is in, it will be converted to INTERNAL status and retried by the client.
Still bad, but probably will eliminate it in practice.

[ulfjack]

This was happening less often because I accidentally made all remote execution single-threaded. :-( Now that we've fixed that, I can see this happening fairly commonly, so we should have a fix for this before we release.

[ulfjack]

Ola says that it still happens even after my change, so reopening this.

[buchgr]

This was happening less often because I accidentally made all remote execution single-threaded. :-(

So even always calling fork in the same thread does not solve the problem?

[ulfjack]

I'm not sure which version Ola was looking at. I've never personally seen it happen with the single-threaded impl.

[ulfjack]

I haven't had time to test the current workaround, so I'm not how likely it is.

[ulfjack]

This might be lower priority if it's actually rare.

[buchgr]

@ulfjack
Ok, I am having a look. I have also not seen it in the single threaded version. I am working on an implementation that has a single thread dedicated to spawning processes and then to asynchronously collect the results. Will let you know once I have results.

[AustinSchuh]

@ulfjack We've seen this in mainline bazel a couple times in our verification builds.

[ola-rozenfeld]

I just tried to run:
while bazel --host_jvm_args=-Dbazel.DigestFunction=SHA1 clean && bazel --host_jvm_args=-Dbazel.DigestFunction=SHA1 build --remote_accept_cached=false --remote_local_fallback=false --remote_timeout=3600 --spawn_strategy=remote --verbose_failures=true --tls_enabled=false --auth_enabled=false --remote_cache=localhost:8080 --remote_executor=localhost:8080 --jobs=20 //src:bazel; do echo; done
With a worker also having --jobs=20.
Took ~25 iterations to reproduce the error.

[buchgr]

I could also reproduce it on third run using it Ola's command.

[buchgr]

So I have a fix that seems to work reliably. I had it running for 4 hours with 128 concurrent actions on a cloud vm with 64 cores, as well as with 40 jobs for an hour on my workstation and I haven't experienced the error once.

The fix is to have a single thread dedicated to launching the process and then waiting for its completion asynchronously - very straightforward.

I ll provide a CL soonish.

[buchgr]

I am marking this a release blocker, since we already have a fix for it and thus should also include it in 0.5.4.