diff --git a/handler/src/main/java/io/netty/handler/logging/LogLevel.java b/handler/src/main/java/io/netty/handler/logging/LogLevel.java index c6a643c25b..7e9fcd4e38 100644 --- a/handler/src/main/java/io/netty/handler/logging/LogLevel.java +++ b/handler/src/main/java/io/netty/handler/logging/LogLevel.java @@ -17,6 +17,9 @@ package io.netty.handler.logging; import io.netty.util.internal.logging.InternalLogLevel; +/** + * Maps the regular {@link LogLevel}s with the {@link InternalLogLevel} ones. + */ public enum LogLevel { TRACE(InternalLogLevel.TRACE), DEBUG(InternalLogLevel.DEBUG), @@ -30,6 +33,11 @@ public enum LogLevel { this.internalLevel = internalLevel; } + /** + * Convert the {@link LogLevel} to its {@link InternalLogLevel} variant. + * + * @return the converted level. + */ InternalLogLevel toInternalLevel() { return internalLevel; } diff --git a/handler/src/main/java/io/netty/handler/logging/LoggingHandler.java b/handler/src/main/java/io/netty/handler/logging/LoggingHandler.java index a33f637232..2d6494a50e 100644 --- a/handler/src/main/java/io/netty/handler/logging/LoggingHandler.java +++ b/handler/src/main/java/io/netty/handler/logging/LoggingHandler.java @@ -99,7 +99,6 @@ public class LoggingHandler extends ChannelDuplexHandler { protected final InternalLogger logger; protected final InternalLogLevel internalLevel; - private final LogLevel level; /** @@ -114,7 +113,7 @@ public class LoggingHandler extends ChannelDuplexHandler { * Creates a new instance whose logger name is the fully qualified class * name of the instance. * - * @param level the log level + * @param level the log level */ public LoggingHandler(LogLevel level) { if (level == null) { @@ -129,6 +128,8 @@ public class LoggingHandler extends ChannelDuplexHandler { /** * Creates a new instance with the specified logger name and with hex dump * enabled. + * + * @param clazz the class type to generate the logger for. */ public LoggingHandler(Class clazz) { this(clazz, DEFAULT_LEVEL); @@ -137,7 +138,8 @@ public class LoggingHandler extends ChannelDuplexHandler { /** * Creates a new instance with the specified logger name. * - * @param level the log level + * @param clazz the class type to generate the logger for. + * @param level the log level. */ public LoggingHandler(Class clazz, LogLevel level) { if (clazz == null) { @@ -146,13 +148,16 @@ public class LoggingHandler extends ChannelDuplexHandler { if (level == null) { throw new NullPointerException("level"); } + logger = InternalLoggerFactory.getInstance(clazz); this.level = level; internalLevel = level.toInternalLevel(); } /** - * Creates a new instance with the specified logger name. + * Creates a new instance with the specified logger name using the default log level. + * + * @param name the name of the class to use for the logger. */ public LoggingHandler(String name) { this(name, DEFAULT_LEVEL); @@ -161,7 +166,8 @@ public class LoggingHandler extends ChannelDuplexHandler { /** * Creates a new instance with the specified logger name. * - * @param level the log level + * @param name the name of the class to use for the logger. + * @param level the log level. */ public LoggingHandler(String name, LogLevel level) { if (name == null) { @@ -170,6 +176,7 @@ public class LoggingHandler extends ChannelDuplexHandler { if (level == null) { throw new NullPointerException("level"); } + logger = InternalLoggerFactory.getInstance(name); this.level = level; internalLevel = level.toInternalLevel(); @@ -182,6 +189,13 @@ public class LoggingHandler extends ChannelDuplexHandler { return level; } + /** + * Formats the given message together with the channel context for output. + * + * @param ctx the channel context. + * @param message the message to format. + * @return the formatted message consisting of the channel context and the actual message. + */ protected String format(ChannelHandlerContext ctx, String message) { String chStr = ctx.channel().toString(); StringBuilder buf = new StringBuilder(chStr.length() + message.length() + 1); @@ -192,53 +206,47 @@ public class LoggingHandler extends ChannelDuplexHandler { } @Override - public void channelRegistered(ChannelHandlerContext ctx) - throws Exception { + public void channelRegistered(ChannelHandlerContext ctx) throws Exception { if (logger.isEnabled(internalLevel)) { - logger.log(internalLevel, format(ctx, "REGISTERED")); + logger.log(internalLevel, format(ctx, "REGISTERED()")); } super.channelRegistered(ctx); } @Override - public void channelActive(ChannelHandlerContext ctx) - throws Exception { + public void channelActive(ChannelHandlerContext ctx) throws Exception { if (logger.isEnabled(internalLevel)) { - logger.log(internalLevel, format(ctx, "ACTIVE")); + logger.log(internalLevel, format(ctx, "ACTIVE()")); } super.channelActive(ctx); } @Override - public void channelInactive(ChannelHandlerContext ctx) - throws Exception { + public void channelInactive(ChannelHandlerContext ctx) throws Exception { if (logger.isEnabled(internalLevel)) { - logger.log(internalLevel, format(ctx, "INACTIVE")); + logger.log(internalLevel, format(ctx, "INACTIVE()")); } super.channelInactive(ctx); } @Override - public void exceptionCaught(ChannelHandlerContext ctx, - Throwable cause) throws Exception { + public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception { if (logger.isEnabled(internalLevel)) { - logger.log(internalLevel, format(ctx, "EXCEPTION: " + cause), cause); + logger.log(internalLevel, format(ctx, "EXCEPTION(" + cause + ')'), cause); } super.exceptionCaught(ctx, cause); } @Override - public void userEventTriggered(ChannelHandlerContext ctx, - Object evt) throws Exception { + public void userEventTriggered(ChannelHandlerContext ctx, Object evt) throws Exception { if (logger.isEnabled(internalLevel)) { - logger.log(internalLevel, format(ctx, "USER_EVENT: " + evt)); + logger.log(internalLevel, format(ctx, "USER_EVENT(" + evt + ')')); } super.userEventTriggered(ctx, evt); } @Override - public void bind(ChannelHandlerContext ctx, - SocketAddress localAddress, ChannelPromise promise) throws Exception { + public void bind(ChannelHandlerContext ctx, SocketAddress localAddress, ChannelPromise promise) throws Exception { if (logger.isEnabled(internalLevel)) { logger.log(internalLevel, format(ctx, "BIND(" + localAddress + ')')); } @@ -246,9 +254,8 @@ public class LoggingHandler extends ChannelDuplexHandler { } @Override - public void connect(ChannelHandlerContext ctx, - SocketAddress remoteAddress, SocketAddress localAddress, - ChannelPromise promise) throws Exception { + public void connect(ChannelHandlerContext ctx, SocketAddress remoteAddress, SocketAddress localAddress, + ChannelPromise promise) throws Exception { if (logger.isEnabled(internalLevel)) { logger.log(internalLevel, format(ctx, "CONNECT(" + remoteAddress + ", " + localAddress + ')')); } @@ -256,8 +263,7 @@ public class LoggingHandler extends ChannelDuplexHandler { } @Override - public void disconnect(ChannelHandlerContext ctx, - ChannelPromise promise) throws Exception { + public void disconnect(ChannelHandlerContext ctx, ChannelPromise promise) throws Exception { if (logger.isEnabled(internalLevel)) { logger.log(internalLevel, format(ctx, "DISCONNECT()")); } @@ -265,8 +271,7 @@ public class LoggingHandler extends ChannelDuplexHandler { } @Override - public void close(ChannelHandlerContext ctx, - ChannelPromise promise) throws Exception { + public void close(ChannelHandlerContext ctx, ChannelPromise promise) throws Exception { if (logger.isEnabled(internalLevel)) { logger.log(internalLevel, format(ctx, "CLOSE()")); } @@ -275,30 +280,44 @@ public class LoggingHandler extends ChannelDuplexHandler { @Override public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception { - logMessage(ctx, "RECEIVED", msg); + logMessage(ctx, "RECEIVED()", msg); ctx.fireChannelRead(msg); } @Override public void write(ChannelHandlerContext ctx, Object msg, ChannelPromise promise) throws Exception { - logMessage(ctx, "WRITE", msg); + logMessage(ctx, "WRITE()", msg); ctx.write(msg, promise); } @Override public void flush(ChannelHandlerContext ctx) throws Exception { if (logger.isEnabled(internalLevel)) { - logger.log(internalLevel, format(ctx, "FLUSH")); + logger.log(internalLevel, format(ctx, "FLUSH()")); } ctx.flush(); } + /** + * Helper method to log the message only if the loger is enabled for the given level. + * + * @param ctx the channel context. + * @param eventName the name of the event to log. + * @param msg the actual message to log. + */ private void logMessage(ChannelHandlerContext ctx, String eventName, Object msg) { if (logger.isEnabled(internalLevel)) { logger.log(internalLevel, format(ctx, formatMessage(eventName, msg))); } } + /** + * Helper method to format the message content. + * + * @param eventName the name of the event to log. + * @param msg the actual message to format. + * @return the formatted message. + */ protected String formatMessage(String eventName, Object msg) { if (msg instanceof ByteBuf) { return formatByteBuf(eventName, (ByteBuf) msg); @@ -310,7 +329,10 @@ public class LoggingHandler extends ChannelDuplexHandler { } /** - * Returns a String which contains all details to log the {@link ByteBuf} + * Returns a String which contains all details to log the {@link ByteBuf}. + * + * @param eventName the name of the event to log. + * @param buf the buffer to log. */ protected String formatByteBuf(String eventName, ByteBuf buf) { int length = buf.readableBytes(); @@ -319,9 +341,9 @@ public class LoggingHandler extends ChannelDuplexHandler { dump.append(eventName).append('(').append(length).append('B').append(')'); dump.append( - NEWLINE + " +-------------------------------------------------+" + - NEWLINE + " | 0 1 2 3 4 5 6 7 8 9 a b c d e f |" + - NEWLINE + "+--------+-------------------------------------------------+----------------+"); + NEWLINE + " +-------------------------------------------------+" + + NEWLINE + " | 0 1 2 3 4 5 6 7 8 9 a b c d e f |" + + NEWLINE + "+--------+-------------------------------------------------+----------------+"); final int startIndex = buf.readerIndex(); final int endIndex = buf.writerIndex(); @@ -357,14 +379,13 @@ public class LoggingHandler extends ChannelDuplexHandler { dump.append('|'); } - dump.append( - NEWLINE + "+--------+-------------------------------------------------+----------------+"); + dump.append(NEWLINE + "+--------+-------------------------------------------------+----------------+"); return dump.toString(); } /** - * Returns a String which contains all details to log the {@link Object} + * Returns a String which contains all details to log the {@link Object}. */ protected String formatNonByteBuf(String eventName, Object msg) { return eventName + ": " + msg; diff --git a/handler/src/test/java/io/netty/handler/logging/LoggingHandlerTest.java b/handler/src/test/java/io/netty/handler/logging/LoggingHandlerTest.java new file mode 100644 index 0000000000..2c6bc0be88 --- /dev/null +++ b/handler/src/test/java/io/netty/handler/logging/LoggingHandlerTest.java @@ -0,0 +1,225 @@ +/* + * Copyright 2012 The Netty Project + * + * The Netty Project licenses this file to you under the Apache License, + * version 2.0 (the "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at: + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT + * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the + * License for the specific language governing permissions and limitations + * under the License. + */ +package io.netty.handler.logging; + +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.Appender; +import io.netty.buffer.ByteBuf; +import io.netty.buffer.Unpooled; +import io.netty.channel.ChannelHandler; +import io.netty.channel.ChannelMetadata; +import io.netty.channel.embedded.EmbeddedChannel; +import io.netty.util.CharsetUtil; +import org.easymock.EasyMock; +import org.easymock.IArgumentMatcher; +import org.junit.Before; +import org.junit.Test; +import org.slf4j.LoggerFactory; + +import java.net.InetSocketAddress; +import java.util.regex.Pattern; + +import static org.easymock.EasyMock.*; +import static org.junit.Assert.assertEquals; + +/** + * Verifies the correct functionality of the {@link LoggingHandler}. + */ +public class LoggingHandlerTest { + + /** + * Custom logback appender which gets used to match on log messages. + */ + private Appender appender; + + @Before + public void setupCustomAppender() { + Logger root = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); + appender = createNiceMock(Appender.class); + root.addAppender(appender); + } + + @Test(expected = NullPointerException.class) + public void shouldNotAcceptNullLogLevel() { + LogLevel level = null; + new LoggingHandler(level); + } + + @Test + public void shouldApplyCustomLogLevel() { + LoggingHandler handler = new LoggingHandler("LoggingHandlerTest", LogLevel.INFO); + assertEquals(LogLevel.INFO, handler.level()); + } + + @Test + public void shouldLogChannelActive() { + appender.doAppend(matchesLog(".+ACTIVE\\(\\)$")); + replay(appender); + new EmbeddedChannel(new LoggingHandler()); + verify(appender); + } + + @Test + public void shouldLogChannelRegistered() { + appender.doAppend(matchesLog(".+REGISTERED\\(\\)$")); + replay(appender); + new EmbeddedChannel(new LoggingHandler()); + verify(appender); + } + + @Test + public void shouldLogChannelClose() throws Exception { + appender.doAppend(matchesLog(".+CLOSE\\(\\)$")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.close().await(); + verify(appender); + } + + @Test + public void shouldLogChannelConnect() throws Exception { + appender.doAppend(matchesLog(".+CONNECT\\(0.0.0.0/0.0.0.0:80, null\\)$")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.connect(new InetSocketAddress(80)).await(); + verify(appender); + } + + @Test + public void shouldLogChannelDisconnect() throws Exception { + appender.doAppend(matchesLog(".+DISCONNECT\\(\\)$")); + replay(appender); + EmbeddedChannel channel = new DisconnectingEmbeddedChannel(new LoggingHandler()); + channel.connect(new InetSocketAddress(80)).await(); + channel.disconnect().await(); + verify(appender); + } + + @Test + public void shouldLogChannelInactive() throws Exception { + appender.doAppend(matchesLog(".+INACTIVE\\(\\)$")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.pipeline().fireChannelInactive(); + verify(appender); + } + + @Test + public void shouldLogChannelBind() throws Exception { + appender.doAppend(matchesLog(".+BIND\\(0.0.0.0/0.0.0.0:80\\)$")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.bind(new InetSocketAddress(80)); + verify(appender); + } + + @Test + public void shouldLogChannelUserEvent() throws Exception { + String userTriggered = "iAmCustom!"; + appender.doAppend(matchesLog(".+USER_EVENT\\(" + userTriggered + "\\)$")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.pipeline().fireUserEventTriggered(new String(userTriggered)); + verify(appender); + } + + @Test + public void shouldLogChannelException() throws Exception { + String msg = "illegalState"; + Throwable cause = new IllegalStateException(msg); + appender.doAppend(matchesLog(".+EXCEPTION\\(" + cause.getClass().getCanonicalName() + ": " + msg + "\\)$")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.pipeline().fireExceptionCaught(cause); + verify(appender); + } + + @Test + public void shouldLogDataWritten() throws Exception { + String msg = "hello"; + appender.doAppend(matchesLog(".+WRITE\\(\\): " + msg + "$")); + appender.doAppend(matchesLog(".+FLUSH\\(\\)")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.writeOutbound(msg); + verify(appender); + } + + @Test + public void shouldLogDataRead() throws Exception { + String msg = "hello"; + appender.doAppend(matchesLog(".+RECEIVED\\(\\): " + msg + "$")); + replay(appender); + EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); + channel.writeInbound(msg); + verify(appender); + } + + /** + * Static helper method for matching Logback messages. + * + * @param toMatch the regex to match. + * @return a mocked event to pass into the {@link Appender#doAppend(Object)} method. + */ + private static ILoggingEvent matchesLog(String toMatch) { + EasyMock.reportMatcher(new RegexLogMatcher(toMatch)); + return null; + } + + /** + * A custom EasyMock matcher that matches on Logback messages. + */ + private static class RegexLogMatcher implements IArgumentMatcher { + + private final String expected; + private String actualMsg; + + public RegexLogMatcher(String expected) { + this.expected = expected; + } + + @Override + public boolean matches(Object actual) { + if (!(actual instanceof ILoggingEvent)) { + return false; + } + + actualMsg = ((ILoggingEvent) actual).getMessage(); + return actualMsg.matches(expected); + } + + @Override + public void appendTo(StringBuffer buffer) { + buffer.append("matchesLog("); + buffer.append("expected: \"" + expected); + buffer.append("\", got: \"" + actualMsg); + buffer.append("\")"); + } + } + + private static final class DisconnectingEmbeddedChannel extends EmbeddedChannel { + + private DisconnectingEmbeddedChannel(ChannelHandler... handlers) { + super(handlers); + } + + @Override + public ChannelMetadata metadata() { + return new ChannelMetadata(true); + } + } +}