jetty / jetty.project

Eclipse Jetty® - Web Container & Clients - supports HTTP/2, HTTP/1.1, HTTP/1.0, websocket, servlets, and more
https://eclipse.dev/jetty
Other
3.86k stars 1.91k forks source link

Incorrect ALPN default protocol #671

Closed UnsungHero97 closed 8 years ago

UnsungHero97 commented 8 years ago

I've set up Jetty 9.3.10.v20160621 with SSL support, and SSL Labs gives my server an A. However, I'm running into a strange problem when I try to enable HTTP/2. With it disabled, SSL Labs reports that my server supports HSTS, but with it enabled, the HSTS section shows failed HTTP request, and Jetty logs the following errors:

2016-06-28 12:50:07.626:WARN:oejut.QueuedThreadPool:qtp1851691492-18: 
java.lang.IllegalStateException: Internal error
    at sun.security.ssl.SSLEngineImpl.initHandshaker(SSLEngineImpl.java:470)
    at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1007)
    at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:907)
    at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781)
    at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:524)
    at org.eclipse.jetty.http2.HTTP2Connection.fill(HTTP2Connection.java:106)
    at org.eclipse.jetty.http2.HTTP2Connection.access$600(HTTP2Connection.java:37)
    at org.eclipse.jetty.http2.HTTP2Connection$HTTP2Producer.produce(HTTP2Connection.java:179)
    at org.eclipse.jetty.util.thread.strategy.ProduceExecuteConsume.execute(ProduceExecuteConsume.java:69)
    at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:97)
    at org.eclipse.jetty.http2.HTTP2Connection$FillCallback.succeeded(HTTP2Connection.java:215)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
    at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:201)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
    at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
    at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
    at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
    at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
    at java.lang.Thread.run(Thread.java:745)
2016-06-28 12:50:07.628:WARN:oejut.QueuedThreadPool:qtp1851691492-18: Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$2@504bdcb8 in qtp1851691492{STARTED,10<=10<=200,i=5,q=0}
2016-06-28 12:50:07.727:WARN:oejut.QueuedThreadPool:qtp1851691492-10: 
java.lang.IllegalStateException: Internal error
    at sun.security.ssl.SSLEngineImpl.initHandshaker(SSLEngineImpl.java:470)
    at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1007)
    at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:907)
    at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781)
    at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:524)
    at org.eclipse.jetty.http2.HTTP2Connection.fill(HTTP2Connection.java:106)
    at org.eclipse.jetty.http2.HTTP2Connection.access$600(HTTP2Connection.java:37)
    at org.eclipse.jetty.http2.HTTP2Connection$HTTP2Producer.produce(HTTP2Connection.java:179)
    at org.eclipse.jetty.util.thread.strategy.ProduceExecuteConsume.execute(ProduceExecuteConsume.java:69)
    at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:97)
    at org.eclipse.jetty.http2.HTTP2Connection$FillCallback.succeeded(HTTP2Connection.java:215)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
    at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:201)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
    at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
    at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
    at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
    at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
    at java.lang.Thread.run(Thread.java:745)
2016-06-28 12:50:07.739:WARN:oejut.QueuedThreadPool:qtp1851691492-10: Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$2@504bdcb8 in qtp1851691492{STARTED,10<=10<=200,i=4,q=0}

What could be going wrong when I enable HTTP/2?

I'm pretty confident that I've configured Jetty with SSL correctly since SSL Labs gives me an A when it tests my server, but I'm not sure how HTTP/2 affects things. I'm happy to provide more details and config files if needed.

Environment Details

$ java -version
openjdk version "1.8.0_91"
OpenJDK Runtime Environment (build 1.8.0_91-8u91-b14-0ubuntu4~15.10.1-b14)
OpenJDK 64-Bit Server VM (build 25.91-b14, mixed mode)
joakime commented 8 years ago

To help us troubleshoot this HTTP/2 environment, can you provide us with ...

UnsungHero97 commented 8 years ago

I updated my question with the version of Java I'm running:

$ java -version
openjdk version "1.8.0_91"
OpenJDK Runtime Environment (build 1.8.0_91-8u91-b14-0ubuntu4~15.10.1-b14)
OpenJDK 64-Bit Server VM (build 25.91-b14, mixed mode)

As for the alpn-boot.jar, I think I missed this step. According to the docs, it seems the corresponding ALPN version for OpenJDK 1.8.0u91 is 8.1.7.v20160121, which I found here:

