首页 > 代码库 > 使用netty4.x客户端接收较大数据量报文时发生的读取不完整bug修复记录

使用netty4.x客户端接收较大数据量报文时发生的读取不完整bug修复记录

1、先说问题

背景:服务是运行在Linux上的安全网关提供的,TCP协议发送 通过二进制编码的xml字符串 报文,报文头的第一个字段是int类型的表示字节序标记,第二个字段是int类型的表示整个报文长度。

现象:数据量较小时完全可以正常收发报文,当服务端发送的报文数据量较大时(本例是将近600k)概率性出现接收数据直接调用readComplete()方法而没有走channelRead()

跟踪:跟踪代码发现出问题时context 的 read() 方法执行中读取到一百多k(有时两百多也可能三百多,总之是还没读取到全部数据)时某次读到的数据本应该是1024字节(填满默认分配的ByteBuf)却只读到了576字节;

    netty框架代码中判断如果当前读到的字节数小于ByteBuf的size则认为是读取完成,因此调用了readComplete()方法,出错。。。

解决方案:在ClientHandler类添加一个标记flag,用于是否正常读取数据判断。channelRead()方法正常调用则将其置为true;readComplete方法中添加一个判断只有当flag为true时关闭context否则继续调用ctx.read()。

2、再上核心代码

Client:

 1 ClientHandler clientHandler = new ClientHandler(this);
 2             bootstrap.group(eventLoop)
 3                     .channel(NioSocketChannel.class)
 4                     .option(ChannelOption.TCP_NODELAY, true)
 5                     .option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 3000)
 6                     .option(ChannelOption.MAX_MESSAGES_PER_READ, Integer.MAX_VALUE)
 7                     .handler(new ClientChannelInitializer(clientHandler));
 8             
 9             ChannelFuture f = bootstrap.connect(host, port).sync();
10 
11             f.channel().closeFuture().sync();
 1 private class ClientChannelInitializer extends ChannelInitializer<SocketChannel> {
 2         private ClientHandler clientHandler;
 3 
 4         public ClientChannelInitializer(ClientHandler clientHandler) {
 5             this.clientHandler = clientHandler;
 6         }
 7 
 8         @Override
 9         protected void initChannel(SocketChannel socketChannel) throws Exception {
10 
11             socketChannel.pipeline().addLast(new SplDecoder());
12             socketChannel.pipeline().addLast(clientHandler);
13             channel = socketChannel;
14         }
15     }
// 解决问题前 initChannel的实现是这样的,使用了netty内部的长度字段解码器
@Override
protected void initChannel(SocketChannel ch) throws Exception { ch.pipeline().addLast(new LengthFieldBasedFrameDecoder(Integer.MAX_VALUE,4,4,-8,0)); ch.pipeline().addLast(clientHandler); }

 

ClientHandler:

