jetty-project / jetty-alpn

Implementation of ALPN (Application Layer Protocol Negotiation) Specification for OpenJDK 7 or greater
48 stars 27 forks source link

SSLProtocolException: Handshake message sequence violation, 1 #17

Open nhenneaux opened 6 years ago

nhenneaux commented 6 years ago

Hello,

From time to time I got the following exception during a connection. Could you tell me what is the cause of the error? Is there a way to solve it?

build   25-Jan-2018 06:05:33    2018-01-25T05:05:33.758+0000  [HttpClient@1767523455-28] WARN  org.eclipse.jetty.io.SelectorManager - Exception while notifying connection SslConnection@6ff29fc0{NEED_UNWRAP,eio=-1/-1,di=-1}=>ALPNClientConnection@50fc8c8b<-SocketChannelEndPoint@4e7e8fa3{localhost/127.0.0.1:54396<->/127.0.0.1:54396,CLOSED,fill=-,flush=-,to=2/0}{io=0/0,kio=-1,kro=-1}->SslConnection@6ff29fc0{NEED_UNWRAP,eio=-1/-1,di=-1}=>ALPNClientConnection@50fc8c8b
build   25-Jan-2018 06:05:33    org.eclipse.jetty.io.RuntimeIOException: javax.net.ssl.SSLHandshakeException: Handshake message sequence violation, 1
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.NegotiatingClientConnection.onOpen(NegotiatingClientConnection.java:73) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ssl.SslConnection.onOpen(SslConnection.java:249) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.SelectorManager.connectionOpened(SelectorManager.java:322) [jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ManagedSelector.createEndPoint(ManagedSelector.java:213) [jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ManagedSelector.access$1600(ManagedSelector.java:60) [jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ManagedSelector$CreateEndPoint.run(ManagedSelector.java:650) [jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708) [jetty-util-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) [jetty-util-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151]
build   25-Jan-2018 06:05:33    Caused by: javax.net.ssl.SSLHandshakeException: Handshake message sequence violation, 1
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:804) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.flush(SslConnection.java:1054) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.NegotiatingClientConnection.onOpen(NegotiatingClientConnection.java:64) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        ... 8 more
build   25-Jan-2018 06:05:33    Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 1
build   25-Jan-2018 06:05:33        at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1487) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:653) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.flush(SslConnection.java:1054) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.NegotiatingClientConnection.onOpen(NegotiatingClientConnection.java:64) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        ... 8 more
build   25-Jan-2018 06:05:33    Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 1
build   25-Jan-2018 06:05:33        at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:200) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1026) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at sun.security.ssl.Handshaker$1.run(Handshaker.java:966) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at sun.security.ssl.Handshaker$1.run(Handshaker.java:963) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1416) ~[?:1.8.0_151]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:747) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.flush(SslConnection.java:1054) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        at org.eclipse.jetty.io.NegotiatingClientConnection.onOpen(NegotiatingClientConnection.java:64) ~[jetty-io-9.4.8.v20171121.jar:9.4.8.v20171121]
build   25-Jan-2018 06:05:33        ... 8 more

Thank you in advance!

sbordet commented 6 years ago

Never seen this. It complains that the client received a ClientHello which is obviously wrong. Are you sure you are using the right ALPN boot jar with the right JDK version ?

nhenneaux commented 6 years ago

JDK is 1.8.0_151 while ALPN version is 8.1.11.v20170118. the problems only occurs at a rate of 1 over 10 or 20 successful execution.

sbordet commented 6 years ago

What server it is ?

nhenneaux commented 6 years ago

Jetty server. Everything running in the same JVM (server and client).

sbordet commented 6 years ago

Do you have reproducible code that we can try ?

nhenneaux commented 6 years ago

it is not a deterministic issue and I cannot reproduce it with an isolated code.