Avoid implicit allocations in Http2FrameLogger when logging is disabled (#7937)

Motivation:

Integer autoboxing in this class (and possibly also the varargs arrays)
showed non-negligible CPU and garbage contribution when profiling a gRPC
service. grpc-java currently hardcodes use of Http2FrameLogger, set at
DEBUG level.

Modifications:

Wrap offending log statements in conditional blocks.

Result:

Garbage won't be produced by Http2FrameLogger when set to a disabled
logging level.
This commit is contained in:
Nick Hill 2018-05-15 00:06:32 -07:00 committed by Norman Maurer
parent 09d9daf1c4
commit 30a02b441a

View File

@ -20,7 +20,6 @@ import io.netty.buffer.ByteBufUtil;
import io.netty.channel.ChannelHandlerAdapter;
import io.netty.channel.ChannelHandlerContext;
import io.netty.handler.logging.LogLevel;
import io.netty.util.internal.StringUtil;
import io.netty.util.internal.UnstableApi;
import io.netty.util.internal.logging.InternalLogLevel;
import io.netty.util.internal.logging.InternalLogger;
@ -60,34 +59,48 @@ public class Http2FrameLogger extends ChannelHandlerAdapter {
this.logger = checkNotNull(logger, "logger");
}
public boolean isEnabled() {
return logger.isEnabled(level);
}
public void logData(Direction direction, ChannelHandlerContext ctx, int streamId, ByteBuf data, int padding,
boolean endStream) {
logger.log(level, "{} {} DATA: streamId={} padding={} endStream={} length={} bytes={}", ctx.channel(),
direction.name(), streamId, padding, endStream, data.readableBytes(), toString(data));
if (isEnabled()) {
logger.log(level, "{} {} DATA: streamId={} padding={} endStream={} length={} bytes={}", ctx.channel(),
direction.name(), streamId, padding, endStream, data.readableBytes(), toString(data));
}
}
public void logHeaders(Direction direction, ChannelHandlerContext ctx, int streamId, Http2Headers headers,
int padding, boolean endStream) {
logger.log(level, "{} {} HEADERS: streamId={} headers={} padding={} endStream={}", ctx.channel(),
direction.name(), streamId, headers, padding, endStream);
if (isEnabled()) {
logger.log(level, "{} {} HEADERS: streamId={} headers={} padding={} endStream={}", ctx.channel(),
direction.name(), streamId, headers, padding, endStream);
}
}
public void logHeaders(Direction direction, ChannelHandlerContext ctx, int streamId, Http2Headers headers,
int streamDependency, short weight, boolean exclusive, int padding, boolean endStream) {
logger.log(level, "{} {} HEADERS: streamId={} headers={} streamDependency={} weight={} exclusive={} " +
"padding={} endStream={}", ctx.channel(),
direction.name(), streamId, headers, streamDependency, weight, exclusive, padding, endStream);
if (isEnabled()) {
logger.log(level, "{} {} HEADERS: streamId={} headers={} streamDependency={} weight={} exclusive={} " +
"padding={} endStream={}", ctx.channel(),
direction.name(), streamId, headers, streamDependency, weight, exclusive, padding, endStream);
}
}
public void logPriority(Direction direction, ChannelHandlerContext ctx, int streamId, int streamDependency,
short weight, boolean exclusive) {
logger.log(level, "{} {} PRIORITY: streamId={} streamDependency={} weight={} exclusive={}", ctx.channel(),
direction.name(), streamId, streamDependency, weight, exclusive);
if (isEnabled()) {
logger.log(level, "{} {} PRIORITY: streamId={} streamDependency={} weight={} exclusive={}", ctx.channel(),
direction.name(), streamId, streamDependency, weight, exclusive);
}
}
public void logRstStream(Direction direction, ChannelHandlerContext ctx, int streamId, long errorCode) {
logger.log(level, "{} {} RST_STREAM: streamId={} errorCode={}", ctx.channel(),
direction.name(), streamId, errorCode);
if (isEnabled()) {
logger.log(level, "{} {} RST_STREAM: streamId={} errorCode={}", ctx.channel(),
direction.name(), streamId, errorCode);
}
}
public void logSettingsAck(Direction direction, ChannelHandlerContext ctx) {
@ -95,48 +108,58 @@ public class Http2FrameLogger extends ChannelHandlerAdapter {
}
public void logSettings(Direction direction, ChannelHandlerContext ctx, Http2Settings settings) {
logger.log(level, "{} {} SETTINGS: ack=false settings={}", ctx.channel(), direction.name(), settings);
if (isEnabled()) {
logger.log(level, "{} {} SETTINGS: ack=false settings={}", ctx.channel(), direction.name(), settings);
}
}
public void logPing(Direction direction, ChannelHandlerContext ctx, long data) {
logger.log(level, "{} {} PING: ack=false bytes={}", ctx.channel(),
direction.name(), data);
if (isEnabled()) {
logger.log(level, "{} {} PING: ack=false bytes={}", ctx.channel(),
direction.name(), data);
}
}
public void logPingAck(Direction direction, ChannelHandlerContext ctx, long data) {
logger.log(level, "{} {} PING: ack=true bytes={}", ctx.channel(),
direction.name(), data);
if (isEnabled()) {
logger.log(level, "{} {} PING: ack=true bytes={}", ctx.channel(),
direction.name(), data);
}
}
public void logPushPromise(Direction direction, ChannelHandlerContext ctx, int streamId, int promisedStreamId,
Http2Headers headers, int padding) {
logger.log(level, "{} {} PUSH_PROMISE: streamId={} promisedStreamId={} headers={} padding={}", ctx.channel(),
direction.name(), streamId, promisedStreamId, headers, padding);
if (isEnabled()) {
logger.log(level, "{} {} PUSH_PROMISE: streamId={} promisedStreamId={} headers={} padding={}",
ctx.channel(), direction.name(), streamId, promisedStreamId, headers, padding);
}
}
public void logGoAway(Direction direction, ChannelHandlerContext ctx, int lastStreamId, long errorCode,
ByteBuf debugData) {
logger.log(level, "{} {} GO_AWAY: lastStreamId={} errorCode={} length={} bytes={}", ctx.channel(),
direction.name(), lastStreamId, errorCode, debugData.readableBytes(), toString(debugData));
if (isEnabled()) {
logger.log(level, "{} {} GO_AWAY: lastStreamId={} errorCode={} length={} bytes={}", ctx.channel(),
direction.name(), lastStreamId, errorCode, debugData.readableBytes(), toString(debugData));
}
}
public void logWindowsUpdate(Direction direction, ChannelHandlerContext ctx, int streamId,
int windowSizeIncrement) {
logger.log(level, "{} {} WINDOW_UPDATE: streamId={} windowSizeIncrement={}", ctx.channel(),
direction.name(), streamId, windowSizeIncrement);
if (isEnabled()) {
logger.log(level, "{} {} WINDOW_UPDATE: streamId={} windowSizeIncrement={}", ctx.channel(),
direction.name(), streamId, windowSizeIncrement);
}
}
public void logUnknownFrame(Direction direction, ChannelHandlerContext ctx, byte frameType, int streamId,
Http2Flags flags, ByteBuf data) {
logger.log(level, "{} {} UNKNOWN: frameType={} streamId={} flags={} length={} bytes={}", ctx.channel(),
direction.name(), frameType & 0xFF, streamId, flags.value(), data.readableBytes(), toString(data));
if (isEnabled()) {
logger.log(level, "{} {} UNKNOWN: frameType={} streamId={} flags={} length={} bytes={}", ctx.channel(),
direction.name(), frameType & 0xFF, streamId, flags.value(), data.readableBytes(), toString(data));
}
}
private String toString(ByteBuf buf) {
if (!logger.isEnabled(level)) {
return StringUtil.EMPTY_STRING;
}
if (level == InternalLogLevel.TRACE || buf.readableBytes() <= BUFFER_LENGTH_THRESHOLD) {
// Log the entire buffer.
return ByteBufUtil.hexDump(buf);