垂直。Netty上的x 2 HTTP服务器：响应字节已写入但从未刷新，通道从未关闭

Question

在Vert中使用HTTP服务器。x 2.1.6（基于Netty 4.0.21）为了处理HTTP请求，静态文件从文件系统读取并写入客户端。有时，在多个同时请求期间（阅读：快速单击浏览器），随机请求永远不会得到任何响应。E、 g.单击注销链接将触发对背景图像、徽标、几个css文件等的请求。所有文件都会成功返回，但徽标文件除外，http请求只是挂起了该文件。这种情况并不总是发生，但似乎是由于在启动新请求之前没有等待以前的请求完成而引发的。

为了弄清楚发生了什么，我将LoggingHandler添加到由Vert创建的netty管道中。x默认HTTPServer。下面的示例显示了成功和不成功请求文件徽标的输出。png（尺寸12754B）。输出给我留下了两个问题：

1. 在成功的例子中，写入实际文件的12754字节后，又写入了12774 10字节。那些字节是什么？
2. 在不成功的示例中，在WRITE操作之前有一个FLUSH操作，之后看不到更多的活动。甚至显式关闭响应也被忽略。这是怎么回事？

编辑关于问题1的内容：我意识到该通道用于多个HTTP请求，所以后面的字节只是另一个正在写入的文件。

请求：

GET /authenticate/res/images/logo.png HTTP/1.1
Host: 192.168.0.12:18443
Connection: keep-alive
Pragma: no-cache
Cache-Control: no-cache
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.113 Safari/537.36
Accept: image/webp,image/apng,image/*,*/*;q=0.8
Referer: https://192.168.0.12:18443/authenticate/res/css/login.css
Accept-Encoding: gzip, deflate, br
Accept-Language: en-GB,en-US;q=0.8,en;q=0.6

成功时的输出：

$ grep 0xafd76300 /var/log/server.log
2017-09-06 15:17:12,609 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] REGISTERED
2017-09-06 15:17:12,609 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] REGISTERED
2017-09-06 15:17:12,609 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] ACTIVE
2017-09-06 15:17:12,609 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] ACTIVE
2017-09-06 15:17:12,625 [SslHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
2017-09-06 15:17:12,625 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] USER_EVENT: io.netty.handler.ssl.SslHandshakeCompletionEvent@38f7a12a
2017-09-06 15:17:12,625 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] USER_EVENT: io.netty.handler.ssl.SslHandshakeCompletionEvent@38f7a12a
2017-09-06 15:17:12,629 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] RECEIVED: DefaultHttpRequest(decodeResult: success)
2017-09-06 15:17:12,633 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] RECEIVED(0B)
2017-09-06 15:17:12,634 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] WRITE(12754B)
2017-09-06 15:17:12,634 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] FLUSH
2017-09-06 15:17:12,635 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] WRITE(0B)
2017-09-06 15:17:12,635 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] WRITE(12774B)
2017-09-06 15:17:12,635 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] FLUSH
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] WRITE(0B)
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] FLUSH
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] WRITE(10B)
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] WRITE(0B)
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] FLUSH
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] CLOSE()
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 => /172.16.238.11:8443] CLOSE()
2017-09-06 15:17:12,636 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 :> /172.16.238.11:8443] INACTIVE
2017-09-06 15:17:12,637 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 :> /172.16.238.11:8443] UNREGISTERED
2017-09-06 15:17:12,637 [LoggingHandler] DEBUG: [id: 0xafd76300, /192.168.10.113:60180 :> /172.16.238.11:8443] UNREGISTERED

不成功时输出：

$ grep 0x09db306c /var/log/server.log
2017-09-06 15:17:25,569 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] REGISTERED
2017-09-06 15:17:25,569 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] REGISTERED
2017-09-06 15:17:25,569 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] ACTIVE
2017-09-06 15:17:25,569 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] ACTIVE
2017-09-06 15:17:25,571 [SslHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
2017-09-06 15:17:25,571 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] USER_EVENT: io.netty.handler.ssl.SslHandshakeCompletionEvent@38f7a12a
2017-09-06 15:17:25,572 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] USER_EVENT: io.netty.handler.ssl.SslHandshakeCompletionEvent@38f7a12a
2017-09-06 15:17:25,608 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] RECEIVED: DefaultHttpRequest(decodeResult: success)
2017-09-06 15:17:25,608 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] RECEIVED(0B)
2017-09-06 15:17:25,609 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] FLUSH
2017-09-06 15:17:25,610 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] WRITE(12754B)
2017-09-06 15:17:25,610 [LoggingHandler] DEBUG: [id: 0x09db306c, /192.168.10.113:60300 => /172.16.238.11:8443] WRITE(0B)

