Optimizations for Http2FrameLogger

Motivation:

The logger was always performing a hex dump of the ByteBufs regarless whether or not the log would take place.

Modifications:

Fixed the logger to avoid serializing the ByteBufs and calling the varargs method if logging is not enabled.

Result:

The loggers should run MUCH faster when disabled.
This commit is contained in:
nmittler 2015-03-12 14:01:43 -07:00
parent 3df7b4dac7
commit 44615f6cb2

View File

@ -33,6 +33,7 @@ public class Http2FrameLogger extends ChannelHandlerAdapter {
OUTBOUND OUTBOUND
} }
private static final int BUFFER_LENGTH_THRESHOLD = 64;
private final InternalLogger logger; private final InternalLogger logger;
private final InternalLogLevel level; private final InternalLogLevel level;
@ -47,81 +48,120 @@ public class Http2FrameLogger extends ChannelHandlerAdapter {
public void logData(Direction direction, int streamId, ByteBuf data, int padding, public void logData(Direction direction, int streamId, ByteBuf data, int padding,
boolean endStream) { boolean endStream) {
log(direction, if (enabled()) {
"DATA: streamId=%d, padding=%d, endStream=%b, length=%d, bytes=%s", log(direction,
streamId, padding, endStream, data.readableBytes(), ByteBufUtil.hexDump(data)); "DATA: streamId=%d, padding=%d, endStream=%b, length=%d, bytes=%s",
streamId, padding, endStream, data.readableBytes(), toString(data));
}
} }
public void logHeaders(Direction direction, int streamId, Http2Headers headers, int padding, public void logHeaders(Direction direction, int streamId, Http2Headers headers, int padding,
boolean endStream) { boolean endStream) {
log(direction, "HEADERS: streamId:%d, headers=%s, padding=%d, endStream=%b", if (enabled()) {
streamId, headers, padding, endStream); log(direction, "HEADERS: streamId:%d, headers=%s, padding=%d, endStream=%b",
streamId, headers, padding, endStream);
}
} }
public void logHeaders(Direction direction, int streamId, Http2Headers headers, public void logHeaders(Direction direction, int streamId, Http2Headers headers,
int streamDependency, short weight, boolean exclusive, int padding, boolean endStream) { int streamDependency, short weight, boolean exclusive, int padding, boolean endStream) {
log(direction, if (enabled()) {
"HEADERS: streamId:%d, headers=%s, streamDependency=%d, weight=%d, exclusive=%b, " log(direction,
+ "padding=%d, endStream=%b", streamId, headers, "HEADERS: streamId:%d, headers=%s, streamDependency=%d, weight=%d, exclusive=%b, "
streamDependency, weight, exclusive, padding, endStream); + "padding=%d, endStream=%b", streamId, headers,
streamDependency, weight, exclusive, padding, endStream);
}
} }
public void logPriority(Direction direction, int streamId, int streamDependency, short weight, public void logPriority(Direction direction, int streamId, int streamDependency, short weight,
boolean exclusive) { boolean exclusive) {
log(direction, "PRIORITY: streamId=%d, streamDependency=%d, weight=%d, exclusive=%b", if (enabled()) {
streamId, streamDependency, weight, exclusive); log(direction, "PRIORITY: streamId=%d, streamDependency=%d, weight=%d, exclusive=%b",
streamId, streamDependency, weight, exclusive);
}
} }
public void logRstStream(Direction direction, int streamId, long errorCode) { public void logRstStream(Direction direction, int streamId, long errorCode) {
log(direction, "RST_STREAM: streamId=%d, errorCode=%d", streamId, errorCode); if (enabled()) {
log(direction, "RST_STREAM: streamId=%d, errorCode=%d", streamId, errorCode);
}
} }
public void logSettingsAck(Direction direction) { public void logSettingsAck(Direction direction) {
log(direction, "SETTINGS ack=true"); if (enabled()) {
log(direction, "SETTINGS ack=true");
}
} }
public void logSettings(Direction direction, Http2Settings settings) { public void logSettings(Direction direction, Http2Settings settings) {
log(direction, "SETTINGS: ack=false, settings=%s", settings); if (enabled()) {
log(direction, "SETTINGS: ack=false, settings=%s", settings);
}
} }
public void logPing(Direction direction, ByteBuf data) { public void logPing(Direction direction, ByteBuf data) {
log(direction, "PING: ack=false, length=%d, bytes=%s", data.readableBytes(), ByteBufUtil.hexDump(data)); if (enabled()) {
log(direction, "PING: ack=false, length=%d, bytes=%s", data.readableBytes(), toString(data));
}
} }
public void logPingAck(Direction direction, ByteBuf data) { public void logPingAck(Direction direction, ByteBuf data) {
log(direction, "PING: ack=true, length=%d, bytes=%s", data.readableBytes(), ByteBufUtil.hexDump(data)); if (enabled()) {
log(direction, "PING: ack=true, length=%d, bytes=%s", data.readableBytes(), toString(data));
}
} }
public void logPushPromise(Direction direction, int streamId, int promisedStreamId, public void logPushPromise(Direction direction, int streamId, int promisedStreamId,
Http2Headers headers, int padding) { Http2Headers headers, int padding) {
log(direction, "PUSH_PROMISE: streamId=%d, promisedStreamId=%d, headers=%s, padding=%d", if (enabled()) {
streamId, promisedStreamId, headers, padding); log(direction, "PUSH_PROMISE: streamId=%d, promisedStreamId=%d, headers=%s, padding=%d",
streamId, promisedStreamId, headers, padding);
}
} }
public void logGoAway(Direction direction, int lastStreamId, long errorCode, ByteBuf debugData) { public void logGoAway(Direction direction, int lastStreamId, long errorCode, ByteBuf debugData) {
log(direction, "GO_AWAY: lastStreamId=%d, errorCode=%d, length=%d, bytes=%s", lastStreamId, if (enabled()) {
errorCode, debugData.readableBytes(), ByteBufUtil.hexDump(debugData)); log(direction, "GO_AWAY: lastStreamId=%d, errorCode=%d, length=%d, bytes=%s", lastStreamId,
errorCode, debugData.readableBytes(), toString(debugData));
}
} }
public void logWindowsUpdate(Direction direction, int streamId, int windowSizeIncrement) { public void logWindowsUpdate(Direction direction, int streamId, int windowSizeIncrement) {
log(direction, "WINDOW_UPDATE: streamId=%d, windowSizeIncrement=%d", streamId, if (enabled()) {
windowSizeIncrement); log(direction, "WINDOW_UPDATE: streamId=%d, windowSizeIncrement=%d", streamId,
windowSizeIncrement);
}
} }
public void logUnknownFrame(Direction direction, byte frameType, int streamId, Http2Flags flags, ByteBuf data) { public void logUnknownFrame(Direction direction, byte frameType, int streamId, Http2Flags flags, ByteBuf data) {
log(direction, "UNKNOWN: frameType=%d, streamId=%d, flags=%d, length=%d, bytes=%s", if (enabled()) {
frameType & 0xFF, streamId, flags.value(), data.readableBytes(), ByteBufUtil.hexDump(data)); log(direction, "UNKNOWN: frameType=%d, streamId=%d, flags=%d, length=%d, bytes=%s",
frameType & 0xFF, streamId, flags.value(), data.readableBytes(), toString(data));
}
}
private boolean enabled() {
return logger.isEnabled(level);
}
private String toString(ByteBuf buf) {
if (level == InternalLogLevel.TRACE || buf.readableBytes() <= BUFFER_LENGTH_THRESHOLD) {
// Log the entire buffer.
return ByteBufUtil.hexDump(buf);
}
// Otherwise just log the first 64 bytes.
int length = Math.min(buf.readableBytes(), BUFFER_LENGTH_THRESHOLD);
return ByteBufUtil.hexDump(buf, buf.readerIndex(), length) + "...";
} }
private void log(Direction direction, String format, Object... args) { private void log(Direction direction, String format, Object... args) {
if (logger.isEnabled(level)) { StringBuilder b = new StringBuilder(200);
StringBuilder b = new StringBuilder(200); b.append("\n----------------")
b.append("\n----------------") .append(direction.name())
.append(direction.name()) .append("--------------------\n")
.append("--------------------\n") .append(String.format(format, args))
.append(String.format(format, args)) .append("\n------------------------------------");
.append("\n------------------------------------"); logger.log(level, b.toString());
logger.log(level, b.toString());
}
} }
} }