http://central.maven.org/maven2/org/mortbay/jetty/alpn/alpn-boot/8.1.7.v20160121/

... as well as here:

$ /path/to/jetty/lib/alpn/alpn-boot-8.1.7.v20160121.jar

I'll try adding this JAR to the classpath now.

joakime commented 8 years ago

@UnsungHero97 note that the required (for HTTP/2) alpn-boot-8.1.7.v20160121.jar must added as a -Xbootclasspath jar, it cannot function as a normal classpath jar.

joakime commented 8 years ago

Are you using Jetty Distribution, or something else?

If you are using jetty-distribution, goto your ${jetty.base} and run ...

$ cd /path/to/mybase
$ java -jar /path/to/jetty-dist/start.jar --add-to-start=http2

That will wire up the ${jetty.base}/start.ini to have the needed components for http2 (including the alpn-boot.jar requirement for your JVM)

UnsungHero97 commented 8 years ago

I'm using Jetty Distribution 9.3.10.v20160621. Also, I know this is bad, but I'm not using a jetty base at the moment. I'm just running the server out of jetty home.

I've already done the --add-to-start=http2 step. So I just tried adding alpn-boot-8.1.7.v20160121.jar and running the server using this command:

$ java -Xbootclasspath/p:/usr/local/jetty9/lib/alpn/alpn-boot-8.1.7.v20160121.jar -jar start.jar

Same result as above.

joakime commented 8 years ago

Running from ${jetty.home} is highly discouraged. There's even a warning presented to you to not do that!

Your effort to inject the -Xbootclasspath is pointless in this scenario, as the jetty-distribution will fork a new JVM with its own -Xbootclasspath as part of its operation when using a properly split ${jetty.home} vs ${jetty.base} setup.

Special Notes:

UnsungHero97 commented 8 years ago

Good to know. Ok, I'll set up jetty base properly and try it all again. I'll report back with the results. Thanks, @joakime!

UnsungHero97 commented 8 years ago

@joakime I think I have the correct ${jetty.home} + ${jetty.base} setup now.

Now, I'm calling java -jar $JETTY_HOME/start.jar from inside ${jetty.base}, but I'm still seeing the above issue. Here's the --list-config:

/usr/local/jetty-base$ java -jar $JETTY_HOME/start.jar --list-config

Java Environment:
-----------------
 java.home = /usr/lib/jvm/java-8-openjdk-amd64/jre
 java.vm.vendor = Oracle Corporation
 java.vm.version = 25.91-b14
 java.vm.name = OpenJDK 64-Bit Server VM
 java.vm.info = mixed mode
 java.runtime.name = OpenJDK Runtime Environment
 java.runtime.version = 1.8.0_91-8u91-b14-0ubuntu4~15.10.1-b14
 java.io.tmpdir = /tmp
 user.dir = /usr/local/jetty-base
 user.language = en
 user.country = US

Jetty Environment:
-----------------
 jetty.version = 9.3.10.v20160621
 jetty.tag.version = master
 jetty.home = /usr/local/jetty-distribution-9.3.10.v20160621
 jetty.base = /usr/local/jetty-base

Config Search Order:
--------------------
 <command-line>
 ${jetty.base} -> /usr/local/jetty-base
 ${jetty.home} -> /usr/local/jetty-distribution-9.3.10.v20160621

JVM Arguments:
--------------
 -Xbootclasspath/p:lib/alpn/alpn-boot-8.1.7.v20160121.jar

System Properties:
------------------
 https.protocols = TLSv1,TLSv1.1,TLSv1.2
 jdk.tls.client.protocols = TLSv1,TLSv1.1,TLSv1.2
 jdk.tls.ephemeralDHKeySize = 2048

Properties:
-----------
 https.protocols = TLSv1,TLSv1.1,TLSv1.2
 java.version = 1.8.0_91
 java.version.major = 1
 java.version.minor = 8
 java.version.revision = 0
 java.version.update = 91
 jdk.tls.client.protocols = TLSv1,TLSv1.1,TLSv1.2
 jdk.tls.ephemeralDHKeySize = 2048
 jetty.sslContext.keyManagerPassword = ...
 jetty.sslContext.keyStorePassword = ...
 jetty.sslContext.trustStorePassword = ...

Jetty Server Classpath:
-----------------------
Version Information on 16 entries in the classpath.
Note: order presented here is how they would appear on the classpath.
      changes to the --module=name command line options will be reflected here.
 0:                    3.1.0 | ${jetty.home}/lib/servlet-api-3.1.jar
 1:                 3.1.0.M0 | ${jetty.home}/lib/jetty-schemas-3.1.jar
 2:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-http-9.3.10.v20160621.jar
 3:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-server-9.3.10.v20160621.jar
 4:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-xml-9.3.10.v20160621.jar
 5:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-util-9.3.10.v20160621.jar
 6:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-io-9.3.10.v20160621.jar
 7:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-rewrite-9.3.10.v20160621.jar
 8:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-security-9.3.10.v20160621.jar
 9:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-servlet-9.3.10.v20160621.jar
10:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-alpn-server-9.3.10.v20160621.jar
11:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-webapp-9.3.10.v20160621.jar
12:         9.3.10.v20160621 | ${jetty.home}/lib/jetty-deploy-9.3.10.v20160621.jar
13:         9.3.10.v20160621 | ${jetty.home}/lib/http2/http2-common-9.3.10.v20160621.jar
14:         9.3.10.v20160621 | ${jetty.home}/lib/http2/http2-hpack-9.3.10.v20160621.jar
15:         9.3.10.v20160621 | ${jetty.home}/lib/http2/http2-server-9.3.10.v20160621.jar

Jetty Active XMLs:
------------------
 ${jetty.home}/etc/jetty.xml
 ${jetty.home}/etc/jetty-http.xml
 ${jetty.base}/etc/jetty-rewrite.xml
 ${jetty.home}/etc/jetty-ssl.xml
 ${jetty.home}/etc/jetty-ssl-context.xml
 ${jetty.home}/etc/jetty-alpn.xml
 ${jetty.home}/etc/jetty-deploy.xml
 ${jetty.home}/etc/jetty-http2.xml
 ${jetty.home}/etc/jetty-https.xml
 ${jetty.base}/etc/base-config-ssl.xml
UnsungHero97 commented 8 years ago

@joakime any updates?

UnsungHero97 commented 8 years ago

I think I found the problem. It looks like jetty-alpn.xml inside ${jetty.home} has empty defaults for jetty.alpn.protocols and jetty.alpn.defaultProtocol. So I updated start.d/alpn.ini inside ${jetty.base} with the following (basically uncommenting the lines for the defaults):

# --------------------------------------- 
# Module: alpn
--module=alpn

## Overrides the order protocols are chosen by the server.
## The default order is that specified by the order of the
## modules declared in start.ini.
jetty.alpn.protocols=h2,http/1.1

## Specifies what protocol to use when negotiation fails.
jetty.alpn.defaultProtocol=http/1.1

After this update, the errors go away, and SSL Labs is happy about HSTS.