public class ClientHandler extends ChannelInboundHandlerAdapter {
 1 @Override
 2     public void channelActive(ChannelHandlerContext context) throws Exception {
 3         logger.info("Ready to send request...");
 4         ByteBuffer result = getByteBuffer();
 5         ByteBuf buf = Unpooled.buffer(result.remaining());
 6         buf.writeBytes(result);
 7 
 8         context.writeAndFlush(buf);
 9     }
10 
11     @Override
12     public void channelRead(ChannelHandlerContext context, Object msg) throws Exception {
13         logger.info("Get server response...");
14 
15         String[] result = (String[]) msg;
16 
17         logger.debug("response xml is : " + result[1]);
18         client.setResponse(result);
19 
20         ok = true;
21     }
22 
23     @Override
24     public void channelReadComplete(ChannelHandlerContext ctx) throws Exception {
25         ctx.flush();
26         if (ok) {
27             ctx.close();
28         } else {
29             ctx.read();
30         }
31     }

3、最后说解决过程

起初我怀疑是使用netty的定长字段解码器LengthFieldBasedFrameDecoder参数不当引起的,因为自认为对它理解不深;于是自己写了一个继承byteToMessageDecoder的解码器可以实现解决拆包问题和解码功能,但是问题依然概率性出现...

后来抱着试试看的态度在ClientHandler里面添加了一个实例属性ok(默认false),在正常执行channelRead()方法后将其置为true,readComplete()方法中做判断如果ok==false调用ctx.read(),运行发现完美解决问题

因为调用read()方法是继续读取数据而不是重新读取(因为此时ctx和channel、pipline等数据状态都没变)!

在SplDecoder类中添加当前读取数据打印信息:“logger.debug("读取数据:本次" + readableBytes + ";累计" + currentLength + ";总共" + total);”;

在ctx.read()前面添加打印错误信息“****** 读取数据不完整,再次读取......”

运行正常和出错时的控制台打印信息如下(由于实际打印行数太多,我用"......"代替了部分重复行):

技术分享
 1 Connected to the target VM, address: ‘127.0.0.1:62194‘, transport: ‘socket‘
 2 log4j:WARN No appenders could be found for logger (io.netty.util.internal.logging.InternalLoggerFactory).
 3 log4j:WARN Please initialize the log4j system properly.
 4 读取数据:本次1024;累计1024;总共574842
 5 读取数据:本次1024;累计2048;总共574842
 6 读取数据:本次1024;累计3072;总共574842
 7 ......
 8 读取数据:本次1024;累计572416;总共574842
 9 读取数据:本次1024;累计573440;总共574842
10 读取数据:本次1024;累计574464;总共574842
11 读取数据:本次378;累计574842;总共574842
12 0 ~~ null
13 Disconnected from the target VM, address: ‘127.0.0.1:62194‘, transport: ‘socket‘
14 
15 Process finished with exit code 0
正常时结果
技术分享
 1 Connected to the target VM, address: ‘127.0.0.1:62068‘, transport: ‘socket‘
 2 log4j:WARN No appenders could be found for logger (io.netty.util.internal.logging.InternalLoggerFactory).
 3 log4j:WARN Please initialize the log4j system properly.
 4 读取数据:本次1024;累计1024;总共574842
 5 读取数据:本次1024;累计2048;总共574842
 6 读取数据:本次1024;累计3072;总共574842
 7 读取数据:本次1024;累计4096;总共574842
 8 读取数据:本次1024;累计5120;总共574842
 9 读取数据:本次1024;累计6144;总共574842
10 读取数据:本次1024;累计7168;总共574842
11 读取数据:本次1024;累计8192;总共574842
12 读取数据:本次1024;累计9216;总共574842
13 读取数据:本次1024;累计10240;总共574842
14 读取数据:本次1024;累计11264;总共574842
15 读取数据:本次1024;累计12288;总共574842
16 读取数据:本次1024;累计13312;总共574842
17 读取数据:本次576;累计13888;总共574842
18 ****** 读取数据不完整,再次读取......
19 读取数据:本次16384;累计30272;总共574842
20 读取数据:本次16384;累计46656;总共574842
21 读取数据:本次16384;累计63040;总共574842
22 ......
23 读取数据:本次16384;累计554560;总共574842
24 读取数据:本次16384;累计570944;总共574842
25 读取数据:本次3898;累计574842;总共574842
26 0 ~~ null
27 Disconnected from the target VM, address: ‘127.0.0.1:62068‘, transport: ‘socket‘
28 
29 Process finished with exit code 0
出错时结果

 结果最后打印0~~null表示正常结束(返回code为0错误信息为null)。

附:

问题处理前控制台打印结果

技术分享
1 "C:\Program Files...
2 log4j:WARN No appenders could be found for logger (io.netty.util.internal.logging.InternalLoggerFactory).
3 log4j:WARN Please initialize the log4j system properly.
4 -1 ~~ 服务异常;Detail:java.lang.NullPointerException
5 
6 Process finished with exit code 0
问题处理前控制台打印信息

由于没有执行channelRead()方法,所以我获取到的数据没能执行赋值操作,报了空指针异常。

结果最后打印 -1 ~~ 服务异常;Detail:java.lang.NullPointerException 表示发生了异常(返回code为-1;错误信息为"服务异常;Detail:java.lang.NullPointerException")

使用netty4.x客户端接收较大数据量报文时发生的读取不完整bug修复记录