在HttpServer上注册的请求处理程序如下所示：

Vertx vertx = ...
HttpServerRequest req = ...
HttpServerResponse response = req.response();
vertx.fileSystem().readFile(file, (AsyncResult<Buffer> e) -> {
    try {
        if (e.succeeded()) {
            Buffer buf = e.result();
            response.putHeader("Content-Type", MimeMapper.getTypeForFile(file)+";charset=UTF-8");
            response.putHeader("Content-Length", Integer.toString(buf.length()));
            response.write(buf);
            response.end();
            response.close();
            LOG.trace("Write success (%d) %s...", buf.length(), file);
        } else {
           LOG.error("Write failure", e.cause());
        }
    } catch (Exception x) {
        LOG.error("Write failure", x);
    }
});

编辑：调用响应。close（）具有立即取消注册和停用通道的效果。如果没有该调用，注销将在最后一次写入大约5分钟后自动触发。在不成功的情况下，从不触发注销，通道将无限期保持在活动模式。

我修改了Vert中的Netty管道。x 2 DefaultHttpServer（版本2.1.6，激活ssl和压缩），方法是添加两个LoggingHandler：

ServerBootstrap bootstrap = new ServerBootstrap();
bootstrap.group(availableWorkers);
bootstrap.channel(NioServerSocketChannel.class);
tcpHelper.applyConnectionOptions(bootstrap);
tcpHelper.checkSSL(vertx);
bootstrap.childHandler(new ChannelInitializer<Channel>() {
    @Override
    protected void initChannel(Channel ch) throws Exception {
      ChannelPipeline pipeline = ch.pipeline();
      if (tcpHelper.isSSL()) {
        pipeline.addLast("ssl", tcpHelper.createSslHandler(vertx, false));
      }
      pipeline.addLast("flashpolicy", new FlashPolicyHandler());
      pipeline.addLast("httpDecoder", new HttpRequestDecoder(4096, 8192, 8192, false));
      pipeline.addLast("httpEncoder", new VertxHttpResponseEncoder());
      pipeline.addLast("reqlog", new LoggingHandler());
      if (compressionSupported) {
        pipeline.addLast("deflater", new HttpChunkContentCompressor());
      }
      if (tcpHelper.isSSL() || compressionSupported) {
        // only add ChunkedWriteHandler when SSL is enabled otherwise it is not needed as FileRegion is used.
        pipeline.addLast("chunkedWriter", new ChunkedWriteHandler());       // For large file / sendfile support
      }
      pipeline.addLast("handler", new ServerHandler());
      pipeline.addLast("rsplog", new LoggingHandler());
    }
});

Answer 1

看来我找到了错误的根源。在我看来，这是一个典型的并发问题。我通过在vertx core版本2.1.6中更改一行代码，将写入操作更改为写入刷新来修复它。修复可能绕过了原始作者的意图，并将导致在netty channel上执行一些不必要的刷新操作。

这就是我认为正在发生的事情。要理解我在代码中的推理，请看一下org。vertx。JAVA果心网实施。2.1.6中的ConnectionBase。涉及两个标志：读取和需要刷新。这里我假设有两个线程同时访问通道。

1. 垂直。HttpServer接收http请求，打开Netty通道并成功读取整个请求。处理程序在读取时处于读取模式，然后返回写入模式，刷新写入缓冲区：READ=false，needsFlush=false

为了解决此问题，我更新了

org.vertx.java.core.http.impl.VertxHttpHandler.write(ChannelHandlerContext ctx, Object msg, ChannelPromise promise)

执行ctx。writeAndFlush（msg，promise）而不仅仅是ctx。写（消息，promise）。

可能我忽略了一些东西，它可以在不修补vertx2的情况下解决问题。也许可以配置vertx2为每个超文本传输协议请求创建一个新的netty通道，而不是为多个请求重复使用相同的通道？如果有人能提出这样的替代解决方案，我很乐意接受。

编辑：也许我应该补充一点，我在重新编译Vertx2时将Netty升级到了4.0.51。不过，这两个版本的问题都是一样的，升级后可能会更糟。