services: fix binary logging empty metadata NPE, add null checks (#4213)

Fix NPE and refactor tests to make it more obvious whether tests
assume empty or non empty metadata.

Add null checks to applicable places in binary log.

2 files changed, 48 insertions, 27 deletions

diff --git a/services/src/main/java/io/grpc/services/BinaryLog.java b/services/src/main/java/io/grpc/services/BinaryLog.java
index 6523ebf64..5f43148fa 100644
--- a/services/src/main/java/io/grpc/services/BinaryLog.java
+++ b/services/src/main/java/io/grpc/services/BinaryLog.java
@@ -81,6 +81,9 @@ final class BinaryLog {
    */
   public void logSendInitialMetadata(
       Metadata metadata, boolean isServer, byte[] callId, SocketAddress peerSocket) {
+    Preconditions.checkNotNull(metadata);
+    // TODO(zpencer): peerSocket may go away, because at this time we have not selected a peer yet
+    Preconditions.checkNotNull(peerSocket);
     GrpcLogEntry entry = GrpcLogEntry
         .newBuilder()
         .setType(Type.SEND_INITIAL_METADATA)
@@ -98,6 +101,8 @@ final class BinaryLog {
    */
   public void logRecvInitialMetadata(
       Metadata metadata, boolean isServer, byte[] callId, SocketAddress peerSocket) {
+    Preconditions.checkNotNull(metadata);
+    Preconditions.checkNotNull(peerSocket);
     GrpcLogEntry entry = GrpcLogEntry
         .newBuilder()
         .setType(Type.RECV_INITIAL_METADATA)
@@ -114,6 +119,7 @@ final class BinaryLog {
    * as determined by the binary logging configuration.
    */
   public void logTrailingMetadata(Metadata metadata, boolean isServer, byte[] callId) {
+    Preconditions.checkNotNull(metadata);
     GrpcLogEntry entry = GrpcLogEntry
         .newBuilder()
         .setType(isServer ? Type.SEND_TRAILING_METADATA : Type.RECV_TRAILING_METADATA)
@@ -131,6 +137,8 @@ final class BinaryLog {
    */
   public void logOutboundMessage(
       ByteBuffer message, boolean compressed, boolean isServer, byte[] callId) {
+    Preconditions.checkNotNull(message);
+    Preconditions.checkNotNull(callId);
     GrpcLogEntry entry = GrpcLogEntry
         .newBuilder()
         .setType(Type.SEND_MESSAGE)
@@ -148,6 +156,8 @@ final class BinaryLog {
    */
   public void logInboundMessage(
       ByteBuffer message, boolean compressed, boolean isServer, byte[] callId) {
+    Preconditions.checkNotNull(message);
+    Preconditions.checkNotNull(callId);
     GrpcLogEntry entry = GrpcLogEntry
         .newBuilder()
         .setType(Type.RECV_MESSAGE)
@@ -370,6 +380,7 @@ final class BinaryLog {
    */
   // TODO(zpencer): verify int64 representation with other gRPC languages
   static Uint128 callIdToProto(byte[] bytes) {
+    Preconditions.checkNotNull(bytes);
     Preconditions.checkArgument(
         bytes.length == 16,
         String.format("can only convert from 16 byte input, actual length = %d", bytes.length));
@@ -382,6 +393,7 @@ final class BinaryLog {
   @VisibleForTesting
   // TODO(zpencer): the binlog design does not specify how to actually express the peer bytes
   static Peer socketToProto(SocketAddress address) {
+    Preconditions.checkNotNull(address);
     PeerType peerType = PeerType.UNKNOWN_PEERTYPE;
     byte[] peerAddress = null;
 
@@ -414,12 +426,13 @@ final class BinaryLog {
 
   @VisibleForTesting
   static io.grpc.binarylog.Metadata metadataToProto(Metadata metadata, int maxHeaderBytes) {
+    Preconditions.checkNotNull(metadata);
     Preconditions.checkState(maxHeaderBytes >= 0);
     Builder builder = io.grpc.binarylog.Metadata.newBuilder();
-    if (maxHeaderBytes > 0) {
-      byte[][] serialized = InternalMetadata.serialize(metadata);
+    // This code is tightly coupled with Metadata's implementation
+    byte[][] serialized;
+    if (maxHeaderBytes > 0 && (serialized = InternalMetadata.serialize(metadata)) != null) {
       int written = 0;
-      // This code is tightly coupled with Metadata's implementation
       for (int i = 0; i < serialized.length && written < maxHeaderBytes; i += 2) {
         byte[] key = serialized[i];
         byte[] value = serialized[i + 1];
@@ -440,6 +453,7 @@ final class BinaryLog {
 
   @VisibleForTesting
   static Message messageToProto(ByteBuffer message, boolean compressed, int maxMessageBytes) {
+    Preconditions.checkNotNull(message);
     int messageSize = message.remaining();
     Message.Builder builder = Message
         .newBuilder()
diff --git a/services/src/test/java/io/grpc/services/BinaryLogTest.java b/services/src/test/java/io/grpc/services/BinaryLogTest.java
index 0f5f6f74e..b57a83901 100644
--- a/services/src/test/java/io/grpc/services/BinaryLogTest.java
+++ b/services/src/test/java/io/grpc/services/BinaryLogTest.java
@@ -95,16 +95,16 @@ public final class BinaryLogTest {
   private static final int HEADER_LIMIT = 10;
   private static final int MESSAGE_LIMIT = Integer.MAX_VALUE;
 
-  private final Metadata metadata = new Metadata();
+  private final Metadata nonEmptyMetadata = new Metadata();
   private final BinaryLogSink sink = mock(BinaryLogSink.class);
   private final BinaryLog binaryLog = new BinaryLog(sink, HEADER_LIMIT, MESSAGE_LIMIT);
   private final ByteBuffer message = ByteBuffer.wrap(new byte[100]);
 
   @Before
   public void setUp() throws Exception {
-    metadata.put(KEY_A, DATA_A);
-    metadata.put(KEY_B, DATA_B);
-    metadata.put(KEY_C, DATA_C);
+    nonEmptyMetadata.put(KEY_A, DATA_A);
+    nonEmptyMetadata.put(KEY_B, DATA_B);
+    nonEmptyMetadata.put(KEY_C, DATA_C);
   }
 
   @Test
@@ -372,6 +372,13 @@ public final class BinaryLogTest {
   }
 
   @Test
+  public void metadataToProto_empty() throws Exception {
+    assertEquals(
+        io.grpc.binarylog.Metadata.getDefaultInstance(),
+        BinaryLog.metadataToProto(new Metadata(), Integer.MAX_VALUE));
+  }
+
+  @Test
   public void metadataToProto() throws Exception {
     assertEquals(
         io.grpc.binarylog.Metadata
@@ -380,7 +387,7 @@ public final class BinaryLogTest {
             .addEntry(ENTRY_B)
             .addEntry(ENTRY_C)
             .build(),
-        BinaryLog.metadataToProto(metadata, Integer.MAX_VALUE));
+        BinaryLog.metadataToProto(nonEmptyMetadata, Integer.MAX_VALUE));
   }
 
   @Test
@@ -388,39 +395,39 @@ public final class BinaryLogTest {
     // 0 byte limit not enough for any metadata
     assertEquals(
         io.grpc.binarylog.Metadata.getDefaultInstance(),
-        BinaryLog.metadataToProto(metadata, 0));
+        BinaryLog.metadataToProto(nonEmptyMetadata, 0));
     // not enough bytes for first key value
     assertEquals(
         io.grpc.binarylog.Metadata.getDefaultInstance(),
-        BinaryLog.metadataToProto(metadata, 9));
+        BinaryLog.metadataToProto(nonEmptyMetadata, 9));
     // enough for first key value
     assertEquals(
         io.grpc.binarylog.Metadata
             .newBuilder()
             .addEntry(ENTRY_A)
             .build(),
-        BinaryLog.metadataToProto(metadata, 10));
+        BinaryLog.metadataToProto(nonEmptyMetadata, 10));
     // Test edge cases for >= 2 key values
     assertEquals(
         io.grpc.binarylog.Metadata
             .newBuilder()
             .addEntry(ENTRY_A)
             .build(),
-        BinaryLog.metadataToProto(metadata, 19));
+        BinaryLog.metadataToProto(nonEmptyMetadata, 19));
     assertEquals(
         io.grpc.binarylog.Metadata
             .newBuilder()
             .addEntry(ENTRY_A)
             .addEntry(ENTRY_B)
             .build(),
-        BinaryLog.metadataToProto(metadata, 20));
+        BinaryLog.metadataToProto(nonEmptyMetadata, 20));
     assertEquals(
         io.grpc.binarylog.Metadata
             .newBuilder()
             .addEntry(ENTRY_A)
             .addEntry(ENTRY_B)
             .build(),
-        BinaryLog.metadataToProto(metadata, 29));
+        BinaryLog.metadataToProto(nonEmptyMetadata, 29));
     assertEquals(
         io.grpc.binarylog.Metadata
             .newBuilder()
@@ -428,7 +435,7 @@ public final class BinaryLogTest {
             .addEntry(ENTRY_B)
             .addEntry(ENTRY_C)
             .build(),
-        BinaryLog.metadataToProto(metadata, 30));
+        BinaryLog.metadataToProto(nonEmptyMetadata, 30));
   }
 
   @Test
@@ -504,7 +511,7 @@ public final class BinaryLogTest {
     InetAddress address = InetAddress.getByName("127.0.0.1");
     int port = 12345;
     InetSocketAddress socketAddress = new InetSocketAddress(address, port);
-    binaryLog.logSendInitialMetadata(metadata, IS_SERVER, CALL_ID, socketAddress);
+    binaryLog.logSendInitialMetadata(nonEmptyMetadata, IS_SERVER, CALL_ID, socketAddress);
     verify(sink).write(
         GrpcLogEntry
             .newBuilder()
@@ -512,7 +519,7 @@ public final class BinaryLogTest {
             .setLogger(GrpcLogEntry.Logger.SERVER)
             .setCallId(BinaryLog.callIdToProto(CALL_ID))
             .setPeer(BinaryLog.socketToProto(socketAddress))
-            .setMetadata(BinaryLog.metadataToProto(metadata, 10))
+            .setMetadata(BinaryLog.metadataToProto(nonEmptyMetadata, 10))
             .build());
   }
 
@@ -521,7 +528,7 @@ public final class BinaryLogTest {
     InetAddress address = InetAddress.getByName("127.0.0.1");
     int port = 12345;
     InetSocketAddress socketAddress = new InetSocketAddress(address, port);
-    binaryLog.logSendInitialMetadata(metadata, IS_CLIENT, CALL_ID, socketAddress);
+    binaryLog.logSendInitialMetadata(nonEmptyMetadata, IS_CLIENT, CALL_ID, socketAddress);
     verify(sink).write(
         GrpcLogEntry
             .newBuilder()
@@ -529,7 +536,7 @@ public final class BinaryLogTest {
             .setLogger(GrpcLogEntry.Logger.CLIENT)
             .setCallId(BinaryLog.callIdToProto(CALL_ID))
             .setPeer(BinaryLog.socketToProto(socketAddress))
-            .setMetadata(BinaryLog.metadataToProto(metadata, 10))
+            .setMetadata(BinaryLog.metadataToProto(nonEmptyMetadata, 10))
             .build());
   }
 
@@ -538,7 +545,7 @@ public final class BinaryLogTest {
     InetAddress address = InetAddress.getByName("127.0.0.1");
     int port = 12345;
     InetSocketAddress socketAddress = new InetSocketAddress(address, port);
-    binaryLog.logRecvInitialMetadata(metadata, IS_SERVER, CALL_ID, socketAddress);
+    binaryLog.logRecvInitialMetadata(nonEmptyMetadata, IS_SERVER, CALL_ID, socketAddress);
     verify(sink).write(
         GrpcLogEntry
             .newBuilder()
@@ -546,7 +553,7 @@ public final class BinaryLogTest {
             .setLogger(GrpcLogEntry.Logger.SERVER)
             .setCallId(BinaryLog.callIdToProto(CALL_ID))
             .setPeer(BinaryLog.socketToProto(socketAddress))
-            .setMetadata(BinaryLog.metadataToProto(metadata, 10))
+            .setMetadata(BinaryLog.metadataToProto(nonEmptyMetadata, 10))
             .build());
   }
 
@@ -555,7 +562,7 @@ public final class BinaryLogTest {
     InetAddress address = InetAddress.getByName("127.0.0.1");
     int port = 12345;
     InetSocketAddress socketAddress = new InetSocketAddress(address, port);
-    binaryLog.logRecvInitialMetadata(metadata, IS_CLIENT, CALL_ID, socketAddress);
+    binaryLog.logRecvInitialMetadata(nonEmptyMetadata, IS_CLIENT, CALL_ID, socketAddress);
     verify(sink).write(
         GrpcLogEntry
             .newBuilder()
@@ -563,33 +570,33 @@ public final class BinaryLogTest {
             .setLogger(GrpcLogEntry.Logger.CLIENT)
             .setCallId(BinaryLog.callIdToProto(CALL_ID))
             .setPeer(BinaryLog.socketToProto(socketAddress))
-            .setMetadata(BinaryLog.metadataToProto(metadata, 10))
+            .setMetadata(BinaryLog.metadataToProto(nonEmptyMetadata, 10))
             .build());
   }
 
   @Test
   public void logTrailingMetadata_server() throws Exception {
-    binaryLog.logTrailingMetadata(metadata, IS_SERVER, CALL_ID);
+    binaryLog.logTrailingMetadata(nonEmptyMetadata, IS_SERVER, CALL_ID);
     verify(sink).write(
         GrpcLogEntry
             .newBuilder()
             .setType(GrpcLogEntry.Type.SEND_TRAILING_METADATA)
             .setLogger(GrpcLogEntry.Logger.SERVER)
             .setCallId(BinaryLog.callIdToProto(CALL_ID))
-            .setMetadata(BinaryLog.metadataToProto(metadata, 10))
+            .setMetadata(BinaryLog.metadataToProto(nonEmptyMetadata, 10))
             .build());
   }
 
   @Test
   public void logTrailingMetadata_client() throws Exception {
-    binaryLog.logTrailingMetadata(metadata, IS_CLIENT, CALL_ID);
+    binaryLog.logTrailingMetadata(nonEmptyMetadata, IS_CLIENT, CALL_ID);
     verify(sink).write(
         GrpcLogEntry
             .newBuilder()
             .setType(GrpcLogEntry.Type.RECV_TRAILING_METADATA)
             .setLogger(GrpcLogEntry.Logger.CLIENT)
             .setCallId(BinaryLog.callIdToProto(CALL_ID))
-            .setMetadata(BinaryLog.metadataToProto(metadata, 10))
+            .setMetadata(BinaryLog.metadataToProto(nonEmptyMetadata, 10))
             .build());
   }