netty LoggingHandler prints multpile messages in one frame and counts length too big

Question

I have built a WebSocket client to keep sending same message to an echo server and count the received bytes. The sever returns message like :

WebSocketData[received message]

But when I check the log printed by LoggingHandler, the received messages send by echo server stick together. So when I put an BytesCountingHandler before the LoggingHandler, the counted result of one single message is too big than usual.

I want to ask: am I doing this wrong?

My preliminary class is below:

connect and send message:

b.group(group)
                .channel(NioSocketChannel.class)
                .handler(new ChannelInitializer<SocketChannel>() {
                    @Override
                    protected void initChannel(SocketChannel ch) {
                        ChannelPipeline p = ch.pipeline();
                        if (sslCtx != null) {
                            p.addLast(sslCtx.newHandler(ch.alloc(), host, port));
                        }
                        p.addLast(
                                new BytesCountHandler(),
                                new LoggingHandler(LogLevel.INFO),
                                new HttpClientCodec(),
                                new HttpObjectAggregator(8192),
                                handler);
                    }
                });
        Channel ch = b.connect(uri.getHost(), port).sync().channel();
        handler.handshakeFuture().sync();

        for (;;) {
            String msg = "hello websocket";
            WebSocketFrame frame = new TextWebSocketFrame(msg);
            ch.writeAndFlush(frame);
        }

BytesCountHandler:

public class BytesCountHandler extends ChannelDuplexHandler {

@Override
public void write(ChannelHandlerContext ctx, Object msg, ChannelPromise promise) throws Exception {
    super.write(ctx, msg, promise);
}

@Override
public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception {
    System.out.println(countMessage(msg));
    super.channelRead(ctx, msg);
}

private int countMessage(Object msg) {
    if (msg instanceof ByteBuf) {
        return countBytes((ByteBuf) msg);
    } else if (msg instanceof ByteBufHolder) {
        return countByteBufHolder((ByteBufHolder) msg);
    }
    return 0;
}

private int countBytes(ByteBuf buf) {
    return buf.readableBytes();
}

private int countByteBufHolder(ByteBufHolder bufHolder) {
    return countBytes(bufHolder.content());
}

log without LoggingHandler:

129
WebSocket Client connected!
320
96
32
32
32
192
160
320
96
448
448

log with LoggingHandler:

...
WebSocket Client connected!
五月 09, 2017 10:08:33 上午 io.netty.handler.logging.LoggingHandler logMessage
信息: [id: 0xed597528, /10.128.7.104:20558 => /10.128.106.20:8085] WRITE(21B)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 81 8f 1f 79 b5 46 77 1c d9 2a 70 59 c2 23 7d 0a |...y.Fw..*pY.#}.|
|00000010| da 25 74 1c c1                                  |.%t..           |
+--------+-------------------------------------------------+----------------+
五月 09, 2017 10:08:33 上午 io.netty.handler.logging.LoggingHandler flush
信息: [id: 0xed597528, /10.128.7.104:20558 => /10.128.106.20:8085] FLUSH
五月 09, 2017 10:08:33 上午 io.netty.handler.logging.LoggingHandler logMessage
信息: [id: 0xed597528, /10.128.7.104:20558 => /10.128.106.20:8085] RECEIVED(32B)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000010| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
+--------+-------------------------------------------------+----------------+
...
五月 09, 2017 10:08:33 上午 io.netty.handler.logging.LoggingHandler logMessage
信息: [id: 0xed597528, /10.128.7.104:20558 => /10.128.106.20:8085] RECEIVED(512B)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000010| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|00000020| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000030| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|00000040| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000050| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|00000060| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000070| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|00000080| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000090| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|000000a0| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|000000b0| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|000000c0| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|000000d0| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|000000e0| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|000000f0| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|00000100| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000110| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
|00000120| 81 1e 57 65 62 53 6f 63 6b 65 74 44 61 74 61 5b |..WebSocketData[|
|00000130| 68 65 6c 6c 6f 20 77 65 62 73 6f 63 6b 65 74 5d |hello websocket]|
...

I hope I have discribed clearly

Thanks

An

score 0 · Answer 1 · answered May 09 '17 at 08:27

0

You are counting low level networking data, rather than the content of your frames.

Since you want to count and print the contents of the websocket frames, instead of the wrapper by the HTTP & WS layers, you should move the logging handler more down:

p.addLast(                              
    new HttpClientCodec(),
    new HttpObjectAggregator(8192),
    new LoggingHandler(LogLevel.INFO),
    handler);

answered May 09 '17 at 08:27

Ferrybig

18,194
6
57
79

Thanks！ Actually I want count the wrapper by the HTTP & WS layers, I just confused that way didn't work. – ayw May 09 '17 at 09:25
Counting the exact bytes is really hard, because the fact that TCP appends all the incoming buffers to each other by certain facts, see http://netty.io/wiki/user-guide-for-4.x.html#dealing-with-a-stream-based-transport why this happens – Ferrybig May 09 '17 at 09:27

netty LoggingHandler prints multpile messages in one frame and counts length too big

1 Answers1