Repository: bazelbuild/bazel
Issue: Race condition in HttpBlobStore.releaseUploadChannel
Labels: untriaged

### Description of the problem / feature request:
Builds can fail with `java.lang.RuntimeException: Unrecoverable error while evaluating node 'ActionLookupData{...}'  ...
Caused by: java.util.NoSuchElementException: io.netty.handler.codec.http.HttpRequestEncoder` when using the HttpBlobStore to cache builds.

It appears a race condition can occur in HttpBlobStore.releaseUploadChannel() when ChannelHandlerContext is closed by HttpUploadHandler.channelRead0 (when not keeping connection alive). Because ChannelHandlerContext.close runs asynchronously and closes all pipelines in reverse order (before the channel is marked as closed), HttpBlobStore.releaseUploadChannel() can be executed while channel is still open and handlers are being removed, causing an exception to be thrown by the ch.pipeline().remove(X) calls.

### Bugs: what's the simplest, easiest way to reproduce this bug? Please provide a minimal example if possible.

The issue is a race condition, so it is difficult to reproduce. Use a local HTTP cache that does not keep connections alive and `bazel clean` before starting a new build. 

### What operating system are you running Bazel on?

Ubuntu 16.04

### What's the output of `bazel info release`?

release 0.16.0

### If `bazel info release` returns "development version" or "(@non-git)", tell us how you built Bazel.

N/A

### What's the output of `git remote get-url origin ; git rev-parse master ; git rev-parse HEAD` ?

https://github.com/bazelbuild/bazel.git
b942140053981c4da5b2101d5f3a608ac25e7829
3e0024b5771539e6dd860c93cd65a603a0986506

###  Have you found anything relevant by searching the web?

No

### Any other information, logs, or outputs that you want to share?

```
java.lang.RuntimeException: Unrecoverable error while evaluating node 'ActionLookupData{actionLookupKey=//foo-service:play-routes BuildConfigurationValue.Key[...] false, actionIndex=0}' (requested by nodes 'File:[[<execution_root>]bazel-out/k8-fastbuild/bin]foo-service/play/routes/play_routes')
    at com.google.devtools.build.skyframe.AbstractParallelEvaluator$Evaluate.run(AbstractParallelEvaluator.java:482)
    at com.google.devtools.build.lib.concurrent.AbstractQueueVisitor$WrappedRunnable.run(AbstractQueueVisitor.java:335)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.util.NoSuchElementException: io.netty.handler.codec.http.HttpRequestEncoder
    at io.netty.channel.DefaultChannelPipeline.getContextOrDie(DefaultChannelPipeline.java:1107)
    at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:449)
    at com.google.devtools.build.lib.remote.blobstore.http.HttpBlobStore.releaseUploadChannel(HttpBlobStore.java:252)
    at com.google.devtools.build.lib.remote.blobstore.http.HttpBlobStore.put(HttpBlobStore.java:468)
    at com.google.devtools.build.lib.remote.blobstore.http.HttpBlobStore.put(HttpBlobStore.java:426)
    at com.google.devtools.build.lib.remote.SimpleBlobStoreActionCache.uploadStream(SimpleBlobStoreActionCache.java:183)
    at com.google.devtools.build.lib.remote.SimpleBlobStoreActionCache.upload(SimpleBlobStoreActionCache.java:148)
    at com.google.devtools.build.lib.remote.SimpleBlobStoreActionCache.upload(SimpleBlobStoreActionCache.java:126)
    at com.google.devtools.build.lib.remote.RemoteSpawnCache$1.store(RemoteSpawnCache.java:186)
    at com.google.devtools.build.lib.exec.AbstractSpawnStrategy.exec(AbstractSpawnStrategy.java:109)
    at com.google.devtools.build.lib.exec.AbstractSpawnStrategy.exec(AbstractSpawnStrategy.java:75)
    at com.google.devtools.build.lib.exec.SpawnActionContextMaps$ProxySpawnActionContext.exec(SpawnActionContextMaps.java:362)
    at com.google.devtools.build.lib.analysis.actions.SpawnAction.internalExecute(SpawnAction.java:287)
    at com.google.devtools.build.lib.analysis.actions.SpawnAction.execute(SpawnAction.java:294)
    at com.google.devtools.build.lib.skyframe.SkyframeActionExecutor.executeActionTask(SkyframeActionExecutor.java:992)
    at com.google.devtools.build.lib.skyframe.SkyframeActionExecutor.prepareScheduleExecuteAndCompleteAction(SkyframeActionExecutor.java:924)
    at com.google.devtools.build.lib.skyframe.SkyframeActionExecutor.access$900(SkyframeActionExecutor.java:119)
    at com.google.devtools.build.lib.skyframe.SkyframeActionExecutor$ActionRunner.call(SkyframeActionExecutor.java:768)
    at com.google.devtools.build.lib.skyframe.SkyframeActionExecutor$ActionRunner.call(SkyframeActionExecutor.java:723)
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
    at com.google.devtools.build.lib.skyframe.SkyframeActionExecutor.executeAction(SkyframeActionExecutor.java:461)
    at com.google.devtools.build.lib.skyframe.ActionExecutionFunction.checkCacheAndExecuteIfNeeded(ActionExecutionFunction.java:512)
    at com.google.devtools.build.lib.skyframe.ActionExecutionFunction.compute(ActionExecutionFunction.java:227)
    at com.google.devtools.build.skyframe.AbstractParallelEvaluator$Evaluate.run(AbstractParallelEvaluator.java:405)
FAILED: Build did NOT complete successfully```

