Description
Here is a code to reproduce the issue:
import org.apache.mina.core.buffer.IoBuffer; import org.apache.mina.core.service.IoHandlerAdapter; import org.apache.mina.core.session.IoSession; import org.apache.mina.filter.codec.*; import org.apache.mina.filter.logging.LoggingFilter; import org.apache.mina.transport.socket.nio.*; import org.junit.Test; public class LoggingTest { @Test public void using_LoggingFilter_and_ProtocolCodecFilter() throws Exception { NioSocketAcceptor acceptor = new NioSocketAcceptor(); acceptor.getFilterChain().addLast("logger", new LoggingFilter()); acceptor.getFilterChain().addLast("codec", new ProtocolCodecFilter(new MyProtocolEncoder(), new MyProtocolDecoder())); acceptor.setHandler(new IoHandlerAdapter() { public void messageReceived(IoSession session, Object message) throws Exception { session.write(message); } }); acceptor.bind(); NioSocketConnector connector = new NioSocketConnector(); connector.setHandler(new IoHandlerAdapter()); IoSession session = connector.connect(acceptor.getLocalAddress()).await().getSession(); session.write(IoBuffer.allocate(2). putChar('x'). flip()); Thread.sleep(1000); acceptor.unbind(); } private static class MyProtocolEncoder extends ProtocolEncoderAdapter { public void encode(IoSession session, Object message, ProtocolEncoderOutput out) throws Exception { String s = (String) message; out.write(IoBuffer.allocate(2). putChar(s.charAt(0)). flip()); } } private static class MyProtocolDecoder extends ProtocolDecoderAdapter { public void decode(IoSession session, IoBuffer in, ProtocolDecoderOutput out) throws Exception { char c = in.getChar(); out.write("" + c); } } }
When using mina-core 2.0.0-RC1 the above code will print properly:
11.5.2011 0:52:36 org.apache.mina.filter.logging.LoggingFilter log INFO: CREATED 11.5.2011 0:52:36 org.apache.mina.filter.logging.LoggingFilter log INFO: OPENED 11.5.2011 0:52:36 org.apache.mina.filter.logging.LoggingFilter log INFO: RECEIVED: HeapBuffer[pos=0 lim=2 cap=2048: 00 78] 11.5.2011 0:52:36 org.apache.mina.filter.logging.LoggingFilter log INFO: SENT: HeapBuffer[pos=0 lim=2 cap=2: 00 78] 11.5.2011 0:52:36 org.apache.mina.filter.logging.LoggingFilter log INFO: SENT: HeapBuffer[pos=0 lim=0 cap=0: empty] 11.5.2011 0:52:37 org.apache.mina.filter.logging.LoggingFilter log INFO: CLOSED
But when using mina-core 2.0.0 or higher (at least up to 2.0.3), it will not log the "INFO: SENT: HeapBuffer[pos=0 lim=2 cap=2: 00 78]" line:
11.5.2011 0:53:10 org.apache.mina.filter.logging.LoggingFilter log INFO: CREATED 11.5.2011 0:53:10 org.apache.mina.filter.logging.LoggingFilter log INFO: OPENED 11.5.2011 0:53:10 org.apache.mina.filter.logging.LoggingFilter log INFO: RECEIVED: HeapBuffer[pos=0 lim=2 cap=2048: 00 78] 11.5.2011 0:53:10 org.apache.mina.filter.logging.LoggingFilter log INFO: SENT: HeapBuffer[pos=0 lim=0 cap=0: empty] 11.5.2011 0:53:11 org.apache.mina.filter.logging.LoggingFilter log INFO: CLOSED