netty实现http服务器keep-alive无效的问题排查

今天在用netty实现一个http服务器的时候,发现keep-alive并没有生效,具体表现是在request和response的header里都能看到keep-alive的标志:

request:
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
Accept-Encoding: gzip, deflate, br
Accept-Language: zh-CN,zh;q=0.9,en;q=0.8
Cache-Control: max-age=0
Connection: keep-alive

response:
HTTP/1.1 200 OK
content-type: text/html;charset=UTF-8
content-length: 0
connection: keep-alive

可以看出,无论是请求还是响应,都是keep-alive的,但是请求两次,服务器端日志如下:

七月 06, 2019 9:51:27 下午 io.netty.handler.logging.LoggingHandler channelRead
信息: [id: 0xade39344, L:/0:0:0:0:0:0:0:0:8080] READ: [id: 0x26d40041, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:33130]
七月 06, 2019 9:51:27 下午 io.netty.handler.logging.LoggingHandler channelReadComplete
信息: [id: 0xade39344, L:/0:0:0:0:0:0:0:0:8080] READ COMPLETE
keepAlive=true
channel id=26d40041
http uri: /a.txt?name=chen&f=123;key=456
name=chen
f=123
key=456
七月 06, 2019 9:51:29 下午 io.netty.handler.logging.LoggingHandler channelRead
信息: [id: 0xade39344, L:/0:0:0:0:0:0:0:0:8080] READ: [id: 0x600995e6, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:33156]
七月 06, 2019 9:51:29 下午 io.netty.handler.logging.LoggingHandler channelReadComplete
信息: [id: 0xade39344, L:/0:0:0:0:0:0:0:0:8080] READ COMPLETE
keepAlive=true
channel id=600995e6
http uri: /a.txt?name=chen&f=123;key=456
name=chen
f=123
key=456

客户端两次连接的socket端口一次是33130,第二次是33156,channel id也不一样,证明确实是两个连接,keep-alive并没有生效。

其中,channel id来自这里

@Override
public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception {
     //
     System.out.println("channel id="+ctx.channel().id());
}

为什么呢,看下代码中Server和ServerHandle也没什么问题,关键代码如下:

serverBootstrap.channel(NioServerSocketChannel.class)
                    .group(boss, work)
                    .handler(new LoggingHandler(LogLevel.INFO))                    // handler在初始化时就会执行,可以设置打印日志级别
                    .childHandler(new ChannelInitializer<SocketChannel>() {
                        @Override
                        protected void initChannel(SocketChannel ch) throws Exception {
                            ch.pipeline().addLast("http-coder",new HttpServerCodec());
                            ch.pipeline().addLast("aggregator",new HttpObjectAggregator(1024*1024));  //在处理 POST消息体时需要加上
                            ch.pipeline().addLast(new HttpServerHandler());
                        }
                    })
                    .option(ChannelOption.SO_BACKLOG, 1024)
                    .childOption(ChannelOption.SO_KEEPALIVE, true)
                    .childOption(ChannelOption.TCP_NODELAY, true);
//handle代码
httpResponse.headers().set(HttpHeaderNames.CONTENT_TYPE, "text/html;charset=UTF-8");
            httpResponse.headers().setInt(HttpHeaderNames.CONTENT_LENGTH, httpResponse.content().readableBytes());
            if (keepAlive) {
                httpResponse.headers().set(HttpHeaderNames.CONNECTION, HttpHeaderValues.KEEP_ALIVE);
                ctx.writeAndFlush(httpResponse);
            } else {
                ctx.writeAndFlush(httpResponse).addListener(ChannelFutureListener.CLOSE);
            }

代码很明显,如果请求是 keep-alive的,那么响应头也加上keep-alive标志,从而实现了长连接。看了半天代码没看出端倪来,突然注意到了在浏览器中,F12看到了/favicon.ico的请求一直是pending的,也就是阻塞在了这里,代码里是这么写的

//去除浏览器"/favicon.ico"的干扰
if (uri.equals(FAVICON_ICO)) {
      return ;
 }

这段代码来自我参考的别人的代码,本意是要忽略 /favicon.ico这种无效的请求,但是由于直接return了,导致当前连接被阻塞了,如果这时刷新,就会导致新开一个连接来处理请求。要解决这个问题很简单,只需要注释掉这段代码,对于/favicon.ico请求,直接返回空的200状态码就好了。

现在再来看下请求日志:

信息: [id: 0xee8bc5e1, L:/0:0:0:0:0:0:0:0:8080] READ: [id: 0x734e2ebb, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:37386]
七月 06, 2019 10:03:48 下午 io.netty.handler.logging.LoggingHandler channelReadComplete
信息: [id: 0xee8bc5e1, L:/0:0:0:0:0:0:0:0:8080] READ COMPLETE
keepAlive=true
channel id=734e2ebb
http uri: /a.txt?name=chen&f=123;key=456
name=chen
f=123
key=456
keepAlive=true
channel id=734e2ebb
http uri: /favicon.ico
keepAlive=true
channel id=734e2ebb
http uri: /a.txt?name=chen&f=123;key=456
name=chen
f=123
key=456
keepAlive=true
channel id=734e2ebb
http uri: /favicon.ico

无论刷新多少次,服务器端日志里也只记录了一次socket连接日志,并且每次的channel id都是一样的。

顺便再测试下,如果把server中的ChannelOption.SO_KEEPALIVE设置为false,是不会影响http的keep-alive的。