From f0bca3d309c51f12cb364b61a6a33cf199d20370 Mon Sep 17 00:00:00 2001 From: Trustin Lee Date: Mon, 18 Apr 2016 18:49:32 +0900 Subject: [PATCH] Add more debug information to HTTP/2 GOAWAY frame Motivation: An HTTP/2 GOAWAY frame with non-zero error code sometimes gives an empty debugData, making it hard to determine the root cause of the error. Modifications: - Add the following information to debugData: - the exact type of Http2Exception - the original message of Http2Exception - the exact type, message and stack trace of the cause of Http2Exception - Add Exceptions.traceText() to stringify the stack trace of an exception - Fix incorrect Logger level check Result: We will have more information when we get an error GOAWAY frame. --- .../AbstractHttpToHttp2ConnectionHandler.java | 47 ++++++++++++++++++- .../common/http/Http2GoAwayListener.java | 2 +- .../armeria/common/util/Exceptions.java | 14 ++++++ 3 files changed, 60 insertions(+), 3 deletions(-) diff --git a/src/main/java/com/linecorp/armeria/common/http/AbstractHttpToHttp2ConnectionHandler.java b/src/main/java/com/linecorp/armeria/common/http/AbstractHttpToHttp2ConnectionHandler.java index e3e86d8a55a..097ebc35a47 100644 --- a/src/main/java/com/linecorp/armeria/common/http/AbstractHttpToHttp2ConnectionHandler.java +++ b/src/main/java/com/linecorp/armeria/common/http/AbstractHttpToHttp2ConnectionHandler.java @@ -16,12 +16,17 @@ package com.linecorp.armeria.common.http; +import static io.netty.handler.codec.http2.Http2Error.INTERNAL_ERROR; + +import com.linecorp.armeria.common.util.Exceptions; + import io.netty.channel.ChannelHandlerContext; import io.netty.channel.ChannelPromise; import io.netty.handler.codec.http2.Http2ConnectionDecoder; import io.netty.handler.codec.http2.Http2ConnectionEncoder; import io.netty.handler.codec.http2.Http2ConnectionHandler; import io.netty.handler.codec.http2.Http2Exception; +import io.netty.handler.codec.http2.Http2Exception.ClosedStreamCreationException; import io.netty.handler.codec.http2.Http2Settings; import io.netty.handler.codec.http2.Http2Stream.State; import io.netty.handler.codec.http2.Http2StreamVisitor; @@ -43,8 +48,10 @@ public abstract class AbstractHttpToHttp2ConnectionHandler extends HttpToHttp2Co private boolean closing; private boolean handlingConnectionError; - protected AbstractHttpToHttp2ConnectionHandler(Http2ConnectionDecoder decoder, Http2ConnectionEncoder encoder, - Http2Settings initialSettings, boolean validateHeaders) { + protected AbstractHttpToHttp2ConnectionHandler( + Http2ConnectionDecoder decoder, Http2ConnectionEncoder encoder, + Http2Settings initialSettings, boolean validateHeaders) { + super(decoder, encoder, initialSettings, validateHeaders); } @@ -59,9 +66,45 @@ protected void onConnectionError(ChannelHandlerContext ctx, Throwable cause, Htt } handlingConnectionError = true; + + // TODO(trustin): Remove this once Http2ConnectionHandler.goAway() sends better debugData. + // See https://github.com/netty/netty/issues/5160 + if (http2Ex == null) { + http2Ex = new Http2Exception(INTERNAL_ERROR, goAwayDebugData(null, cause), cause); + } else if (http2Ex instanceof ClosedStreamCreationException) { + final ClosedStreamCreationException e = (ClosedStreamCreationException) http2Ex; + http2Ex = new ClosedStreamCreationException(e.error(), goAwayDebugData(e, cause), cause); + } else { + http2Ex = new Http2Exception( + http2Ex.error(), goAwayDebugData(http2Ex, cause), cause, http2Ex.shutdownHint()); + } + super.onConnectionError(ctx, cause, http2Ex); } + private static String goAwayDebugData(Http2Exception http2Ex, Throwable cause) { + final StringBuilder buf = new StringBuilder(256); + final String type; + final String message; + + if (http2Ex != null) { + type = http2Ex.getClass().getName(); + message = http2Ex.getMessage(); + } else { + type = null; + message = null; + } + + buf.append("type: "); + buf.append(type != null ? type : "n/a"); + buf.append(", message: "); + buf.append(message != null ? message : "n/a"); + buf.append(", cause: "); + buf.append(cause != null ? Exceptions.traceText(cause) : "n/a"); + + return buf.toString(); + } + @Override public void close(ChannelHandlerContext ctx, ChannelPromise promise) throws Exception { closing = true; diff --git a/src/main/java/com/linecorp/armeria/common/http/Http2GoAwayListener.java b/src/main/java/com/linecorp/armeria/common/http/Http2GoAwayListener.java index 3835d562543..e4aeb8b761b 100644 --- a/src/main/java/com/linecorp/armeria/common/http/Http2GoAwayListener.java +++ b/src/main/java/com/linecorp/armeria/common/http/Http2GoAwayListener.java @@ -70,7 +70,7 @@ ch, sentOrReceived, lastStreamId, errorStr(errorCode), ByteBufUtil.hexDump(debugData)); } } else { - if (logger.isInfoEnabled()) { + if (logger.isDebugEnabled()) { logger.debug("{} {} a GOAWAY frame: lastStreamId={}, errorCode=NO_ERROR", ch, sentOrReceived, lastStreamId); } diff --git a/src/main/java/com/linecorp/armeria/common/util/Exceptions.java b/src/main/java/com/linecorp/armeria/common/util/Exceptions.java index 7823c5e94cc..d99a8548653 100644 --- a/src/main/java/com/linecorp/armeria/common/util/Exceptions.java +++ b/src/main/java/com/linecorp/armeria/common/util/Exceptions.java @@ -19,6 +19,8 @@ import static java.util.Objects.requireNonNull; import java.io.IOException; +import java.io.PrintWriter; +import java.io.StringWriter; import java.nio.channels.ClosedChannelException; import java.util.regex.Pattern; @@ -118,5 +120,17 @@ public static T clearTrace(T exception) { return exception; } + /** + * Returns the stack trace of the specified {@code exception} as a {@link String}. + */ + public static String traceText(Throwable exception) { + requireNonNull(exception, "exception"); + final StringWriter out = new StringWriter(256); + final PrintWriter pout = new PrintWriter(out); + exception.printStackTrace(pout); + pout.flush(); + return out.toString(); + } + private Exceptions() {} }