andreacavalli/netty5
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Optimize and clean up LoggingHandler

Browse Source 
- Use ': ' instead of '(...)' for simpler string concatenation and prettier presentation
- Optimize the overall performance of format*() methods
- All format*() methods are now expected to encode the channel information by themselves so that StringBuilder instances are created less often.
- Use a look-up table for generating per-row prefixes
- Hid formatByteBuf(), formatByteBufHolder(), and formatNonByteBuf() from user because a user can always override format(ctx, eventName, arg).  For example, to disable hexdump:

    protected void format(ChannelHandlerContext ctx, String eventName, Object arg) {
        if (arg instanceof ByteBuf) {
            super.format(ctx, eventName, arg.toString());
        } else {
            super.format(ctx, eventName, arg);
        }
    }
This commit is contained in:
Trustin Lee 2013-12-02 18:43:49 +09:00
parent a4e4479407
commit 5e575daefc
2 changed files with 275 additions and 115 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

269
handler/src/main/java/io/netty/handler/logging/LoggingHandler.java
View File

@ -33,6 +33,7 @@ import java.net.SocketAddress;
* By default, all events are logged at <tt>DEBUG</tt> level. * By default, all events are logged at <tt>DEBUG</tt> level.
*/ */
@Sharable @Sharable
@SuppressWarnings("StringBufferReplaceableByString")
public class LoggingHandler extends ChannelHandlerAdapter { public class LoggingHandler extends ChannelHandlerAdapter {
private static final LogLevel DEFAULT_LEVEL = LogLevel.DEBUG; private static final LogLevel DEFAULT_LEVEL = LogLevel.DEBUG;
@ -43,6 +44,7 @@ public class LoggingHandler extends ChannelHandlerAdapter {
private static final String[] HEXPADDING = new String[16]; private static final String[] HEXPADDING = new String[16];
private static final String[] BYTEPADDING = new String[16]; private static final String[] BYTEPADDING = new String[16];
private static final char[] BYTE2CHAR = new char[256]; private static final char[] BYTE2CHAR = new char[256];
private static final String[] HEXDUMP_ROWPREFIXES = new String[65536 >>> 4];
static { static {
int i; int i;
@ -95,6 +97,16 @@ public class LoggingHandler extends ChannelHandlerAdapter {
BYTE2CHAR[i] = (char) i; BYTE2CHAR[i] = (char) i;
} }
} }
// Generate the lookup table for the start-offset header in each row (up to 64KiB).
for (i = 0; i < HEXDUMP_ROWPREFIXES.length; i ++) {
StringBuilder buf = new StringBuilder(12);
buf.append(NEWLINE);
buf.append(Long.toHexString(i << 4 & 0xFFFFFFFFL | 0x100000000L));
buf.setCharAt(buf.length() - 9, '|');
buf.append('|');
HEXDUMP_ROWPREFIXES[i] = buf.toString();
}
} }
protected final InternalLogger logger; protected final InternalLogger logger;
@ -189,190 +201,250 @@ public class LoggingHandler extends ChannelHandlerAdapter {
return level; 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);
buf.append(chStr);
buf.append(' ');
buf.append(message);
return buf.toString();
}
@Override @Override
public void channelRegistered(ChannelHandlerContext ctx) throws Exception { public void channelRegistered(ChannelHandlerContext ctx) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "REGISTERED()")); logger.log(internalLevel, format(ctx, "REGISTERED"));
} }
super.channelRegistered(ctx); ctx.fireChannelRegistered();
} }
@Override @Override
public void channelActive(ChannelHandlerContext ctx) throws Exception { public void channelActive(ChannelHandlerContext ctx) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "ACTIVE()")); logger.log(internalLevel, format(ctx, "ACTIVE"));
} }
super.channelActive(ctx); ctx.fireChannelActive();
} }
@Override @Override
public void channelInactive(ChannelHandlerContext ctx) throws Exception { public void channelInactive(ChannelHandlerContext ctx) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "INACTIVE()")); logger.log(internalLevel, format(ctx, "INACTIVE"));
} }
super.channelInactive(ctx); ctx.fireChannelInactive();
} }
@Override @Override
public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception { public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "EXCEPTION(" + cause + ')'), cause); logger.log(internalLevel, format(ctx, "EXCEPTION", cause), cause);
} }
super.exceptionCaught(ctx, cause); ctx.fireExceptionCaught(cause);
} }
@Override @Override
public void userEventTriggered(ChannelHandlerContext ctx, Object evt) throws Exception { public void userEventTriggered(ChannelHandlerContext ctx, Object evt) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "USER_EVENT(" + evt + ')')); logger.log(internalLevel, format(ctx, "USER_EVENT", evt));
} }
super.userEventTriggered(ctx, evt); ctx.fireUserEventTriggered(evt);
} }
@Override @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)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "BIND(" + localAddress + ')')); logger.log(internalLevel, format(ctx, "BIND", localAddress));
} }
super.bind(ctx, localAddress, promise); ctx.bind(localAddress, promise);
} }
@Override @Override
public void connect(ChannelHandlerContext ctx, SocketAddress remoteAddress, SocketAddress localAddress, public void connect(ChannelHandlerContext ctx, SocketAddress remoteAddress, SocketAddress localAddress,
ChannelPromise promise) throws Exception { ChannelPromise promise) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "CONNECT(" + remoteAddress + ", " + localAddress + ')')); logger.log(internalLevel, format(ctx, "CONNECT", remoteAddress, localAddress));
} }
super.connect(ctx, remoteAddress, localAddress, promise); ctx.connect(remoteAddress, localAddress, promise);
} }
@Override @Override
public void disconnect(ChannelHandlerContext ctx, ChannelPromise promise) throws Exception { public void disconnect(ChannelHandlerContext ctx, ChannelPromise promise) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "DISCONNECT()")); logger.log(internalLevel, format(ctx, "DISCONNECT"));
} }
super.disconnect(ctx, promise); ctx.disconnect(promise);
} }
@Override @Override
public void close(ChannelHandlerContext ctx, ChannelPromise promise) throws Exception { public void close(ChannelHandlerContext ctx, ChannelPromise promise) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "CLOSE()")); logger.log(internalLevel, format(ctx, "CLOSE"));
} }
super.close(ctx, promise); ctx.close(promise);
} }
@Override @Override
public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception { public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception {
logMessage(ctx, "RECEIVED()", msg); if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "RECEIVED", msg));
}
ctx.fireChannelRead(msg); ctx.fireChannelRead(msg);
} }
@Override @Override
public void write(ChannelHandlerContext ctx, Object msg, ChannelPromise promise) throws Exception { public void write(ChannelHandlerContext ctx, Object msg, ChannelPromise promise) throws Exception {
logMessage(ctx, "WRITE()", msg); if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "WRITE", msg));
}
ctx.write(msg, promise); ctx.write(msg, promise);
} }
@Override @Override
public void flush(ChannelHandlerContext ctx) throws Exception { public void flush(ChannelHandlerContext ctx) throws Exception {
if (logger.isEnabled(internalLevel)) { if (logger.isEnabled(internalLevel)) {
logger.log(internalLevel, format(ctx, "FLUSH()")); logger.log(internalLevel, format(ctx, "FLUSH"));
} }
ctx.flush(); ctx.flush();
} }
/** /**
* Helper method to log the message only if the loger is enabled for the given level. * Formats an event and returns the formatted message.
* *
* @param ctx the channel context. * @param eventName the name of the event
* @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) { protected String format(ChannelHandlerContext ctx, String eventName) {
if (logger.isEnabled(internalLevel)) { String chStr = ctx.channel().toString();
logger.log(internalLevel, format(ctx, formatMessage(eventName, msg))); StringBuilder buf = new StringBuilder(chStr.length() + 1 + eventName.length());
} buf.append(chStr);
buf.append(' ');
buf.append(eventName);
return buf.toString();
} }
/** /**
* Helper method to format the message content. * Formats an event and returns the formatted message.
* *
* @param eventName the name of the event to log. * @param eventName the name of the event
* @param msg the actual message to format. * @param arg the argument of the event
* @return the formatted message.
*/ */
protected String formatMessage(String eventName, Object msg) { protected String format(ChannelHandlerContext ctx, String eventName, Object arg) {
if (msg instanceof ByteBuf) { if (arg instanceof ByteBuf) {
return formatByteBuf(eventName, (ByteBuf) msg); return formatByteBuf(ctx, eventName, (ByteBuf) arg);
} else if (msg instanceof ByteBufHolder) { } else if (arg instanceof ByteBufHolder) {
return formatByteBufHolder(eventName, (ByteBufHolder) msg); return formatByteBufHolder(ctx, eventName, (ByteBufHolder) arg);
} else { } else {
return formatNonByteBuf(eventName, msg); return formatUserMessage(ctx, eventName, arg);
} }
} }
/** /**
* Returns a String which contains all details to log the {@link ByteBuf}. * Formats an event and returns the formatted message.
* *
* @param eventName the name of the event to log. * @param eventName the name of the event
* @param buf the buffer to log. * @param firstArg the first argument of the event
* @param secondArg the second argument of the event
*/ */
protected String formatByteBuf(String eventName, ByteBuf buf) { protected String format(ChannelHandlerContext ctx, String eventName, Object firstArg, Object secondArg) {
int length = buf.readableBytes(); String chStr = ctx.channel().toString();
int rows = length / 16 + (length % 15 == 0? 0 : 1) + 4; String arg1Str = String.valueOf(firstArg);
StringBuilder dump = new StringBuilder(rows * 80 + eventName.length() + 16); if (secondArg == null) {
StringBuilder buf = new StringBuilder(chStr.length() + 1 + eventName + 2 + arg1Str.length());
buf.append(chStr).append(' ').append(eventName).append(": ").append(arg1Str);
return buf.toString();
} else {
String arg2Str = secondArg.toString();
StringBuilder buf = new StringBuilder(
chStr.length() + 1 + eventName + 2 + arg1Str.length() + 2 + arg2Str.length());
buf.append(chStr).append(' ').append(eventName).append(": ").append(arg1Str).append(", ").append(arg2Str);
return buf.toString();
}
}
dump.append(eventName).append('(').append(length).append('B').append(')'); /**
* Generates the default log message of the specified event whose argument is a {@link ByteBuf}.
*/
private static String formatByteBuf(ChannelHandlerContext ctx, String eventName, ByteBuf msg) {
String chStr = ctx.channel().toString();
int length = msg.readableBytes();
if (length == 0) {
StringBuilder buf = new StringBuilder(chStr.length() + 1 + eventName.length() + 4);
buf.append(chStr).append(' ').append(eventName).append(": 0B");
return buf.toString();
} else {
int rows = length / 16 + (length % 15 == 0? 0 : 1) + 4;
StringBuilder buf = new StringBuilder(chStr.length() + 1 + eventName.length() + 2 + 10 + 1 + 2 + rows * 80);
buf.append(chStr).append(' ').append(eventName).append(": ").append(length).append('B');
appendHexDump(buf, msg);
return buf.toString();
}
}
/**
* Generates the default log message of the specified event whose argument is a {@link ByteBufHolder}.
*/
private static String formatByteBufHolder(ChannelHandlerContext ctx, String eventName, ByteBufHolder msg) {
String chStr = ctx.channel().toString();
String msgStr = msg.toString();
ByteBuf content = msg.content();
int length = content.readableBytes();
if (length == 0) {
StringBuilder buf = new StringBuilder(chStr.length() + 1 + eventName.length() + 2 + msgStr.length() + 4);
buf.append(chStr).append(' ').append(eventName).append(", ").append(msgStr).append(", 0B");
return buf.toString();
} else {
int rows = length / 16 + (length % 15 == 0? 0 : 1) + 4;
StringBuilder buf = new StringBuilder(
chStr.length() + 1 + eventName.length() + 2 + msgStr.length() + 2 + 10 + 1 + 2 + rows * 80);
buf.append(chStr).append(' ').append(eventName).append(": ");
buf.append(msgStr).append(", ").append(length).append('B');
appendHexDump(buf, content);
return buf.toString();
}
}
private static void appendHexDump(StringBuilder dump, ByteBuf buf) {
dump.append( dump.append(
NEWLINE + " +-------------------------------------------------+" + NEWLINE + " +-------------------------------------------------+" +
NEWLINE + " | 0 1 2 3 4 5 6 7 8 9 a b c d e f |" + NEWLINE + " | 0 1 2 3 4 5 6 7 8 9 a b c d e f |" +
NEWLINE + "+--------+-------------------------------------------------+----------------+"); NEWLINE + "+--------+-------------------------------------------------+----------------+");
final int startIndex = buf.readerIndex(); final int startIndex = buf.readerIndex();
final int endIndex = buf.writerIndex(); final int endIndex = buf.writerIndex();
final int length = endIndex - startIndex;
final int fullRows = length >>> 4;
final int remainder = length & 0xF;
int i; // Dump the rows which have 16 bytes.
for (i = startIndex; i < endIndex; i ++) { for (int row = 0; row < fullRows; row ++) {
int relIdx = i - startIndex; int rowStartIndex = row << 4;
int relIdxMod16 = relIdx & 15;
if (relIdxMod16 == 0) { // Per-row prefix.
dump.append(NEWLINE); appendHexDumpRowPrefix(dump, row, rowStartIndex);
dump.append(Long.toHexString(relIdx & 0xFFFFFFFFL | 0x100000000L));
dump.setCharAt(dump.length() - 9, '|'); // Hex dump
dump.append('|'); int rowEndIndex = rowStartIndex + 16;
for (int j = rowStartIndex; j < rowEndIndex; j ++) {
dump.append(BYTE2HEX[buf.getUnsignedByte(j)]);
} }
dump.append(BYTE2HEX[buf.getUnsignedByte(i)]); dump.append(" |");
if (relIdxMod16 == 15) {
dump.append(" |"); // ASCII dump
for (int j = i - 15; j <= i; j ++) { for (int j = rowStartIndex; j < rowEndIndex; j ++) {
dump.append(BYTE2CHAR[buf.getUnsignedByte(j)]); dump.append(BYTE2CHAR[buf.getUnsignedByte(j)]);
}
dump.append('|');
} }
dump.append('|');
} }
if ((i - startIndex & 15) != 0) { // Dump the last row which has less than 16 bytes.
int remainder = length & 15; if (remainder != 0) {
int rowStartIndex = fullRows << 4;
appendHexDumpRowPrefix(dump, fullRows, rowStartIndex);
// Hex dump
int rowEndIndex = rowStartIndex + remainder;
for (int j = rowStartIndex; j < rowEndIndex; j ++) {
dump.append(BYTE2HEX[buf.getUnsignedByte(j)]);
}
dump.append(HEXPADDING[remainder]); dump.append(HEXPADDING[remainder]);
dump.append(" |"); dump.append(" |");
for (int j = i - remainder; j < i; j ++) {
// Ascii dump
for (int j = rowStartIndex; j < rowEndIndex; j ++) {
dump.append(BYTE2CHAR[buf.getUnsignedByte(j)]); dump.append(BYTE2CHAR[buf.getUnsignedByte(j)]);
} }
dump.append(BYTEPADDING[remainder]); dump.append(BYTEPADDING[remainder]);
@ -380,24 +452,29 @@ public class LoggingHandler extends ChannelHandlerAdapter {
} }
dump.append(NEWLINE + "+--------+-------------------------------------------------+----------------+"); dump.append(NEWLINE + "+--------+-------------------------------------------------+----------------+");
return dump.toString();
} }
/** /**
* Returns a String which contains all details to log the {@link Object}. * Appends the prefix of each hex dump row. Uses the look-up table for the buffer <= 64 KiB.
*/ */
protected String formatNonByteBuf(String eventName, Object msg) { private static void appendHexDumpRowPrefix(StringBuilder dump, int row, int rowStartIndex) {
return eventName + ": " + msg; if (row < HEXDUMP_ROWPREFIXES.length) {
dump.append(HEXDUMP_ROWPREFIXES[row]);
} else {
dump.append(NEWLINE);
dump.append(Long.toHexString(rowStartIndex & 0xFFFFFFFFL | 0x100000000L));
dump.setCharAt(dump.length() - 9, '|');
dump.append('|');
}
} }
/** /**
* Returns a String which contains all details to log the {@link ByteBufHolder}. * Generates the default log message of the specified event whose argument is an arbitrary object.
*
* By default this method just delegates to {@link #formatByteBuf(String, ByteBuf)},
* using the content of the {@link ByteBufHolder}. Sub-classes may override this.
*/ */
protected String formatByteBufHolder(String eventName, ByteBufHolder msg) { private static String formatUserMessage(ChannelHandlerContext ctx, String eventName, Object msg) {
return formatByteBuf(eventName, msg.content()); String chStr = ctx.channel().toString();
String msgStr = String.valueOf(msg);
StringBuilder buf = new StringBuilder(chStr.length() + 1 + eventName.length() + 2 + msgStr.length());
return buf.append(chStr).append(' ').append(eventName).append(": ").append(msgStr).toString();
} }
} }

