使用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()前面添加打印错误信息“****** 读取数据不完整,再次读取......”
运行正常和出错时的控制台打印信息如下(由于实际打印行数太多,我用"......"代替了部分重复行):
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
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
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
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)。
附:
问题处理前控制台打印结果
![](https://images.cnblogs.com/OutliningIndicators/ContractedBlock.gif)
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")。