Issue comments:
I'm about to submit a pull request which fixes this issue.
Here's the pull request: https://github.com/bazelbuild/bazel/pull/5953

Pull request review comments:
I think the changes in this file are no longer necessary and can be reverted?
I think we don't want to clear the pipeline but actually fail if there's anything in there.
It would be a bug in our code if the pipeline were not empty.
Good point, I'll revert this back since the exception handler should cover the race condition universally.
Okay, I've updated the two `acquire*Channel()` methods to check if the pipeline is not empty and fail the promise if so. The pipeline could be in a strange state if there are any handlers on a newly acquired channel, so you're right that failing probably makes sense there.

Patch that resolved the issue:
diff --git a/src/main/java/com/google/devtools/build/lib/remote/blobstore/http/HttpBlobStore.java b/src/main/java/com/google/devtools/build/lib/remote/blobstore/http/HttpBlobStore.java
index ca9a8ebff47012..a3d363616b8108 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/blobstore/http/HttpBlobStore.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/blobstore/http/HttpBlobStore.java
@@ -65,6 +65,7 @@
 import java.net.SocketAddress;
 import java.net.URI;
 import java.util.List;
+import java.util.NoSuchElementException;
 import java.util.concurrent.ExecutionException;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicBoolean;
@@ -99,7 +100,6 @@
  * <p>The implementation currently does not support transfer encoding chunked.
  */
 public final class HttpBlobStore implements SimpleBlobStore {
-
   private static final Pattern INVALID_TOKEN_ERROR =
       Pattern.compile("\\s*error\\s*=\\s*\"?invalid_token\"?");
 
@@ -107,6 +107,7 @@ public final class HttpBlobStore implements SimpleBlobStore {
   private final ChannelPool channelPool;
   private final URI uri;
   private final int timeoutMillis;
+  private final boolean useTls;
 
   private final Object closeLock = new Object();
 
@@ -159,7 +160,7 @@ private HttpBlobStore(
       URI uri, int timeoutMillis, int remoteMaxConnections, @Nullable final Credentials creds,
       @Nullable SocketAddress socketAddress)
       throws Exception {
-    boolean useTls = uri.getScheme().equals("https");
+    useTls = uri.getScheme().equals("https");
     if (uri.getPort() == -1) {
       int port = useTls ? 443 : 80;
       uri =
@@ -237,6 +238,12 @@ private Channel acquireUploadChannel() throws InterruptedException {
               try {
                 Channel ch = channelAcquired.getNow();
                 ChannelPipeline p = ch.pipeline();
+
+                if (!isChannelPipelineEmpty(p)) {
+                  channelReady.setFailure(new IllegalStateException("Channel pipeline is not empty."));
+                  return;
+                }
+
                 p.addLast(new HttpResponseDecoder());
                 // The 10KiB limit was chosen at random. We only expect HTTP servers to respond with
                 // an error message in the body and that should always be less than 10KiB.
@@ -264,11 +271,18 @@ private Channel acquireUploadChannel() throws InterruptedException {
   @SuppressWarnings("FutureReturnValueIgnored")
   private void releaseUploadChannel(Channel ch) {
     if (ch.isOpen()) {
-      ch.pipeline().remove(HttpResponseDecoder.class);
-      ch.pipeline().remove(HttpObjectAggregator.class);
-      ch.pipeline().remove(HttpRequestEncoder.class);
-      ch.pipeline().remove(ChunkedWriteHandler.class);
-      ch.pipeline().remove(HttpUploadHandler.class);
+      try {
+        ch.pipeline().remove(HttpResponseDecoder.class);
+        ch.pipeline().remove(HttpObjectAggregator.class);
+        ch.pipeline().remove(HttpRequestEncoder.class);
+        ch.pipeline().remove(ChunkedWriteHandler.class);
+        ch.pipeline().remove(HttpUploadHandler.class);
+      } catch (NoSuchElementException e) {
+        // If the channel is in the process of closing but not yet closed, some handlers could have
+        // been removed and would cause NoSuchElement exceptions to be thrown. Because handlers are
+        // removed in reverse-order, if we get a NoSuchElement exception, the following handlers
+        // should have been removed.
+      }
     }
     channelPool.release(ch);
   }
@@ -288,6 +302,12 @@ private Future<Channel> acquireDownloadChannel() {
               try {
                 Channel ch = channelAcquired.getNow();
                 ChannelPipeline p = ch.pipeline();
+
+                if (!isChannelPipelineEmpty(p)) {
+                  channelReady.setFailure(new IllegalStateException("Channel pipeline is not empty."));
+                  return;
+                }
+
                 ch.pipeline()
                     .addFirst("read-timeout-handler", new ReadTimeoutHandler(timeoutMillis));
                 p.addLast(new HttpClientCodec());
@@ -309,13 +329,24 @@ private void releaseDownloadChannel(Channel ch) {
     if (ch.isOpen()) {
       // The channel might have been closed due to an error, in which case its pipeline
       // has already been cleared. Closed channels can't be reused.
-      ch.pipeline().remove(ReadTimeoutHandler.class);
-      ch.pipeline().remove(HttpClientCodec.class);
-      ch.pipeline().remove(HttpDownloadHandler.class);
+      try {
+        ch.pipeline().remove(ReadTimeoutHandler.class);
+        ch.pipeline().remove(HttpClientCodec.class);
+        ch.pipeline().remove(HttpDownloadHandler.class);
+      } catch (NoSuchElementException e) {
+        // If the channel is in the process of closing but not yet closed, some handlers could have
+        // been removed and would cause NoSuchElement exceptions to be thrown. Because handlers are
+        // removed in reverse-order, if we get a NoSuchElement exception, the following handlers
+        // should have been removed.
+      }
     }
     channelPool.release(ch);
   }
 
+  private boolean isChannelPipelineEmpty(ChannelPipeline pipeline) {
+    return (pipeline.first() == null) || (useTls && pipeline.firstContext().name() == "ssl-handler" && pipeline.first() == pipeline.last());
+  }
+
   @Override
   public boolean containsKey(String key) {
     throw new UnsupportedOperationException("HTTP Caching does not use this method.");


Test patch: