Channel closed on bootstrapping

[flore77]

Hello, we have been running in a problem while using Vertx's HttpClient which uses Netty. Our application makes requests to a few hosts, and it slowly started to throw javax.net.ssl.SSLHandshakeException:

The above problem was happening for a single host, and only a part of the requests sent against the affected host suffered from this problem.

We think that the part where only a portion of traffic was impacted can be explained as successful requests were reusing existing connections and the failing requests were the ones which were opening new ones. But we do not have an explanation for the part where only this host was affected, as we had multiple instances running our application and this behaviour was happening only on a single one of them.

The problem was resolved by a simple restart of the instance which was manifesting the problem.

After some digging, we observed that the SSLHandshakeException is thrown by Vertx, but in response to an error thrown by Netty java.nio.channels.ClosedChannelException:

netty/handler/src/main/java/io/netty/handler/ssl/SslHandler.java

Line 1064 in d6f029c

ClosedChannelException exception = new ClosedChannelException();

which is thrown from the channelInactive method in the SSLHandler.

Our question is how can a channel be closed when it is just bootstraping? We would like to understand in which conditions this can happen, so that we can investigate further / fix the problem. (I posted also the complete stacktrace at the end) Thanks!

Netty version

Netty: 4.1.67.Final
Vertx: 4.1.3

JVM version (e.g. java -version)

openjdk version "11.0.9.1" 2020-11-04 LTS
OpenJDK Runtime Environment Zulu11.43+56-SA (build 11.0.9.1+1-LTS)
OpenJDK 64-Bit Server VM Zulu11.43+56-SA (build 11.0.9.1+1-LTS, mixed mode)

OS version (e.g. uname -a)

Linux 5.4.92-flatcar x86_64 Linux (Docker image)

