Hello,

When using Nio2 connector with OpenSSL we sometimes had hanging requests
which finally ended in a timeout. This behaviour was not reproducable with
single requests (e.g. via Browser, with curl etc) but while doing some
research we were able to find a pattern and could reproduce this with some
tools/software [5]:

Pattern: first request ok, all other were hanging until timeout

Gatling Performance-Tool with activated http client sharing (which is
default) [3]
=> with using disableClientSharing we could get around it.

When using Nginx as a proxy between client and Tomcat, with activated
ssl_session_reuse [4].
=> setting proxy_ssl_session_reuse to off, no hanging requests.

When using HAProxy (we were not able to configure to make it work)

As it always works with other connector configurations (NIO/OpenSSL and
APR/OpenSSL) we assume that the problem must be in Tomcat/Nio2/OpenSSL
implementation related to ssl session reuse.
Considering the fact that nobody else in the world mentioned this problem
we also accept when we broke something in our environment, but at the
moment we don't know what we could do.
Currently it's not mission criticial for us but I'm still curious what
could be wrong.

Any hint is appreciated.

Kind regards,
Roger


[1] Versions
Tomcat         8.5.34
Tomcat Native  1.2.18
APR            1.6.3
RedHatLinux    7.5
OpenSSL        1.0.2p
Java           1.8.0_192

[2] Tomcat startup log
see attachment

[3] Reference and test example for Gatling
Documentation: https://gatling.io/docs/2.3/http/http_protocol/

  val httpProtocol = http
    .baseURL("https://tomcat:7073";)
    .inferHtmlResources()
    .acceptHeader("*/*")
    .userAgentHeader("curl/7.49.1")
    //.disableClientSharing

[4] Nginx proxy configuration
  location /nio2 {
    proxy_pass https://tomcat7073/;
    proxy_ssl_session_reuse on/off;
  }

