[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-24 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

Remy Maucherat  changed:

   What|Removed |Added

 Resolution|--- |FIXED
 Status|NEW |RESOLVED

--- Comment #8 from Remy Maucherat  ---
The fix will be in 9.0.27 and 8.5.47.

-- 
You are receiving this mail because:
You are the assignee for the bug.
-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-24 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

--- Comment #7 from Remy Maucherat  ---
(In reply to Rainer Jung from comment #6)
> Can't say whether it is safe though.

It likely sounds safe to unwrap first (it would do an underflow and cause a
read) reading some previous comment:
https://github.com/apache/tomcat/commit/3f3dfc63e12e816d68f1a2e21e80d77513e2a2d4

At least I am not getting any test issues so it's worth trying ...

-- 
You are receiving this mail because:
You are the assignee for the bug.
-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-24 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

--- Comment #6 from Rainer Jung  ---
(In reply to Remy Maucherat from comment #1)
> This looked like the usual not-unwrapping-enough "IO" issue, so changing the
> initial value of unwrapBeforeRead to true in SecureNio2Channel.reset avoids
> it. Not sure if it is 100% safe (although it looks rather similar to NIO
> with its non blocking read returning 0).
> I cannot reproduce this that reliably personally, it may be only visible on
> localhost.

At least it fixes the problem for me:

diff --git a/java/org/apache/tomcat/util/net/SecureNio2Channel.java
b/java/org/apache/tomcat/util/net/SecureNio2Channel.java
index 9e5ab07ea0..da899b26aa 100644
--- a/java/org/apache/tomcat/util/net/SecureNio2Channel.java
+++ b/java/org/apache/tomcat/util/net/SecureNio2Channel.java
@@ -132,6 +132,7 @@ public class SecureNio2Channel extends Nio2Channel  {
 handshakeComplete = false;
 closed = false;
 closing = false;
+unwrapBeforeRead = true;
 netInBuffer.clear();
 }

Can't say whether it is safe though.

-- 
You are receiving this mail because:
You are the assignee for the bug.
-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-24 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

--- Comment #5 from Rainer Jung  ---
And here Nio2 using TLS 1.2:

...
24-Sep-2019 15:16:55.232 FINE [https-openssl-nio2-8443-exec-4]
org.apache.tomcat.util.net.SocketWrapperBase.populateReadBuffer Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@281c779a:org.apache.tomcat.util.net.SecureNio2Channel@1f564c66:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:19684]], Read from buffer:
[0]

but now

24-Sep-2019 15:16:55.236 FINE [https-openssl-nio2-8443-exec-4]
org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper$2.completed Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@281c779a:org.apache.tomcat.util.net.SecureNio2Channel@1f564c66:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:19684]], Interest: [false]
24-Sep-2019 15:16:55.237 FINE [https-openssl-nio2-8443-exec-4]
org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper.read Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@281c779a:org.apache.tomcat.util.net.SecureNio2Channel@1f564c66:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:19684]], Read into buffer:
[78]
24-Sep-2019 15:16:55.237 FINE [https-openssl-nio2-8443-exec-4]
org.apache.tomcat.util.net.SocketWrapperBase.populateReadBuffer Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@281c779a:org.apache.tomcat.util.net.SecureNio2Channel@1f564c66:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:19684]], Read from buffer:
[78]

-- 
You are receiving this mail because:
You are the assignee for the bug.
-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-24 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

--- Comment #4 from Rainer Jung  ---
For comparison the Nio (not NIO2) log snippet where the request works:

24-Sep-2019 13:54:40.068 FINE [https-openssl-nio-8443-Acceptor]
org.apache.tomcat.util.threads.LimitLatch.countUpOrAwait Counting
up[https-openssl-nio-8443-Acceptor] latch=1
24-Sep-2019 13:54:40.076 FINE [https-openssl-nio-8443-exec-1]
org.apache.tomcat.util.net.SecureNioChannel.processSNI The SNI host name
extracted for connection [java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]] was [localhost]
24-Sep-2019 13:54:40.094 FINE [https-openssl-nio-8443-exec-3]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Processing socket
[org.apache.tomcat.util.net.SecureNioChannel@39172781:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]] with status
[OPEN_READ]
24-Sep-2019 13:54:40.095 FINE [https-openssl-nio-8443-exec-3]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Found processor
[null] for socket
[org.apache.tomcat.util.net.SecureNioChannel@39172781:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]]
24-Sep-2019 13:54:40.095 FINE [https-openssl-nio-8443-exec-3]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Popped processor
[null] from cache
24-Sep-2019 13:54:40.132 FINE [https-openssl-nio-8443-exec-3]
org.apache.coyote.AbstractProtocol$ConnectionHandler.register Register
Catalina:type=RequestProcessor,worker="https-openssl-nio-8443",name=HttpRequest1
24-Sep-2019 13:54:40.135 FINE [https-openssl-nio-8443-exec-3]
org.apache.tomcat.util.net.SocketWrapperBase.populateReadBuffer Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@6c99b5c8:org.apache.tomcat.util.net.SecureNioChannel@39172781:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]], Read from buffer:
[0]

Looks the same until here, but now Nio does:

24-Sep-2019 13:54:40.136 FINE [https-openssl-nio-8443-exec-3]
org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.read Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@6c99b5c8:org.apache.tomcat.util.net.SecureNioChannel@39172781:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]], Read direct from
socket: [78]
24-Sep-2019 13:54:40.136 FINE [https-openssl-nio-8443-exec-3]
org.apache.coyote.http11.Http11InputBuffer.parseRequestLine Received [GET /
HTTP/1.1
Host: localhost:8443
User-Agent: curl/7.66.0
Accept: */*

]
24-Sep-2019 13:54:40.161 FINE [https-openssl-nio-8443-exec-3]
org.apache.tomcat.util.http.Parameters.setQueryStringCharset Set query string
encoding to UTF-8
24-Sep-2019 13:54:40.375 FINE [https-openssl-nio-8443-exec-3]
org.apache.tomcat.util.net.SocketWrapperBase.populateReadBuffer Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@6c99b5c8:org.apache.tomcat.util.net.SecureNioChannel@39172781:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]], Read from buffer:
[0]
24-Sep-2019 13:54:40.376 FINE [https-openssl-nio-8443-exec-3]
org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.read Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@6c99b5c8:org.apache.tomcat.util.net.SecureNioChannel@39172781:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]], Read direct from
socket: [0]
24-Sep-2019 13:54:40.377 FINE [https-openssl-nio-8443-exec-3]
org.apache.coyote.AbstractProcessorLight.process Socket:
[org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@6c99b5c8:org.apache.tomcat.util.net.SecureNioChannel@39172781:java.nio.channels.SocketChannel[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:51197]], Status in:
[OPEN_READ], State out: [OPEN]

...

-- 
You are receiving this mail because:
You are the assignee for the bug.
-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-24 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

--- Comment #3 from Rainer Jung  ---
I can also reproduce on SLES 12 and RHEL 7 but not on Solaris.

For me it does not happen with a real remote connection, but always with local
ones and with connections from another virtual guest on the same host system,
so specifics of the IP stack might be relevant.

I am using tcnative 1.2.23 build against APR 1.7.0 and OpenSSL 1.1.1d.

My curl is 7.66.0 also build against OpenSSL 1.1.1d.

Java is 1.8.0, also observable with Java 11.

TC is TC9 git 6a173978c5865421192578da21ec8f418e5a3da4 (2019-09-19).

Some debug log lines:

End of startup:

24-Sep-2019 13:48:29.200 INFO [main] org.apache.catalina.startup.Catalina.start
Server startup in [2,003] milliseconds

Start of request:

24-Sep-2019 13:49:09.410 FINE [https-openssl-nio2-8443-exec-3]
org.apache.tomcat.util.threads.LimitLatch.countUpOrAwait Counting
up[https-openssl-nio2-8443-exec-3] latch=1
24-Sep-2019 13:49:09.436 FINE [https-openssl-nio2-8443-exec-2]
org.apache.tomcat.util.net.SecureNio2Channel.processSNI The SNI host name
extracted for connection
[sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]] was [localhost]
24-Sep-2019 13:49:09.457 FINE [https-openssl-nio2-8443-exec-4]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Processing socket
[org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]] with status
[OPEN_READ]
24-Sep-2019 13:49:09.457 FINE [https-openssl-nio2-8443-exec-4]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Found processor
[null] for socket
[org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]]
24-Sep-2019 13:49:09.458 FINE [https-openssl-nio2-8443-exec-4]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Popped processor
[null] from cache
24-Sep-2019 13:49:09.493 FINE [https-openssl-nio2-8443-exec-4]
org.apache.coyote.AbstractProtocol$ConnectionHandler.register Register
Catalina:type=RequestProcessor,worker="https-openssl-nio2-8443",name=HttpRequest1
24-Sep-2019 13:49:09.497 FINE [https-openssl-nio2-8443-exec-4]
org.apache.tomcat.util.net.SocketWrapperBase.populateReadBuffer Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@4ed079d9:org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]], Read from buffer:
[0]
24-Sep-2019 13:49:09.499 FINE [https-openssl-nio2-8443-exec-4]
org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper.read Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@4ed079d9:org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]], Read into buffer:
[0]
24-Sep-2019 13:49:09.499 FINE [https-openssl-nio2-8443-exec-4]
org.apache.coyote.AbstractProcessorLight.process Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@4ed079d9:org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]], Status in:
[OPEN_READ], State out: [OPEN]
24-Sep-2019 13:49:09.500 FINE [https-openssl-nio2-8443-exec-4]
org.apache.coyote.AbstractProtocol$ConnectionHandler.release Pushed Processor
[org.apache.coyote.http11.Http11Processor@20d73a43]

then the hang occurs. After a minute, curl gets "empty reply from server" and
the logs show:

24-Sep-2019 13:50:09.501 FINE [https-openssl-nio2-8443-exec-6]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Processing socket
[org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]] with status [ERROR]
24-Sep-2019 13:50:09.502 FINE [https-openssl-nio2-8443-exec-6]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Found processor
[null] for socket
[org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]]
24-Sep-2019 13:50:09.502 FINE [https-openssl-nio2-8443-exec-6]
org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper.doClose Calling
[org.apache.tomcat.util.net.Nio2Endpoint@6d79b7f7].closeSocket([org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@4ed079d9:org.apache.tomcat.util.net.SecureNio2Channel@76110ba6:sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/0:0:0:0:0:0:0:1:8443 remote=/0:0:0:0:0:0:0:1:50367]])
java.lang.Exception
at
org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper.doClose(Nio2Endpoint.java:915)
 

[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-24 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

--- Comment #2 from Coty Sutherland  ---
> I cannot reproduce this that reliably personally, it may be only visible on 
> localhost.

Weird. I can reproduce this between two machines as well, so it doesn't seem to
be a lo only issue.

-- 
You are receiving this mail because:
You are the assignee for the bug.
-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org



[Bug 63765] NIO2 Connector with OpenSSL 1.1.1 hangs with TLSv1.3

2019-09-23 Thread bugzilla
https://bz.apache.org/bugzilla/show_bug.cgi?id=63765

--- Comment #1 from Remy Maucherat  ---
This looked like the usual not-unwrapping-enough "IO" issue, so changing the
initial value of unwrapBeforeRead to true in SecureNio2Channel.reset avoids it.
Not sure if it is 100% safe (although it looks rather similar to NIO with its
non blocking read returning 0).
I cannot reproduce this that reliably personally, it may be only visible on
localhost.

-- 
You are receiving this mail because:
You are the assignee for the bug.
-
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org