Another update:
- APR connector works well
- It looks like it has to do with readFromSSL() after the handshake
returning 0 bytes.
I remember having added some native code to mod_ssl for OpenSSL 1.1.1,
which handles new behavior in OpenSSL SSL_read(). It can now return 0
and set the ssl error to SSL_ERROR_WANT_READ, expecting the application
to call the SSL_read() again. That's documented in OpenSSL docs since a
long time, but was not happenng before 1.1.1 and was not handled in the
original mod_ssl code. Our tcnative code used from the APR connector
handles that case (I think in sslnetwork.c).
The Nio(2) connectors plus OpenSSL code (ssl.c) partially handle it in
OpenSSLEngine.java, but I suspect it's incomplete.
Another maybe realted observation: when testing with OpenSSL s_client
(any version) and TLS 1.0, it looks like I have to add an additional
trailing empty line after the request, to get the response back. When I
only send a normal request it hangs, but as soon as I add the empty line
(eg. after a few seconds), I get back the response.
I suspect OpenSSL has already read the request from the socket, but
SSL_read() does not immediatley return it, instead just sets
SSL_ERROR_WANT_READ. Since the request was read, polling the socket does
not fire any event so we hang. When I send another empty line, an event
gets fired and the request data gets read from the OpenSSL buffer.
I'll debug more in OpenSSLEngine.
Regards,
Rainer
Am 23.11.2018 um 20:37 schrieb Rainer Jung:
One correction: using openssl s_client correctly does not hang.
Only curl build with OpenSSL hangs. I tried my old curl builds and it
seems it starts to hang with curl 7.24.0. Version 7.23.1 does not hang.
The OpenSSL lib version on the client side does not seem to matter.
I'll do some more debugging (eg. check whether APR also hangs or only
NIO+native) but eventually this might end up being a curl bug.
Regards,
Rainer
Am 23.11.2018 um 17:19 schrieb Rainer Jung:
Short addition: When using Apache httpd 2.4.37 build with OpenSSL
1.1.1a, there are no hangs with TLS 1.0. So it seems we have a
relevant difference in our server-side use of the OpenSSL API. Easy to
reproduce, but not easy to debug ...
Regards,
Rainer
Am 23.11.2018 um 15:50 schrieb Rainer Jung:
Am 23.11.2018 um 14:54 schrieb Mark Thomas:
Hi all,
Given bugs 62662 and 62944, I plan to tag 1.2.19 early next week
with a
view to including 1.2.19 in the next round of Tomcat releases.
I observed a problem with TLS 1.0 under the following conditions:
- using 9.0.13 with NIO plus tcnative 1.2 head build against OpenSSL
1.1.1a
- in combination with clients that also are based on OpenSSL (but
even for older OpenSSL version like 1.0.2) and try to use TLS 1.0.
The handshake works, but then the request times out after a minute.
Observed for curl and "openssl s_client".
From the server Logs:
2018-11-23 14:48:47,494 42891 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.tomcat.util.modeler.modules.MbeansDescriptorsIntrospectionSource
(MbeansDescriptorsIntrospectionSource.java:326) - Introspected
attribute currentUri public java.lang.String
org.apache.coyote.RequestInfo.getCurrentUri() null
2018-11-23 14:48:47,494 42891 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.tomcat.util.modeler.modules.MbeansDescriptorsIntrospectionSource
(MbeansDescriptorsIntrospectionSource.java:326) - Introspected
attribute lastRequestProcessingTime public long
org.apache.coyote.RequestInfo.getLastRequestProcessingTime() public
void org.apache.coyote.RequestInfo.setLastRequestProcessingTime(long)
2018-11-23 14:48:47,494 42891 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.tomcat.util.modeler.modules.MbeansDescriptorsIntrospectionSource
(MbeansDescriptorsIntrospectionSource.java:326) - Introspected
attribute errorCount public int
org.apache.coyote.RequestInfo.getErrorCount() public void
org.apache.coyote.RequestInfo.setErrorCount(int)
2018-11-23 14:48:47,494 42891 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.tomcat.util.modeler.modules.MbeansDescriptorsIntrospectionSource
(MbeansDescriptorsIntrospectionSource.java:359) - Setting name:
org.apache.coyote.RequestInfo
2018-11-23 14:48:47,495 42892 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.tomcat.util.modeler.BaseModelMBean
(BaseModelMBean.java:887) - preRegister
org.apache.coyote.RequestInfo@5750c763
Catalina:type=RequestProcessor,worker="https-openssl-nio-8143",name=HttpRequest1
2018-11-23 14:48:47,496 42893 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.tomcat.util.net.SocketWrapperBase
(SocketWrapperBase.java:333) - Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@5761c8c:org.apache.tomcat.util.net.SecureNioChannel@87dd2cc:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8143 remote=/0:0:0:0:0:0:0:1:42343]], Read
from buffer: [0]
2018-11-23 14:48:47,497 42894 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.tomcat.util.net.NioEndpoint (NioEndpoint.java:1144) -
Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@5761c8c:org.apache.tomcat.util.net.SecureNioChannel@87dd2cc:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8143 remote=/0:0:0:0:0:0:0:1:42343]], Read
direct from socket: [0]
2018-11-23 14:48:47,498 42895 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.coyote.http11.Http11Processor
(AbstractProcessorLight.java:74) - Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@5761c8c:org.apache.tomcat.util.net.SecureNioChannel@87dd2cc:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8143 remote=/0:0:0:0:0:0:0:1:42343]], Status
in: [OPEN_READ], State out: [OPEN]
2018-11-23 14:48:47,498 42895 DEBUG [https-openssl-nio-8143-exec-2]
org.apache.coyote.http11.Http11NioProtocol
(AbstractProtocol.java:981) - Pushed Processor
[org.apache.coyote.http11.Http11Processor@54ccb89e]
... hang ...
2018-11-23 14:49:47,579 102976 DEBUG [https-openssl-nio-8143-exec-3]
org.apache.coyote.http11.Http11NioProtocol
(AbstractProtocol.java:697) - Processing socket
[org.apache.tomcat.util.net.SecureNioChannel@87dd2cc:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8143 remote=/0:0:0:0:0:0:0:1:42343]] with
status [ERROR]
2018-11-23 14:49:47,579 102976 DEBUG [https-openssl-nio-8143-exec-3]
org.apache.coyote.http11.Http11NioProtocol
(AbstractProtocol.java:709) - Found processor [null] for socket
[org.apache.tomcat.util.net.SecureNioChannel@87dd2cc:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8143 remote=/0:0:0:0:0:0:0:1:42343]]
2018-11-23 14:49:47,581 102978 DEBUG [https-openssl-nio-8143-exec-3]
org.apache.tomcat.util.threads.LimitLatch (LimitLatch.java:128) -
Counting down[https-openssl-nio-8143-exec-3] latch=1
2018-11-23 14:49:47,581 102978 DEBUG [https-openssl-nio-8143-exec-3]
org.apache.tomcat.util.net.NioEndpoint (NioEndpoint.java:475) -
Socket:
[org.apache.tomcat.util.net.SecureNioChannel@87dd2cc:java.nio.channels.SocketChannel[closed]]
closed
The client shows the handshake t finish, but then the actual
request/response exchange hangs.
The problem does not occur when using platform curl on RHEL (based on
NSS instead of OpenSSL) and also not when using a Java 8 client. It
also does not occur, when building tcnative against OpenSSL 1.0.2q.
The problem happens independent of whether I only allow "TLSv1" as
protocols in SSLHostConfig or try with the default "all".
I will try to check against an OpenSSL 1.1.1a based Apache web server
to see, whether the hangs happen there too. If not, we might be able
to compare code.
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
