This looks really weird, and would usually only happen if a HTTP/2
channel was forcibly closed while in the middle of writing a response
(that said we could potentially handle this better, depending on what
is causing the channel to be closed).
What is your handler doing? If it is forcibly closing the channel it
could account for why it works with HTTP/1 and not HTTP/2, as the
flush()/close() behavior is slightly different between them (the
channel contract is the same, but HTTP/1 is more likely to work if you
don't stick to the contract).
Stuart
On Tue, Dec 13, 2016 at 7:25 AM, Hicks, Matt <matt(a)matthicks.com> wrote:
Yes, the same code works in HTTP, but if you look at the trace it
looks as
though it's never even getting to my code. I'm getting ERR_CONNECTION_RESET
in the browser when I load the page with GET params but the page itself is
loading. Something really bizarre is happening here and the referenced
resources aren't coming through properly. The same exact resources though
come through fine if I manually load them or if I do it from a URL without
any query args. I'm still digging into this, but it seems directly related
to SSL.
Stuart, can you make any sense of this?
On Mon, Dec 12, 2016 at 1:24 PM Bill O'Neil <bill(a)dartalley.com> wrote:
>
> Does the same code work in HTTP? can you post a snippet of where you read
> the query parameters?
>
> On Mon, Dec 12, 2016 at 1:13 PM, Hicks, Matt <matt(a)matthicks.com> wrote:
>>
>> Sorry guys, I need to resurrect this thread.
>>
>> SSL is working for the most part, but it seems when I try to load any URL
>> that has GET args it starts throwing:
>>
>> siteJVM[ERROR] Dec 12, 2016 12:10:41 PM org.xnio.ChannelListeners
>> invokeChannelListener
>> siteJVM[ERROR] ERROR: XNIO001007: A channel event listener threw an
>> exception
>> siteJVM[ERROR] java.lang.IllegalStateException
>> siteJVM[ERROR] at
>>
io.undertow.server.protocol.framed.AbstractFramedStreamSinkChannel.getBuffer(AbstractFramedStreamSinkChannel.java:578)
>> siteJVM[ERROR] at
>>
io.undertow.server.protocol.framed.AbstractFramedChannel.flushSenders(AbstractFramedChannel.java:630)
>> siteJVM[ERROR] at
>>
io.undertow.server.protocol.framed.AbstractFramedChannel$FrameWriteListener.handleEvent(AbstractFramedChannel.java:943)
>> siteJVM[ERROR] at
>>
io.undertow.server.protocol.framed.AbstractFramedChannel$FrameWriteListener.handleEvent(AbstractFramedChannel.java:940)
>> siteJVM[ERROR] at
>> org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
>> siteJVM[ERROR] at
>>
org.xnio.conduits.WriteReadyHandler$ChannelListenerHandler.writeReady(WriteReadyHandler.java:65)
>> siteJVM[ERROR] at
>>
io.undertow.protocols.ssl.SslConduit$SslWriteReadyHandler.writeReady(SslConduit.java:1224)
>> siteJVM[ERROR] at
>> io.undertow.protocols.ssl.SslConduit$3.run(SslConduit.java:275)
>> siteJVM[ERROR] at
>> org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:580)
>> siteJVM[ERROR] at org.xnio.nio.WorkerThread.run(WorkerThread.java:464)
>>
>> All over the place. It also throws XNIO000011 sometimes as well. If I
>> load the exact same URL with no GET args it seems to load just fine. Any
>> idea why this might be happening?
>>
>> On Mon, Dec 12, 2016 at 11:01 AM Hicks, Matt <matt(a)matthicks.com> wrote:
>>>
>>> Stuart, I apologize for not figuring that out myself, but that was the
>>> problem. It's working correctly now.
>>>
>>> Ideally Undertow should be able to detect this internally and throw an
>>> error instead of just silently failing. I understand that this relies on
>>> the SSLContext which is not part of Undertow's code, but it seems like
if
>>> there is any way to detect this scenario it would be a major convenience to
>>> avoid such pitfalls for other developers in the future.
>>>
>>> Thanks everyone for your help with this. I greatly appreciate it.
>>>
>>> On Sun, Dec 11, 2016 at 6:48 PM Stuart Douglas <sdouglas(a)redhat.com>
>>> wrote:
>>>>
>>>> I have modified the example so it will now blow up if the keystore
>>>> cannot be loaded:
>>>>
>>>>
https://github.com/undertow-io/undertow/commit/d142748f138bb7416b8f5ff003...
>>>>
>>>> Stuart
>>>>
>>>> On Sun, Dec 11, 2016 at 10:44 AM, Stuart Douglas
<sdouglas(a)redhat.com>
>>>> wrote:
>>>>>
>>>>> I also failed to run the example, until I realized that the code
does
>>>>> not validate that the keystore is loaded correctly (passing
'null' into
>>>>> KeyStore.load apparently works without error).
>>>>>
>>>>> Are you sure you are actually loading the keystore correctly (maybe
>>>>> add a null check into the loading code)?
>>>>>
>>>>> Stuart
>>>>>
>>>>> On Sun, Dec 11, 2016 at 3:05 AM, Bill O'Neil
<bill(a)dartalley.com>
>>>>> wrote:
>>>>>>
>>>>>> Here is the trace occurs with Http2 true and false. Issue seems
to be
>>>>>> javax.net.ssl.SSLException: Inbound closed before receiving
peer's
>>>>>> close_notify: possible truncation attack?
>>>>>>
>>>>>>
>>>>>> 2016-12-10 11:03:03.669 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.670 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected key sun.nio.ch.SelectionKeyImpl@611889f4 for
>>>>>> sun.nio.ch.ServerSocketChannelImpl[/127.0.0.1:8443]
>>>>>> 2016-12-10 11:03:03.670 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@5c0faa95
>>>>>> 2016-12-10 11:03:03.670 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.670 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task org.xnio.nio.QueuedNioTcpServer$1@52c85f64
>>>>>> 2016-12-10 11:03:03.670 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.671 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener Delegating channel listener -> Accepting
listener for
>>>>>> io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5 on
channel TCP
>>>>>> server (NIO) <13f5555f>
>>>>>> 2016-12-10 11:03:03.671 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected key sun.nio.ch.SelectionKeyImpl@611889f4 for
>>>>>> sun.nio.ch.ServerSocketChannelImpl[/127.0.0.1:8443]
>>>>>> 2016-12-10 11:03:03.671 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener Accepting listener for
>>>>>> io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5 on
channel
>>>>>> io.undertow.protocols.ssl.UndertowAcceptingSslChannel@328f1eb6
>>>>>> 2016-12-10 11:03:03.671 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.674 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener
io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5
>>>>>> on channel
io.undertow.protocols.ssl.UndertowSslConnection@53f69e92
>>>>>> 2016-12-10 11:03:03.675 [XNIO-1 I/O-2] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@49c6180b
>>>>>> 2016-12-10 11:03:03.675 [XNIO-1 I/O-4] TRACE io.undertow.request
-
>>>>>> Opened connection with /127.0.0.1:56854
>>>>>> 2016-12-10 11:03:03.676 [XNIO-1 I/O-2] TRACE org.xnio.nio -
Running
>>>>>> task org.xnio.nio.QueuedNioTcpServer$1@52c85f64
>>>>>> 2016-12-10 11:03:03.681 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@5c0faa95 (with
timeout)
>>>>>> 2016-12-10 11:03:03.681 [XNIO-1 I/O-2] TRACE org.xnio.listener -
>>>>>> Invoking listener Delegating channel listener -> Accepting
listener for
>>>>>> io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5 on
channel TCP
>>>>>> server (NIO) <13f5555f>
>>>>>> 2016-12-10 11:03:03.683 [XNIO-1 I/O-2] TRACE org.xnio.listener -
>>>>>> Invoking listener Accepting listener for
>>>>>> io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5 on
channel
>>>>>> io.undertow.protocols.ssl.UndertowAcceptingSslChannel@328f1eb6
>>>>>> 2016-12-10 11:03:03.685 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@5c0faa95
>>>>>> 2016-12-10 11:03:03.688 [XNIO-1 I/O-2] TRACE org.xnio.listener -
>>>>>> Invoking listener
io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5
>>>>>> on channel
io.undertow.protocols.ssl.UndertowSslConnection@3ac7f450
>>>>>> 2016-12-10 11:03:03.688 [XNIO-1 I/O-2] TRACE io.undertow.request
-
>>>>>> Opened connection with /127.0.0.1:56856
>>>>>> 2016-12-10 11:03:03.690 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Selected key sun.nio.ch.SelectionKeyImpl@673b2384 for
>>>>>> java.nio.channels.SocketChannel[connected local=/127.0.0.1:8443
>>>>>> remote=/127.0.0.1:56854]
>>>>>> 2016-12-10 11:03:03.691 [XNIO-1 I/O-2] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@49c6180b (with
timeout)
>>>>>> 2016-12-10 11:03:03.692 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener
io.undertow.server.protocol.http.HttpReadListener@255c6481
>>>>>> on channel org.xnio.conduits.ConduitStreamSourceChannel@1b4554ad
>>>>>> 2016-12-10 11:03:03.692 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@5c0faa95 (with
timeout)
>>>>>> 2016-12-10 11:03:03.696 [XNIO-1 I/O-2] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@49c6180b
>>>>>> 2016-12-10 11:03:03.696 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@5c0faa95
>>>>>> 2016-12-10 11:03:03.696 [XNIO-1 I/O-2] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$5$1@32b59207
>>>>>> 2016-12-10 11:03:03.696 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$5$1@7c204b59
>>>>>> 2016-12-10 11:03:03.696 [XNIO-1 I/O-2] TRACE
io.undertow.request.io -
>>>>>> Exception closing read side of SSL channel
>>>>>> javax.net.ssl.SSLException: Inbound closed before receiving
peer's
>>>>>> close_notify: possible truncation attack?
>>>>>> at sun.security.ssl.Alerts.getSSLException(Alerts.java:208)
>>>>>> at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1666)
>>>>>> at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1634)
>>>>>> at
>>>>>>
sun.security.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1561)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.notifyReadClosed(SslConduit.java:612)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.closed(SslConduit.java:983)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.close(SslConduit.java:1078)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.doUnwrap(SslConduit.java:799)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:645)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63)
>>>>>> at
io.undertow.protocols.ssl.SslConduit$5$1.run(SslConduit.java:1045)
>>>>>> at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:580)
>>>>>> at org.xnio.nio.WorkerThread.run(WorkerThread.java:464)
>>>>>> 2016-12-10 11:03:03.697 [XNIO-1 I/O-4] TRACE
io.undertow.request.io -
>>>>>> Exception closing read side of SSL channel
>>>>>> javax.net.ssl.SSLException: Inbound closed before receiving
peer's
>>>>>> close_notify: possible truncation attack?
>>>>>> at sun.security.ssl.Alerts.getSSLException(Alerts.java:208)
>>>>>> at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1666)
>>>>>> at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1634)
>>>>>> at
>>>>>>
sun.security.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1561)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.notifyReadClosed(SslConduit.java:612)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.closed(SslConduit.java:983)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.close(SslConduit.java:1078)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.doUnwrap(SslConduit.java:799)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:645)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63)
>>>>>> at
io.undertow.protocols.ssl.SslConduit$5$1.run(SslConduit.java:1045)
>>>>>> at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:580)
>>>>>> at org.xnio.nio.WorkerThread.run(WorkerThread.java:464)
>>>>>> 2016-12-10 11:03:03.697 [XNIO-1 I/O-2] TRACE org.xnio.listener -
>>>>>> Invoking listener
>>>>>> io.undertow.server.AbstractServerConnection$CloseSetter@55df2063
on channel
>>>>>> io.undertow.protocols.ssl.UndertowSslConnection@3ac7f450
>>>>>> 2016-12-10 11:03:03.698 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener
>>>>>> io.undertow.server.AbstractServerConnection$CloseSetter@42277317
on channel
>>>>>> io.undertow.protocols.ssl.UndertowSslConnection@53f69e92
>>>>>> 2016-12-10 11:03:03.698 [XNIO-1 I/O-2] TRACE org.xnio.safe-close
-
>>>>>> Closing resource org.xnio.nio.NioSocketStreamConnection@50bf3bfc
>>>>>> 2016-12-10 11:03:03.698 [XNIO-1 I/O-4] TRACE org.xnio.safe-close
-
>>>>>> Closing resource org.xnio.nio.NioSocketStreamConnection@4196fbe
>>>>>> 2016-12-10 11:03:03.698 [XNIO-1 I/O-2] TRACE org.xnio.nio -
>>>>>> Cancelling key sun.nio.ch.SelectionKeyImpl@4805f11b of
>>>>>> java.nio.channels.SocketChannel[connected local=/127.0.0.1:8443
>>>>>> remote=/127.0.0.1:56856] (same thread)
>>>>>> 2016-12-10 11:03:03.698 [XNIO-1 I/O-4] TRACE org.xnio.nio -
>>>>>> Cancelling key sun.nio.ch.SelectionKeyImpl@673b2384 of
>>>>>> java.nio.channels.SocketChannel[connected local=/127.0.0.1:8443
>>>>>> remote=/127.0.0.1:56854] (same thread)
>>>>>> 2016-12-10 11:03:03.699 [XNIO-1 I/O-2] TRACE org.xnio.safe-close
-
>>>>>> Closing resource
io.undertow.protocols.ssl.UndertowSslConnection@3ac7f450
>>>>>> 2016-12-10 11:03:03.699 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.699 [XNIO-1 I/O-4] TRACE org.xnio.safe-close
-
>>>>>> Closing resource
io.undertow.protocols.ssl.UndertowSslConnection@53f69e92
>>>>>> 2016-12-10 11:03:03.699 [XNIO-1 Accept] TRACE org.xnio.nio -
Running
>>>>>> task org.xnio.nio.QueuedNioTcpServer$2@1ce2a083
>>>>>> 2016-12-10 11:03:03.699 [XNIO-1 I/O-2] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$1@77593ca5
>>>>>> 2016-12-10 11:03:03.700 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$1@3548b3ac
>>>>>> 2016-12-10 11:03:03.700 [XNIO-1 Accept] TRACE org.xnio.nio -
Running
>>>>>> task org.xnio.nio.QueuedNioTcpServer$2@1ce2a083
>>>>>> 2016-12-10 11:03:03.700 [XNIO-1 I/O-2] TRACE org.xnio.listener -
>>>>>> Invoking listener
io.undertow.server.protocol.http.HttpReadListener@6962bde3
>>>>>> on channel org.xnio.conduits.ConduitStreamSourceChannel@45125494
>>>>>> 2016-12-10 11:03:03.700 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener
io.undertow.server.protocol.http.HttpReadListener@255c6481
>>>>>> on channel org.xnio.conduits.ConduitStreamSourceChannel@1b4554ad
>>>>>> 2016-12-10 11:03:03.700 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.701 [XNIO-1 I/O-2] TRACE org.xnio.safe-close
-
>>>>>> Closing resource
>>>>>> io.undertow.server.protocol.http.HttpServerConnection@6cdbf711
>>>>>> 2016-12-10 11:03:03.701 [XNIO-1 I/O-4] TRACE org.xnio.safe-close
-
>>>>>> Closing resource
>>>>>> io.undertow.server.protocol.http.HttpServerConnection@4bcc5cdf
>>>>>> 2016-12-10 11:03:03.701 [XNIO-1 I/O-2] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$2@52d9523b
>>>>>> 2016-12-10 11:03:03.702 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$2@320a217a
>>>>>> 2016-12-10 11:03:03.702 [XNIO-1 I/O-2] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@49c6180b
>>>>>> 2016-12-10 11:03:03.702 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@5c0faa95
>>>>>> 2016-12-10 11:03:03.714 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.715 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected key sun.nio.ch.SelectionKeyImpl@611889f4 for
>>>>>> sun.nio.ch.ServerSocketChannelImpl[/127.0.0.1:8443]
>>>>>> 2016-12-10 11:03:03.716 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.717 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@5c0faa95
>>>>>> 2016-12-10 11:03:03.718 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task org.xnio.nio.QueuedNioTcpServer$1@52c85f64
>>>>>> 2016-12-10 11:03:03.719 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener Delegating channel listener -> Accepting
listener for
>>>>>> io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5 on
channel TCP
>>>>>> server (NIO) <13f5555f>
>>>>>> 2016-12-10 11:03:03.719 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener Accepting listener for
>>>>>> io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5 on
channel
>>>>>> io.undertow.protocols.ssl.UndertowAcceptingSslChannel@328f1eb6
>>>>>> 2016-12-10 11:03:03.721 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener
io.undertow.server.protocol.http.HttpOpenListener@56f7c1e5
>>>>>> on channel
io.undertow.protocols.ssl.UndertowSslConnection@d84c5d1
>>>>>> 2016-12-10 11:03:03.721 [XNIO-1 I/O-4] TRACE io.undertow.request
-
>>>>>> Opened connection with /127.0.0.1:56858
>>>>>> 2016-12-10 11:03:03.724 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@5c0faa95 (with
timeout)
>>>>>> 2016-12-10 11:03:03.728 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@5c0faa95
>>>>>> 2016-12-10 11:03:03.728 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$5$1@47e5be01
>>>>>> 2016-12-10 11:03:03.729 [XNIO-1 I/O-4] TRACE
io.undertow.request.io -
>>>>>> Exception closing read side of SSL channel
>>>>>> javax.net.ssl.SSLException: Inbound closed before receiving
peer's
>>>>>> close_notify: possible truncation attack?
>>>>>> at sun.security.ssl.Alerts.getSSLException(Alerts.java:208)
>>>>>> at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1666)
>>>>>> at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1634)
>>>>>> at
>>>>>>
sun.security.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1561)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.notifyReadClosed(SslConduit.java:612)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.closed(SslConduit.java:983)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.close(SslConduit.java:1078)
>>>>>> at
io.undertow.protocols.ssl.SslConduit.doUnwrap(SslConduit.java:799)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:645)
>>>>>> at
>>>>>>
io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63)
>>>>>> at
io.undertow.protocols.ssl.SslConduit$5$1.run(SslConduit.java:1045)
>>>>>> at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:580)
>>>>>> at org.xnio.nio.WorkerThread.run(WorkerThread.java:464)
>>>>>> 2016-12-10 11:03:03.729 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener
>>>>>> io.undertow.server.AbstractServerConnection$CloseSetter@3457fbeb
on channel
>>>>>> io.undertow.protocols.ssl.UndertowSslConnection@d84c5d1
>>>>>> 2016-12-10 11:03:03.729 [XNIO-1 I/O-4] TRACE org.xnio.safe-close
-
>>>>>> Closing resource org.xnio.nio.NioSocketStreamConnection@1fd60afd
>>>>>> 2016-12-10 11:03:03.729 [XNIO-1 I/O-4] TRACE org.xnio.nio -
>>>>>> Cancelling key sun.nio.ch.SelectionKeyImpl@7da1dc1a of
>>>>>> java.nio.channels.SocketChannel[connected local=/127.0.0.1:8443
>>>>>> remote=/127.0.0.1:56858] (same thread)
>>>>>> 2016-12-10 11:03:03.730 [XNIO-1 I/O-4] TRACE org.xnio.safe-close
-
>>>>>> Closing resource
io.undertow.protocols.ssl.UndertowSslConnection@d84c5d1
>>>>>> 2016-12-10 11:03:03.730 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Selected on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.730 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$1@11f5487
>>>>>> 2016-12-10 11:03:03.730 [XNIO-1 Accept] TRACE org.xnio.nio -
Running
>>>>>> task org.xnio.nio.QueuedNioTcpServer$2@1ce2a083
>>>>>> 2016-12-10 11:03:03.730 [XNIO-1 I/O-4] TRACE org.xnio.listener -
>>>>>> Invoking listener
io.undertow.server.protocol.http.HttpReadListener@6b60e713
>>>>>> on channel org.xnio.conduits.ConduitStreamSourceChannel@60e3d137
>>>>>> 2016-12-10 11:03:03.731 [XNIO-1 Accept] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@342f8479
>>>>>> 2016-12-10 11:03:03.731 [XNIO-1 I/O-4] TRACE org.xnio.safe-close
-
>>>>>> Closing resource
>>>>>> io.undertow.server.protocol.http.HttpServerConnection@4f4dae34
>>>>>> 2016-12-10 11:03:03.732 [XNIO-1 I/O-4] TRACE org.xnio.nio -
Running
>>>>>> task io.undertow.protocols.ssl.SslConduit$2@348d6036
>>>>>> 2016-12-10 11:03:03.732 [XNIO-1 I/O-4] TRACE
org.xnio.nio.selector -
>>>>>> Beginning select on sun.nio.ch.KQueueSelectorImpl@5c0faa95
>>>>>>
>>>>>>
>>>>>> On Sat, Dec 10, 2016 at 10:58 AM, Hicks, Matt
<matt(a)matthicks.com>
>>>>>> wrote:
>>>>>>>
>>>>>>> Thanks Bill....I don't feel as crazy now. ;)
>>>>>>>
>>>>>>> On Sat, Dec 10, 2016 at 9:51 AM Bill O'Neil
<bill(a)dartalley.com>
>>>>>>> wrote:
>>>>>>>>
>>>>>>>> Oops I forgot
https://localhost:8443. Now it is giving me
localhost
>>>>>>>> unexpectedly closed the connection. With no errors. I
also don't have a cert
>>>>>>>> set up but I would think that should throw an error?
>>>>>>>>
>>>>>>>> The on startup JDK9 issue is still there.
>>>>>>>>
>>>>>>>> On Sat, Dec 10, 2016 at 10:45 AM, Bill O'Neil
<bill(a)dartalley.com>
>>>>>>>> wrote:
>>>>>>>>>
>>>>>>>>> Matt did you try turning on logging? Here are the two
errors I
>>>>>>>>> get. Stuart maybe you can help from this I don't
know much about SSL.
>>>>>>>>>
>>>>>>>>> This error is on server start. I'm running JDK
8.
>>>>>>>>>
>>>>>>>>> java.lang.NoSuchMethodException:
>>>>>>>>>
javax.net.ssl.SSLParameters.setApplicationProtocols([Ljava.lang.String;)
>>>>>>>>> at java.lang.Class.getMethod(Class.java:1786)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.alpn.JDK9AlpnProvider$1.run(JDK9AlpnProvider.java:47)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.alpn.JDK9AlpnProvider$1.run(JDK9AlpnProvider.java:43)
>>>>>>>>> at java.security.AccessController.doPrivileged(Native
Method)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.alpn.JDK9AlpnProvider.<clinit>(JDK9AlpnProvider.java:43)
>>>>>>>>> at
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
>>>>>>>>> Method)
>>>>>>>>> at
>>>>>>>>>
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
>>>>>>>>> at
>>>>>>>>>
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
>>>>>>>>> at
java.lang.reflect.Constructor.newInstance(Constructor.java:422)
>>>>>>>>> at java.lang.Class.newInstance(Class.java:442)
>>>>>>>>> at
>>>>>>>>>
java.util.ServiceLoader$LazyIterator.nextService(ServiceLoader.java:380)
>>>>>>>>> at
>>>>>>>>>
java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:404)
>>>>>>>>> at
java.util.ServiceLoader$1.next(ServiceLoader.java:480)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.alpn.ALPNManager.<init>(ALPNManager.java:40)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.alpn.ALPNManager.<clinit>(ALPNManager.java:35)
>>>>>>>>> at
>>>>>>>>>
io.undertow.server.protocol.http.AlpnOpenListener.<init>(AlpnOpenListener.java:67)
>>>>>>>>> at
>>>>>>>>>
io.undertow.server.protocol.http.AlpnOpenListener.<init>(AlpnOpenListener.java:90)
>>>>>>>>> at io.undertow.Undertow.start(Undertow.java:177)
>>>>>>>>> at
com.dartalley.function.Http2Server.main(Http2Server.java:70)
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> The following errors happen on request to the
localhost:8443 from
>>>>>>>>> Matt's code which leads to an empty response.
>>>>>>>>>
>>>>>>>>> 10:42:29.083 [XNIO-1 I/O-2] DEBUG
io.undertow.request.io -
>>>>>>>>> UT005013: An IOException occurred
>>>>>>>>> javax.net.ssl.SSLHandshakeException: UT000140:
Initial SSL/TLS
>>>>>>>>> data is not a handshake record
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.ALPNHackClientHelloExplorer.exploreClientHello(ALPNHackClientHelloExplorer.java:84)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.ALPNHackSSLEngine.unwrap(ALPNHackSSLEngine.java:205)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit.doUnwrap(SslConduit.java:729)
>>>>>>>>> at
io.undertow.protocols.ssl.SslConduit.read(SslConduit.java:567)
>>>>>>>>> at
>>>>>>>>>
org.xnio.conduits.ConduitStreamSourceChannel.read(ConduitStreamSourceChannel.java:127)
>>>>>>>>> at
>>>>>>>>>
io.undertow.server.protocol.http.AlpnOpenListener$AlpnConnectionListener.handleEvent(AlpnOpenListener.java:280)
>>>>>>>>> at
>>>>>>>>>
io.undertow.server.protocol.http.AlpnOpenListener.handleEvent(AlpnOpenListener.java:249)
>>>>>>>>> at
>>>>>>>>>
io.undertow.server.protocol.http.AlpnOpenListener.handleEvent(AlpnOpenListener.java:60)
>>>>>>>>> at
>>>>>>>>>
org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
>>>>>>>>> at
>>>>>>>>>
org.xnio.ChannelListeners$10.handleEvent(ChannelListeners.java:291)
>>>>>>>>> at
>>>>>>>>>
org.xnio.ChannelListeners$10.handleEvent(ChannelListeners.java:286)
>>>>>>>>> at
>>>>>>>>>
org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
>>>>>>>>> at
>>>>>>>>>
org.xnio.ChannelListeners$DelegatingChannelListener.handleEvent(ChannelListeners.java:1092)
>>>>>>>>> at
>>>>>>>>>
org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
>>>>>>>>> at
>>>>>>>>>
org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:128)
>>>>>>>>> at
org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:580)
>>>>>>>>> at
org.xnio.nio.WorkerThread.run(WorkerThread.java:464)
>>>>>>>>> 10:42:29.091 [XNIO-1 I/O-4] DEBUG io.undertow.request
- UT005013:
>>>>>>>>> An IOException occurred
>>>>>>>>> javax.net.ssl.SSLHandshakeException: UT000140:
Initial SSL/TLS
>>>>>>>>> data is not a handshake record
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.ALPNHackClientHelloExplorer.exploreClientHello(ALPNHackClientHelloExplorer.java:84)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.ALPNHackSSLEngine.unwrap(ALPNHackSSLEngine.java:205)
>>>>>>>>> at
javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit.doUnwrap(SslConduit.java:748)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:645)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit$SslReadReadyHandler.readReady(SslConduit.java:1097)
>>>>>>>>> at
>>>>>>>>>
org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:88)
>>>>>>>>> at
org.xnio.nio.WorkerThread.run(WorkerThread.java:559)
>>>>>>>>> 10:42:29.100 [XNIO-1 I/O-2] DEBUG io.undertow.request
- UT005013:
>>>>>>>>> An IOException occurred
>>>>>>>>> javax.net.ssl.SSLHandshakeException: UT000140:
Initial SSL/TLS
>>>>>>>>> data is not a handshake record
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.ALPNHackClientHelloExplorer.exploreClientHello(ALPNHackClientHelloExplorer.java:84)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.ALPNHackSSLEngine.unwrap(ALPNHackSSLEngine.java:205)
>>>>>>>>> at
javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit.doUnwrap(SslConduit.java:748)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:645)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63)
>>>>>>>>> at
>>>>>>>>>
io.undertow.protocols.ssl.SslConduit$SslReadReadyHandler.readReady(SslConduit.java:1097)
>>>>>>>>> at
>>>>>>>>>
org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:88)
>>>>>>>>> at
org.xnio.nio.WorkerThread.run(WorkerThread.java:559)
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On Sat, Dec 10, 2016 at 10:15 AM, Hicks, Matt
<matt(a)matthicks.com>
>>>>>>>>> wrote:
>>>>>>>>>>
>>>>>>>>>> I've updated to 1.4.7.Final, I switched to
passing an Array of
>>>>>>>>>> keyManagers and an Array of trustManagers,
I've tried commenting out
>>>>>>>>>> ENABLE_HTTP2, I've installed the JCE
Unlimited Strength (and verified it's
>>>>>>>>>> being used) and I'm consistently getting
ERR_CONNECTION_CLOSED when I try to
>>>>>>>>>> connect to
https://localhost:8443
>>>>>>>>>>
>>>>>>>>>> If I connect to
http://localhost:8080 then I get
the expected
>>>>>>>>>> "Hello, World!". If someone could just
test that snippet and tell me if
>>>>>>>>>> they can repeat the problem it would be greatly
appreciated.
>>>>>>>>>>
>>>>>>>>>> On Fri, Dec 9, 2016 at 5:30 PM Hicks, Matt
<matt(a)matthicks.com>
>>>>>>>>>> wrote:
>>>>>>>>>>>
>>>>>>>>>>> Stuart, I don't think I have the JCE
Unlimited Strength policy
>>>>>>>>>>> files installed. I'll look into seeing
if that's the problem. I am
>>>>>>>>>>> currently using 1.4.6.Final. I commented out
enabling of HTTP2 but I'm
>>>>>>>>>>> still getting the same problem. It will
probably be tomorrow before I can
>>>>>>>>>>> get the JCE Unlimited Strength installed, but
either way I should be seeing
>>>>>>>>>>> an error but I am not.
>>>>>>>>>>>
>>>>>>>>>>> Can you check that code snippet I posted?
It's a simplified
>>>>>>>>>>> version of the example you sent me previously
that just outputs "Hello,
>>>>>>>>>>> World!". If you're able to run it
and it works then perhaps there's
>>>>>>>>>>> something wrong in my machine configuration,
but I'd like some confirmation.
>>>>>>>>>>>
>>>>>>>>>>> On Fri, Dec 9, 2016 at 4:30 PM Stuart
Douglas
>>>>>>>>>>> <sdouglas(a)redhat.com> wrote:
>>>>>>>>>>>>
>>>>>>>>>>>> I just released 1.4.7.Final that should
fix the
>>>>>>>>>>>> ClassCastException that you were seeing.
>>>>>>>>>>>>
>>>>>>>>>>>> Your example code should work. What
version of Undertow are you
>>>>>>>>>>>> using, and do you have the JCE unlimited
strength ciphers installed?
>>>>>>>>>>>>