This leads me to another question. Is there a recommended way to update ${jetty.base} with custom values and settings? Should all configuration happen only in ${jetty.base}/start.ini, or only in ${jetty.base}/start.d/*.ini, or only in ${jetty.base}/etc/*.xml, or a mixture of all?

gregw commented 8 years ago

Hristo,

Very strange! The ALPN should default those values to exactly those values, unless you have non standard connection factories installed.

It would be great to see a server dump (see start.d/server.ini) without these properties set.

regards

On 2 July 2016 at 09:48, Hristo Oskov notifications@github.com wrote:

I think I found the problem. It looks like jetty-alpn.xml inside ${jetty.home} has empty defaults for jetty.alpn.protocols and jetty.alpn.defaultProtocol. So I updated start.d/alpn.ini inside ${jetty.base} with the following (basically uncommenting the lines for the defaults):

---------------------------------------

Module: alpn

--module=alpn

Overrides the order protocols are chosen by the server.

The default order is that specified by the order of the

modules declared in start.ini.

jetty.alpn.protocols=h2,http/1.1

Specifies what protocol to use when negotiation fails.

jetty.alpn.defaultProtocol=http/1.1

After this update, the errors go away, and SSL Labs is happy about HSTS.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/eclipse/jetty.project/issues/671#issuecomment-230069535, or mute the thread https://github.com/notifications/unsubscribe/AAEUrTtygqyOf54mWM_px_trVYzRHlcFks5qRadMgaJpZM4JAVE6 .

Greg Wilkins gregw@webtide.com CTO http://webtide.com

UnsungHero97 commented 8 years ago

@gregw, are you referring to the following config settings in ${jetty.base}/start.d/server.ini?

jetty.server.dumpAfterStart=true
jetty.server.dumpBeforeStop=true
UnsungHero97 commented 8 years ago

@gregw , I set the jetty.server.dumpAfterStart and dumpBeforeStop to true in ${jetty.base}/start.d/server.ini, then started Jetty, then ran the SSL Labs test to trigger the error, then stopped Jetty. I'm attaching the output in the logs after these steps. Please let me know if this is what you're referring to.

jetty-server-dump.txt

gregw commented 8 years ago

Here is the relevant section:

 += ServerConnector@714ad79a{SSL,[ssl, alpn, h2, h2-17, h2-16, h2-15, h2-14, http/1.1]}{0.0.0.0:8444} - STARTED
 |   +~ org.eclipse.jetty.server.Server@5594a1b5 - STARTING
 |   +~ qtp772777427{STARTED,10<=10<=200,i=6,q=0} - STARTED
 |   +~ org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@443b7951 - STARTED
 |   +- org.eclipse.jetty.io.ArrayByteBufferPool@53aac487
 |   += org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@52b1beb6 - STARTED
 |   |   += org.eclipse.jetty.io.ManagedSelector@273e7444 id=0 keys=0 selected=0 id=0
 |   |       +- sun.nio.ch.EPollSelectorImpl@6c89fe1c keys=0
 |   += SslConnectionFactory@2a33fae0{SSL->alpn} - STARTED
 |   |   += SslContextFactory@4d02f94e(file:///usr/local/jetty-test/etc/keystore,file:///usr/local/jetty-test/etc/keystore) - STARTED
 |   += ALPNServerConnectionFactory@7b1d7fff{[alpn],null,[]} - STARTED
 |   += HTTP2ServerConnectionFactory@45c8e616[h2, h2-17, h2-16, h2-15, h2-14] - STARTED
 |   |   +- HttpConfiguration@7db12bb6{32768/8192,8192/8192,https://:8443,[SecureRequestCustomizer@783a467b]}
 |   += HttpConnectionFactory@75bd9247[HTTP/1.1] - STARTED
 |   |   +- HttpConfiguration@7db12bb6{32768/8192,8192/8192,https://:8443,[SecureRequestCustomizer@783a467b]}
 |   +- sun.nio.ch.ServerSocketChannelImpl[/0:0:0:0:0:0:0:0:8444]
 |   +- qtp772777427-13-acceptor-0@7f8d261b-ServerConnector@714ad79a{SSL,[ssl, alpn, h2, h2-17, h2-16, h2-15, h2-14, http/1.1]}{0.0.0.0:8444}

Which shows that the ALPNServerConnectionFactory has been started without either a default protocol, nor a list of protocols to negotiate.

So when newConnection is called, the lack of a protocol list will trigger this code, which extracts a list from the connectors protocol list, which we can see is [ssl, alpn, h2, h2-17, h2-16, h2-15, h2-14, http/1.1].

This all looks good, except http/1.1 is last, so h2 is being [selected as the default protocol](// if default protocol is not set, then it is the first protocol given String dft = defaultProtocol; if %28dft == null && !negotiated.isEmpty%28%29%29 dft = negotiated.get%280%29;)?

So something has gone wrong in our module ordering.... stand by why I investigate.

gregw commented 8 years ago

@sbordet Can you review this fix when you get a chance. The convention was to pick the first protocol as the default, but if you have a priority ordered list of h2,http/1.1 then that is the wrong choice for clients that do not speak ALPN.

I have changed to always pock http/1.1 if it is in the list of protocols. While this is a bit of a special case, I think it is a reasonable heuristic to make a zero configuration connector work out of the box.

UnsungHero97 commented 8 years ago

thanks @gregw for taking a look!

since we have this thread going, can you please answer my other question (from an above comment)...

Is there a recommended way to update ${jetty.base} with custom values and settings? Should all configuration happen only in ${jetty.base}/start.ini, or only in ${jetty.base}/start.d/*.ini, or only in ${jetty.base}/etc/*.xml, or a mixture of all?

gregw commented 8 years ago

@sbordet I committed a code cleanup and then reopened for your review.

joakime commented 8 years ago

@sbordet have you completed your code review on this?

sbordet commented 8 years ago

Latest code looks good.