From 74ca288c0711deec4c308759e4db9d0aedcfe4bd Mon Sep 17 00:00:00 2001 From: Kevin Gessner Date: Wed, 4 Nov 2020 23:58:52 -0800 Subject: [PATCH] ensure the gRPC LoggingInterceptor does not throw exceptions where they cannot be handled This fixes a hang that I've struggled with for ages: when using `--build_event_json_file` to write a BEP file, enabling `--experimental_remote_grpc_log` causes the build to hang indefinitely after completion with a message of "Waiting for build events upload: JsonFormatFileTransport". The default `--build_event_json_file_path_conversion` ends up doing an RPC call when closing the BEP file. Unfortunately, this call happens after the gRPC log file has already been closed. That exception in the LoggingInterceptor is uncatchable -- it [causes the RPC call to hang indefinitely](https://github.com/grpc/grpc-java/pull/6107). Therefore, Bazel needs to handle and consume the exception so `onClose` always succeeds. Closes #12416. PiperOrigin-RevId: 340796218 --- .../devtools/build/lib/remote/logging/BUILD | 1 + .../lib/remote/logging/LoggingInterceptor.java | 15 ++++++++++++++- 2 files changed, 15 insertions(+), 1 deletion(-) diff --git a/src/main/java/com/google/devtools/build/lib/remote/logging/BUILD b/src/main/java/com/google/devtools/build/lib/remote/logging/BUILD index 8cb4b04f90cbeb..46a9b5f5caaabe 100644 --- a/src/main/java/com/google/devtools/build/lib/remote/logging/BUILD +++ b/src/main/java/com/google/devtools/build/lib/remote/logging/BUILD @@ -18,6 +18,7 @@ java_library( "//src/main/java/com/google/devtools/build/lib/remote/util", "//src/main/java/com/google/devtools/build/lib/util/io", "//src/main/protobuf:remote_execution_log_java_proto", + "//third_party:flogger", "//third_party:jsr305", "//third_party/grpc:grpc-jar", "//third_party/protobuf:protobuf_java", diff --git a/src/main/java/com/google/devtools/build/lib/remote/logging/LoggingInterceptor.java b/src/main/java/com/google/devtools/build/lib/remote/logging/LoggingInterceptor.java index ee4771fe99e7f0..c6738942b2d783 100644 --- a/src/main/java/com/google/devtools/build/lib/remote/logging/LoggingInterceptor.java +++ b/src/main/java/com/google/devtools/build/lib/remote/logging/LoggingInterceptor.java @@ -20,6 +20,7 @@ import build.bazel.remote.execution.v2.ExecutionGrpc; import build.bazel.remote.execution.v2.RequestMetadata; import com.google.bytestream.ByteStreamGrpc; +import com.google.common.flogger.GoogleLogger; import com.google.devtools.build.lib.clock.Clock; import com.google.devtools.build.lib.remote.logging.RemoteExecutionLog.LogEntry; import com.google.devtools.build.lib.remote.util.TracingMetadataUtils; @@ -39,6 +40,8 @@ /** Client interceptor for logging details of certain gRPC calls. */ public class LoggingInterceptor implements ClientInterceptor { + private static final GoogleLogger logger = GoogleLogger.forEnclosingClass(); + private final AsynchronousFileOutputStream rpcLogFile; private final Clock clock; @@ -133,12 +136,22 @@ public void onMessage(RespT message) { super.onMessage(message); } + /** + * This method must not throw any exceptions! Doing so will cause the wrapped call to + * silently hang indefinitely: https://github.com/grpc/grpc-java/pull/6107 + */ @Override public void onClose(Status status, Metadata trailers) { entryBuilder.setEndTime(getCurrentTimestamp()); entryBuilder.setStatus(makeStatusProto(status)); entryBuilder.setDetails(handler.getDetails()); - rpcLogFile.write(entryBuilder.build()); + try { + rpcLogFile.write(entryBuilder.build()); + } catch (RuntimeException e) { + // e.g. the log file is already closed. + logger.atWarning().withCause(e).log( + "Unable to write RPC log entry for %s", entryBuilder.build()); + } super.onClose(status, trailers); } },