netty: fix ENHANCE_YOUR_CALM debug data logging

akandybaev · akandybaev · commit 6a52c067af7d · 2020-01-10T16:11:53.000-08:00
diff --git a/netty/src/main/java/io/grpc/netty/NettyClientHandler.java b/netty/src/main/java/io/grpc/netty/NettyClientHandler.java
@@ -268,7 +268,7 @@ public void onGoAwayReceived(int lastStreamId, long errorCode, ByteBuf debugData
         if (errorCode == Http2Error.ENHANCE_YOUR_CALM.code()) {
           String data = new String(debugDataBytes, UTF_8);
           logger.log(
-              Level.WARNING, "Received GOAWAY with ENHANCE_YOUR_CALM. Debug data: {1}", data);
+              Level.WARNING, "Received GOAWAY with ENHANCE_YOUR_CALM. Debug data: {0}", data);
           if ("too_many_pings".equals(data)) {
             tooManyPingsRunnable.run();
           }
diff --git a/netty/src/test/java/io/grpc/netty/NettyClientHandlerTest.java b/netty/src/test/java/io/grpc/netty/NettyClientHandlerTest.java
@@ -84,10 +84,17 @@
 import io.netty.handler.codec.http2.Http2Stream;
 import io.netty.util.AsciiString;
 import java.io.InputStream;
+import java.text.MessageFormat;
 import java.util.LinkedList;
 import java.util.List;
 import java.util.Queue;
 import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.concurrent.atomic.AtomicReference;
+import java.util.logging.Handler;
+import java.util.logging.LogRecord;
+import java.util.logging.Logger;
+import java.util.logging.SimpleFormatter;
+
 import org.junit.Before;
 import org.junit.Rule;
 import org.junit.Test;
@@ -459,6 +466,37 @@ public void run() {
     assertTrue(b.get());
   }
 
+  @Test
+  public void receivedGoAway_enhanceYourCalmShouldLogDebugData() throws Exception {
+    final AtomicReference<LogRecord> logRef = new AtomicReference<>();
+    Handler handler = new Handler() {
+      @Override
+      public void publish(LogRecord record) {
+        logRef.set(record);
+      }
+
+      @Override
+      public void flush() {
+      }
+
+      @Override
+      public void close() throws SecurityException {
+      }
+    };
+    Logger logger = Logger.getLogger(NettyClientHandler.class.getName());
+    try {
+      logger.addHandler(handler);
+      enqueue(newCreateStreamCommand(grpcHeaders, streamTransportState));
+      channelRead(goAwayFrame(0, 11 /* Enhance your calm */,
+            Unpooled.copiedBuffer("this is a test", UTF_8)));
+      assertNotNull(logRef);
+      assertTrue(MessageFormat.format(logRef.get().getMessage(), logRef.get().getParameters())
+              .contains("Debug data: this is a test"));
+    } finally {
+      logger.removeHandler(handler);
+    }
+  }
+
   @Test
   public void cancelStreamShouldCreateAndThenFailBufferedStream() throws Exception {
     receiveMaxConcurrentStreams(0);

Original file line number	Diff line number	Diff line change
`@@ -268,7 +268,7 @@ public void onGoAwayReceived(int lastStreamId, long errorCode, ByteBuf debugData`
`268`	`268`	`if (errorCode == Http2Error.ENHANCE_YOUR_CALM.code()) {`
`269`	`269`	`String data = new String(debugDataBytes, UTF_8);`
`270`	`270`	`logger.log(`
`271`		`- Level.WARNING, "Received GOAWAY with ENHANCE_YOUR_CALM. Debug data: {1}", data);`
	`271`	`+ Level.WARNING, "Received GOAWAY with ENHANCE_YOUR_CALM. Debug data: {0}", data);`
`272`	`272`	`if ("too_many_pings".equals(data)) {`
`273`	`273`	`tooManyPingsRunnable.run();`
`274`	`274`	`}`