[5] Ouptput of test programm (doing two requests with curl via nginx proxy,
e.g. curl http://nginx.loc/nio2/tomcat85/simpleServlet)

NIO: testing http://nginx.loc/nio/tomcat85/simpleServlet
1st request: https-openssl-nio-XXX.XX.XXX.X-7071-exec-7 simpleservlet
2nd request: https-openssl-nio-XXX.XX.XXX.X-7071-exec-9 simpleservlet

APR: testing http://nginx.loc/apr/tomcat85/simpleServlet
1st request: https-openssl-apr-XXX.XX.XXX.X-7075-exec-7 simpleservlet
2nd request: https-openssl-apr-XXX.XX.XXX.X-7075-exec-8 simpleservlet

NIO2: testing http://nginx.loc/nio2/tomcat85/simpleServlet
1st request: https-openssl-nio2-XXX.XX.XXX.X-7073-exec-1 simpleservlet
2nd request: 502 Bad Gateway (from nginx)
16-Jan-2019 11:01:33.445 INFO [main] 
org.apache.catalina.startup.VersionLoggerListener.log System property:       
java.runtime.name = Java(TM) SE Runtime Environment
16-Jan-2019 11:01:33.446 INFO [main] 
org.apache.catalina.startup.VersionLoggerListener.log System property:       
java.runtime.version = 1.8.0_192-b12
16-Jan-2019 11:01:33.446 INFO [main] 
org.apache.catalina.startup.VersionLoggerListener.log System property:       
java.specification.name = Java Platform API Specification
16-Jan-2019 11:01:33.446 INFO [main] 
org.apache.catalina.startup.VersionLoggerListener.log System property:       
java.specification.vendor = Oracle Corporation
16-Jan-2019 11:01:33.446 INFO [main] 
org.apache.catalina.startup.VersionLoggerListener.log System property:       
java.specification.version = 1.8
(....)
16-Jan-2019 11:01:33.453 INFO [main] 
org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based 
Apache Tomcat Native library [1.2.18] using APR version [1.6.3].
16-Jan-2019 11:01:33.453 INFO [main] 
org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: 
IPv6 [true], sendfile [true], accept filters [false], random [true].
16-Jan-2019 11:01:33.453 INFO [main] 
org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL 
configuration: useAprConnector [true], useOpenSSL [true]
16-Jan-2019 11:01:33.457 INFO [main] 
org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL 
successfully initialized [OpenSSL 1.0.2p  14 Aug 2018]
16-Jan-2019 11:01:33.697 INFO [main] org.apache.coyote.AbstractProtocol.init 
Initializing ProtocolHandler ["http-nio-XXX.XX.XXX.X-7070"]
16-Jan-2019 11:01:33.708 INFO [main] 
org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared 
selector for servlet write/read
16-Jan-2019 11:01:33.714 INFO [main] org.apache.coyote.AbstractProtocol.init 
Initializing ProtocolHandler ["https-openssl-nio-XXX.XX.XXX.X-7071"]
16-Jan-2019 11:01:33.923 INFO [main] 
org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared 
selector for servlet write/read
16-Jan-2019 11:01:33.924 INFO [main] org.apache.coyote.AbstractProtocol.init 
Initializing ProtocolHandler ["http-nio2-XXX.XX.XXX.X-7072"]
16-Jan-2019 11:01:33.938 INFO [main] 
org.apache.coyote.http11.AbstractHttp11Protocol.configureUpgradeProtocol The 
["https-openssl-nio2-XXX.XX.XXX.X-7073"] connector has been configured to 
support negotiation to [h2] via ALPN
16-Jan-2019 11:01:33.938 INFO [main] org.apache.coyote.AbstractProtocol.init 
Initializing ProtocolHandler ["https-openssl-nio2-XXX.XX.XXX.X-7073"]
16-Jan-2019 11:01:33.948 INFO [main] org.apache.coyote.AbstractProtocol.init 
Initializing ProtocolHandler ["http-apr-XXX.XX.XXX.X-7074"]
16-Jan-2019 11:01:33.954 INFO [main] 
org.apache.coyote.http11.AbstractHttp11Protocol.configureUpgradeProtocol The 
["https-openssl-apr-XXX.XX.XXX.X-7075"] connector has been configured to 
support negotiation to [h2] via ALPN
16-Jan-2019 11:01:33.954 INFO [main] org.apache.coyote.AbstractProtocol.init 
Initializing ProtocolHandler ["https-openssl-apr-XXX.XX.XXX.X-7075"]
16-Jan-2019 11:01:33.957 INFO [main] org.apache.catalina.startup.Catalina.load 
Initialization processed in 1017 ms
(...)
16-Jan-2019 11:01:34.650 INFO [main] org.apache.coyote.AbstractProtocol.start 
Starting ProtocolHandler ["http-nio-XXX.XX.XXX.X-7070"]
16-Jan-2019 11:01:34.653 INFO [main] org.apache.coyote.AbstractProtocol.start 
Starting ProtocolHandler ["https-openssl-nio-XXX.XX.XXX.X-7071"]
16-Jan-2019 11:01:34.656 INFO [main] org.apache.coyote.AbstractProtocol.start 
Starting ProtocolHandler ["http-nio2-XXX.XX.XXX.X-7072"]
16-Jan-2019 11:01:34.660 INFO [main] org.apache.coyote.AbstractProtocol.start 
Starting ProtocolHandler ["https-openssl-nio2-XXX.XX.XXX.X-7073"]
16-Jan-2019 11:01:34.666 INFO [main] org.apache.coyote.AbstractProtocol.start 
Starting ProtocolHandler ["http-apr-XXX.XX.XXX.X-7074"]
16-Jan-2019 11:01:34.671 INFO [main] org.apache.coyote.AbstractProtocol.start 
Starting ProtocolHandler ["https-openssl-apr-XXX.XX.XXX.X-7075"]
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org

Reply via email to