121
handler/src/test/java/io/netty/handler/logging/LoggingHandlerTest.java
View File

@ -18,37 +18,72 @@ package io.netty.handler.logging;
import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.Appender; import ch.qos.logback.core.Appender;
import io.netty.buffer.ByteBuf;
import io.netty.buffer.ByteBufHolder;
import io.netty.buffer.DefaultByteBufHolder;
import io.netty.buffer.Unpooled;
import io.netty.channel.ChannelHandler; import io.netty.channel.ChannelHandler;
import io.netty.channel.ChannelMetadata; import io.netty.channel.ChannelMetadata;
import io.netty.channel.embedded.EmbeddedChannel; import io.netty.channel.embedded.EmbeddedChannel;
import org.easymock.EasyMock; import io.netty.util.CharsetUtil;
import org.easymock.IArgumentMatcher; import org.easymock.IArgumentMatcher;
import org.junit.After;
import org.junit.AfterClass;
import org.junit.Before; import org.junit.Before;
import org.junit.BeforeClass;
import org.junit.Test; import org.junit.Test;
import org.slf4j.LoggerFactory; import org.slf4j.LoggerFactory;
import java.net.InetSocketAddress; import java.net.InetSocketAddress;
import java.util.ArrayList;
import java.util.Iterator;
import java.util.List;
import static org.easymock.EasyMock.*; import static org.easymock.EasyMock.*;
import static org.junit.Assert.assertEquals; import static org.junit.Assert.*;
/** /**
* Verifies the correct functionality of the {@link LoggingHandler}. * Verifies the correct functionality of the {@link LoggingHandler}.
*/ */
public class LoggingHandlerTest { public class LoggingHandlerTest {
private static final Logger root = (Logger) LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME);
private static final List<Appender<ILoggingEvent>> oldAppenders = new ArrayList<Appender<ILoggingEvent>>();
/** /**
* Custom logback appender which gets used to match on log messages. * Custom logback appender which gets used to match on log messages.
*/ */
private Appender<ILoggingEvent> appender; private Appender<ILoggingEvent> appender;
@BeforeClass
public static void beforeClass() {
for (Iterator<Appender<ILoggingEvent>> i = root.iteratorForAppenders(); i.hasNext();) {
Appender<ILoggingEvent> a = i.next();
oldAppenders.add(a);
root.detachAppender(a);
}
Unpooled.buffer();
}
@AfterClass
public static void afterClass() {
for (Appender<ILoggingEvent> a: oldAppenders) {
root.addAppender(a);
}
}
@Before @Before
public void setupCustomAppender() { @SuppressWarnings("unchecked")
Logger root = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); public void setup() {
appender = createNiceMock(Appender.class); appender = createNiceMock(Appender.class);
root.addAppender(appender); root.addAppender(appender);
} }
@After
public void teardown() {
root.detachAppender(appender);
}
@Test(expected = NullPointerException.class) @Test(expected = NullPointerException.class)
public void shouldNotAcceptNullLogLevel() { public void shouldNotAcceptNullLogLevel() {
LogLevel level = null; LogLevel level = null;
@ -63,7 +98,7 @@ public class LoggingHandlerTest {
@Test @Test
public void shouldLogChannelActive() { public void shouldLogChannelActive() {
appender.doAppend(matchesLog(".+ACTIVE\\(\\)$")); appender.doAppend(matchesLog(".+ACTIVE$"));
replay(appender); replay(appender);
new EmbeddedChannel(new LoggingHandler()); new EmbeddedChannel(new LoggingHandler());
verify(appender); verify(appender);
@ -71,7 +106,7 @@ public class LoggingHandlerTest {
@Test @Test
public void shouldLogChannelRegistered() { public void shouldLogChannelRegistered() {
appender.doAppend(matchesLog(".+REGISTERED\\(\\)$")); appender.doAppend(matchesLog(".+REGISTERED$"));
replay(appender); replay(appender);
new EmbeddedChannel(new LoggingHandler()); new EmbeddedChannel(new LoggingHandler());
verify(appender); verify(appender);
@ -79,7 +114,7 @@ public class LoggingHandlerTest {
@Test @Test
public void shouldLogChannelClose() throws Exception { public void shouldLogChannelClose() throws Exception {
appender.doAppend(matchesLog(".+CLOSE\\(\\)$")); appender.doAppend(matchesLog(".+CLOSE$"));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.close().await(); channel.close().await();
@ -88,16 +123,25 @@ public class LoggingHandlerTest {
@Test @Test
public void shouldLogChannelConnect() throws Exception { public void shouldLogChannelConnect() throws Exception {
appender.doAppend(matchesLog(".+CONNECT\\(0.0.0.0/0.0.0.0:80, null\\)$")); appender.doAppend(matchesLog(".+CONNECT: 0.0.0.0/0.0.0.0:80$"));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.connect(new InetSocketAddress(80)).await(); channel.connect(new InetSocketAddress(80)).await();
verify(appender); verify(appender);
} }
@Test
public void shouldLogChannelConnectWithLocalAddress() throws Exception {
appender.doAppend(matchesLog(".+CONNECT: 0.0.0.0/0.0.0.0:80, 0.0.0.0/0.0.0.0:81$"));
replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.connect(new InetSocketAddress(80), new InetSocketAddress(81)).await();
verify(appender);
}
@Test @Test
public void shouldLogChannelDisconnect() throws Exception { public void shouldLogChannelDisconnect() throws Exception {
appender.doAppend(matchesLog(".+DISCONNECT\\(\\)$")); appender.doAppend(matchesLog(".+DISCONNECT$"));
replay(appender); replay(appender);
EmbeddedChannel channel = new DisconnectingEmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new DisconnectingEmbeddedChannel(new LoggingHandler());
channel.connect(new InetSocketAddress(80)).await(); channel.connect(new InetSocketAddress(80)).await();
@ -107,7 +151,7 @@ public class LoggingHandlerTest {
@Test @Test
public void shouldLogChannelInactive() throws Exception { public void shouldLogChannelInactive() throws Exception {
appender.doAppend(matchesLog(".+INACTIVE\\(\\)$")); appender.doAppend(matchesLog(".+INACTIVE$"));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.pipeline().fireChannelInactive(); channel.pipeline().fireChannelInactive();
@ -116,7 +160,7 @@ public class LoggingHandlerTest {
@Test @Test
public void shouldLogChannelBind() throws Exception { public void shouldLogChannelBind() throws Exception {
appender.doAppend(matchesLog(".+BIND\\(0.0.0.0/0.0.0.0:80\\)$")); appender.doAppend(matchesLog(".+BIND: 0.0.0.0/0.0.0.0:80$"));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.bind(new InetSocketAddress(80)); channel.bind(new InetSocketAddress(80));
@ -124,9 +168,10 @@ public class LoggingHandlerTest {
} }
@Test @Test
@SuppressWarnings("RedundantStringConstructorCall")
public void shouldLogChannelUserEvent() throws Exception { public void shouldLogChannelUserEvent() throws Exception {
String userTriggered = "iAmCustom!"; String userTriggered = "iAmCustom!";
appender.doAppend(matchesLog(".+USER_EVENT\\(" + userTriggered + "\\)$")); appender.doAppend(matchesLog(".+USER_EVENT: " + userTriggered + '$'));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.pipeline().fireUserEventTriggered(new String(userTriggered)); channel.pipeline().fireUserEventTriggered(new String(userTriggered));
@ -137,7 +182,7 @@ public class LoggingHandlerTest {
public void shouldLogChannelException() throws Exception { public void shouldLogChannelException() throws Exception {
String msg = "illegalState"; String msg = "illegalState";
Throwable cause = new IllegalStateException(msg); Throwable cause = new IllegalStateException(msg);
appender.doAppend(matchesLog(".+EXCEPTION\\(" + cause.getClass().getCanonicalName() + ": " + msg + "\\)$")); appender.doAppend(matchesLog(".+EXCEPTION: " + cause.getClass().getCanonicalName() + ": " + msg + '$'));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.pipeline().fireExceptionCaught(cause); channel.pipeline().fireExceptionCaught(cause);
@ -147,8 +192,8 @@ public class LoggingHandlerTest {
@Test @Test
public void shouldLogDataWritten() throws Exception { public void shouldLogDataWritten() throws Exception {
String msg = "hello"; String msg = "hello";
appender.doAppend(matchesLog(".+WRITE\\(\\): " + msg + "$")); appender.doAppend(matchesLog(".+WRITE: " + msg + '$'));
appender.doAppend(matchesLog(".+FLUSH\\(\\)")); appender.doAppend(matchesLog(".+FLUSH$"));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.writeOutbound(msg); channel.writeOutbound(msg);
@ -156,9 +201,45 @@ public class LoggingHandlerTest {
} }
@Test @Test
public void shouldLogDataRead() throws Exception { public void shouldLogNonByteBufDataRead() throws Exception {
String msg = "hello"; String msg = "hello";
appender.doAppend(matchesLog(".+RECEIVED\\(\\): " + msg + "$")); appender.doAppend(matchesLog(".+RECEIVED: " + msg + '$'));
replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.writeInbound(msg);
verify(appender);
}
@Test
public void shouldLogByteBufDataRead() throws Exception {
ByteBuf msg = Unpooled.copiedBuffer("hello", CharsetUtil.UTF_8);
appender.doAppend(matchesLog(".+RECEIVED: " + msg.readableBytes() + "B$"));
replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.writeInbound(msg);
verify(appender);
}
@Test
public void shouldLogEmptyByteBufDataRead() throws Exception {
ByteBuf msg = Unpooled.EMPTY_BUFFER;
appender.doAppend(matchesLog(".+RECEIVED: 0B$"));
replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.writeInbound(msg);
verify(appender);
}
@Test
public void shouldLogByteBufHolderDataRead() throws Exception {
ByteBufHolder msg = new DefaultByteBufHolder(Unpooled.copiedBuffer("hello", CharsetUtil.UTF_8)) {
@Override
public String toString() {
return "foobar";
}
};
appender.doAppend(matchesLog(".+RECEIVED: foobar, 5B$"));
replay(appender); replay(appender);
EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler()); EmbeddedChannel channel = new EmbeddedChannel(new LoggingHandler());
channel.writeInbound(msg); channel.writeInbound(msg);
@ -172,7 +253,7 @@ public class LoggingHandlerTest {
* @return a mocked event to pass into the {@link Appender#doAppend(Object)} method. * @return a mocked event to pass into the {@link Appender#doAppend(Object)} method.
*/ */
private static ILoggingEvent matchesLog(String toMatch) { private static ILoggingEvent matchesLog(String toMatch) {
EasyMock.reportMatcher(new RegexLogMatcher(toMatch)); reportMatcher(new RegexLogMatcher(toMatch));
return null; return null;
} }
@ -189,12 +270,14 @@ public class LoggingHandlerTest {
} }
@Override @Override
@SuppressWarnings("DynamicRegexReplaceableByCompiledPattern")
public boolean matches(Object actual) { public boolean matches(Object actual) {
if (!(actual instanceof ILoggingEvent)) { if (!(actual instanceof ILoggingEvent)) {
return false; return false;
} }
actualMsg = ((ILoggingEvent) actual).getMessage(); // Match only the first line to skip the validation of hex-dump format.
actualMsg = ((ILoggingEvent) actual).getMessage().split("(?s)[\\r\\n]+")[0];
return actualMsg.matches(expected); return actualMsg.matches(expected);
} }