Stacktrace

  "message": {
    "thrown": {
      "commonElementCount": 0,
      "cause": {
        "commonElementCount": 0,
        "localizedMessage": "Failed to create SSL connection",
        "message": "Failed to create SSL connection",
        "name": "javax.net.ssl.SSLHandshakeException",
        "cause": {
          "commonElementCount": 0,
          "name": "java.nio.channels.ClosedChannelException",
          "extendedStackTrace": [
            {
              "class": "io.netty.handler.ssl.SslHandler",
              "method": "channelInactive",
              "file": "SslHandler.java",
              "line": 1065,
              "exact": false,
              "location": "netty-handler-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.AbstractChannelHandlerContext",
              "method": "invokeChannelInactive",
              "file": "AbstractChannelHandlerContext.java",
              "line": 262,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.AbstractChannelHandlerContext",
              "method": "invokeChannelInactive",
              "file": "AbstractChannelHandlerContext.java",
              "line": 248,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.AbstractChannelHandlerContext",
              "method": "fireChannelInactive",
              "file": "AbstractChannelHandlerContext.java",
              "line": 241,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.DefaultChannelPipeline$HeadContext",
              "method": "channelInactive",
              "file": "DefaultChannelPipeline.java",
              "line": 1405,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.AbstractChannelHandlerContext",
              "method": "invokeChannelInactive",
              "file": "AbstractChannelHandlerContext.java",
              "line": 262,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.AbstractChannelHandlerContext",
              "method": "invokeChannelInactive",
              "file": "AbstractChannelHandlerContext.java",
              "line": 248,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.DefaultChannelPipeline",
              "method": "fireChannelInactive",
              "file": "DefaultChannelPipeline.java",
              "line": 901,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.AbstractChannel$AbstractUnsafe$8",
              "method": "run",
              "file": "AbstractChannel.java",
              "line": 831,
              "exact": false,
              "location": "netty-transport-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.util.concurrent.AbstractEventExecutor",
              "method": "safeExecute",
              "file": "AbstractEventExecutor.java",
              "line": 164,
              "exact": false,
              "location": "netty-common-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.util.concurrent.SingleThreadEventExecutor",
              "method": "runAllTasks",
              "file": "SingleThreadEventExecutor.java",
              "line": 469,
              "exact": false,
              "location": "netty-common-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.channel.epoll.EpollEventLoop",
              "method": "run",
              "file": "EpollEventLoop.java",
              "line": 384,
              "exact": false,
              "location": "netty-transport-native-epoll-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.util.concurrent.SingleThreadEventExecutor$4",
              "method": "run",
              "file": "SingleThreadEventExecutor.java",
              "line": 986,
              "exact": false,
              "location": "netty-common-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.util.internal.ThreadExecutorMap$2",
              "method": "run",
              "file": "ThreadExecutorMap.java",
              "line": 74,
              "exact": false,
              "location": "netty-common-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "io.netty.util.concurrent.FastThreadLocalRunnable",
              "method": "run",
              "file": "FastThreadLocalRunnable.java",
              "line": 30,
              "exact": false,
              "location": "netty-common-4.1.67.Final.jar",
              "version": "4.1.67.Final"
            },
            {
              "class": "java.lang.Thread",
              "method": "run",
              "line": -1,
              "exact": false,
              "location": "?",
              "version": "?"
            }
          ]
        },
        "extendedStackTrace": [
          {
            "class": "io.vertx.core.net.impl.ChannelProvider$1",
            "method": "userEventTriggered",
            "file": "ChannelProvider.java",
            "line": 129,
            "exact": false,
            "location": "vertx-core-4.1.3.jar",
            "version": "4.1.3"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "invokeUserEventTriggered",
            "file": "AbstractChannelHandlerContext.java",
            "line": 346,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "invokeUserEventTriggered",
            "file": "AbstractChannelHandlerContext.java",
            "line": 332,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "fireUserEventTriggered",
            "file": "AbstractChannelHandlerContext.java",
            "line": 324,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.handler.ssl.SslUtils",
            "method": "handleHandshakeFailure",
            "file": "SslUtils.java",
            "line": 438,
            "exact": false,
            "location": "netty-handler-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.handler.ssl.SslHandler",
            "method": "setHandshakeFailure",
            "file": "SslHandler.java",
            "line": 1882,
            "exact": false,
            "location": "netty-handler-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.handler.ssl.SslHandler",
            "method": "channelInactive",
            "file": "SslHandler.java",
            "line": 1068,
            "exact": false,
            "location": "netty-handler-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "invokeChannelInactive",
            "file": "AbstractChannelHandlerContext.java",
            "line": 262,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "invokeChannelInactive",
            "file": "AbstractChannelHandlerContext.java",
            "line": 248,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "fireChannelInactive",
            "file": "AbstractChannelHandlerContext.java",
            "line": 241,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.DefaultChannelPipeline$HeadContext",
            "method": "channelInactive",
            "file": "DefaultChannelPipeline.java",
            "line": 1405,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "invokeChannelInactive",
            "file": "AbstractChannelHandlerContext.java",
            "line": 262,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannelHandlerContext",
            "method": "invokeChannelInactive",
            "file": "AbstractChannelHandlerContext.java",
            "line": 248,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.DefaultChannelPipeline",
            "method": "fireChannelInactive",
            "file": "DefaultChannelPipeline.java",
            "line": 901,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.AbstractChannel$AbstractUnsafe$8",
            "method": "run",
            "file": "AbstractChannel.java",
            "line": 831,
            "exact": false,
            "location": "netty-transport-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.util.concurrent.AbstractEventExecutor",
            "method": "safeExecute",
            "file": "AbstractEventExecutor.java",
            "line": 164,
            "exact": false,
            "location": "netty-common-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.util.concurrent.SingleThreadEventExecutor",
            "method": "runAllTasks",
            "file": "SingleThreadEventExecutor.java",
            "line": 469,
            "exact": false,
            "location": "netty-common-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.channel.epoll.EpollEventLoop",
            "method": "run",
            "file": "EpollEventLoop.java",
            "line": 384,
            "exact": false,
            "location": "netty-transport-native-epoll-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.util.concurrent.SingleThreadEventExecutor$4",
            "method": "run",
            "file": "SingleThreadEventExecutor.java",
            "line": 986,
            "exact": false,
            "location": "netty-common-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.util.internal.ThreadExecutorMap$2",
            "method": "run",
            "file": "ThreadExecutorMap.java",
            "line": 74,
            "exact": false,
            "location": "netty-common-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "io.netty.util.concurrent.FastThreadLocalRunnable",
            "method": "run",
            "file": "FastThreadLocalRunnable.java",
            "line": 30,
            "exact": false,
            "location": "netty-common-4.1.67.Final.jar",
            "version": "4.1.67.Final"
          },
          {
            "class": "java.lang.Thread",
            "method": "run",
            "line": -1,
            "exact": true,
            "location": "?",
            "version": "?"
          }
        ]
      }
    }
  }
}```

[NiteshKant]

Our question is how can a channel be closed when it is just bootstraping?

Not sure what you are referring to as "bootstraping" here, but connection closure during TLS handshake is totally expected. Some peers may close connection if the TLS packets are malformed as an example.