Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
[jetty-users] SSL-handshake more or less broken in Jetty 9.0.3

Hi,

I know the subject is quite hard (as well, since this is my
first mail in this group ;-) but I don't know of a better one,
since it really seems to be the case.

I'm currenty doing a migration from Jetty 7 to Jetty 9 and
run into problems when setting up an SSL-server with and without
needed client certificates. The problems are similar to the
mail at http://dev.eclipse.org/mhonarc/lists/jetty-users/msg03102.html
but it goes farther.

I tried to create a bug-report at bugzilla (or add a comment to
https://bugs.eclipse.org/bugs/show_bug.cgi?id=402626 which covers
a bit of the whole problem) but I haven't found a register-link.

The problem is that the server doesn't generate SSL-Alerts leaving
the client in a socket.read() until that client is running into a
timeout (which might be never in dependence on how the socket is
created). The closing of the endpoint in oej.io.ssl.SslConnection
doesn't seem to have any effect. Until there is a garbage collector
run the socket stays open. Sooner or later (on low-traffic systems
expect it to be the latter) the sockets are closed, so at least
you shouldn't be able to construct a DoS-attack with this.

To reproduce the problem I created a JUnit-testcase that allows
an easy reproduction of the problem. As well you can see another
problem occuring if you comment out lines 249-252 leading to the
effect that the server get no server-certificates for the connection.
In that case testSslStandardConnection will also end in a read
timeout (in that case after two minutes).

In addition to that I added the Wireshark-trace of the second
test showing that no SSL-Alert is sent to the client and that
the connection is only closed after the client ran into the timeout.
Don't get confused by the IPs being involved. I ran a TCP-gateway
on a second computer to be able to capture the packets, since
this doesn't work here on the loopback device.

If this bug-report is better sent to jetty-dev, just tell me ;-)
JVM being used for the test is JDK 1.7.0_21 on Windows 32 Bit.
The testcase uses BouncyCastle for the creation of the certificates
the server should use. The testcase sets its own KeyStore,
KeyManager and TrustManager, so you don't need to create
file-based KeyStores before starting the test.

This bug stopped our migration, so a fix is highly appreciated ;-)


Best regards,

Lothar Kimmeringer
2013-07-15 14:15:03.995:DBUG:oejuc.ContainerLifeCycle:main: org.eclipse.jetty.server.Server@13968f1 added {qtp4599696{STOPPED,8<=0<=200,i=0,q=0},AUTO}
2013-07-15 14:15:04.037:DBUG:oejuc.ContainerLifeCycle:main: SslConnectionFactory@1fc0f04{SSL-http/1.1} added {TestSSLContextFactory@13ded59(null,null),AUTO}
2013-07-15 14:15:04.072:DBUG:oejuc.ContainerLifeCycle:main: HttpConnectionFactory@edeea8{HTTP/1.1} added {HttpConfiguration@cf71b7{32768,8192/8192,https://:0,[]},POJO}
2013-07-15 14:15:04.088:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{null}{0.0.0.0:0} added {org.eclipse.jetty.server.Server@13968f1,UNMANAGED}
2013-07-15 14:15:04.089:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{null}{0.0.0.0:0} added {qtp4599696{STOPPED,8<=0<=200,i=0,q=0},AUTO}
2013-07-15 14:15:04.091:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{null}{0.0.0.0:0} added {org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@ac706a,AUTO}
2013-07-15 14:15:04.092:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{null}{0.0.0.0:0} added {org.eclipse.jetty.io.ArrayByteBufferPool@16affac,POJO}
2013-07-15 14:15:04.093:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{null}{0.0.0.0:0} added {SslConnectionFactory@1fc0f04{SSL-http/1.1},AUTO}
2013-07-15 14:15:04.094:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:0} added {HttpConnectionFactory@edeea8{HTTP/1.1},AUTO}
2013-07-15 14:15:04.099:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:0} added {org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@124e205,MANAGED}
2013-07-15 14:15:04.100:DBUG:oejuc.ContainerLifeCycle:main: org.eclipse.jetty.server.Server@13968f1 added {ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345},AUTO}
2013-07-15 14:15:04.123:DBUG:oejuc.ContainerLifeCycle:main: org.eclipse.jetty.server.Server@13968f1 added {org.eclipse.jetty.server.handler.ContextHandlerCollection@c21d01,AUTO}
2013-07-15 14:15:04.123:DBUG:oejuc.AbstractLifeCycle:main: starting org.eclipse.jetty.server.Server@13968f1
2013-07-15 14:15:04.132:INFO:oejs.Server:main: jetty-9.0.3.v20130506
2013-07-15 14:15:04.236:DBUG:oejsh.AbstractHandler:main: starting org.eclipse.jetty.server.Server@13968f1
2013-07-15 14:15:04.236:DBUG:oejuc.AbstractLifeCycle:main: starting qtp4599696{STOPPED,8<=0<=200,i=0,q=0}
2013-07-15 14:15:04.241:DBUG:oejuc.AbstractLifeCycle:main: STARTED qtp4599696{STARTED,8<=8<=200,i=2,q=0}
2013-07-15 14:15:04.242:DBUG:oejuc.AbstractLifeCycle:main: starting org.eclipse.jetty.server.handler.ContextHandlerCollection@c21d01
2013-07-15 14:15:04.249:DBUG:oejsh.AbstractHandler:main: starting org.eclipse.jetty.server.handler.ContextHandlerCollection@c21d01
2013-07-15 14:15:04.249:DBUG:oejuc.AbstractLifeCycle:main: STARTED org.eclipse.jetty.server.handler.ContextHandlerCollection@c21d01
2013-07-15 14:15:04.249:DBUG:oejuc.AbstractLifeCycle:main: starting ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}
2013-07-15 14:15:04.265:DBUG:oejuc.ContainerLifeCycle:main: ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345} added {sun.nio.ch.ServerSocketChannelImpl[/0:0:0:0:0:0:0:0:12345],POJO}
2013-07-15 14:15:04.267:DBUG:oejuc.AbstractLifeCycle:main: starting org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@ac706a
2013-07-15 14:15:04.275:DBUG:oejuc.AbstractLifeCycle:main: STARTED org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@ac706a
2013-07-15 14:15:04.275:DBUG:oejuc.AbstractLifeCycle:main: starting SslConnectionFactory@1fc0f04{SSL-http/1.1}
2013-07-15 14:15:04.276:DBUG:oejuc.AbstractLifeCycle:main: starting TestSSLContextFactory@13ded59(null,null)
create test keystore
create test keymanager
get key manager for keystore java.security.KeyStore@11b1e39
get trust manager for keystore java.security.KeyStore@11b1e39
2013-07-15 14:15:05.837:DBUG:oejus.SslContextFactory:main: Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
2013-07-15 14:15:05.844:DBUG:oejus.SslContextFactory:main: Enabled Ciphers   [TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_SHA, TLS_ECDH_ECDSA_WITH_RC4_128_SHA, TLS_ECDH_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_EMPTY_RENEGOTIATION_INFO_SCSV] of [TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_SHA, TLS_ECDH_ECDSA_WITH_RC4_128_SHA, TLS_ECDH_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, TLS_DH_anon_WITH_AES_256_CBC_SHA256, TLS_ECDH_anon_WITH_AES_256_CBC_SHA, TLS_DH_anon_WITH_AES_256_CBC_SHA, TLS_DH_anon_WITH_AES_128_CBC_SHA256, TLS_ECDH_anon_WITH_AES_128_CBC_SHA, TLS_DH_anon_WITH_AES_128_CBC_SHA, TLS_ECDH_anon_WITH_RC4_128_SHA, SSL_DH_anon_WITH_RC4_128_MD5, TLS_ECDH_anon_WITH_3DES_EDE_CBC_SHA, SSL_DH_anon_WITH_3DES_EDE_CBC_SHA, TLS_RSA_WITH_NULL_SHA256, TLS_ECDHE_ECDSA_WITH_NULL_SHA, TLS_ECDHE_RSA_WITH_NULL_SHA, SSL_RSA_WITH_NULL_SHA, TLS_ECDH_ECDSA_WITH_NULL_SHA, TLS_ECDH_RSA_WITH_NULL_SHA, TLS_ECDH_anon_WITH_NULL_SHA, SSL_RSA_WITH_NULL_MD5, SSL_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_DH_anon_WITH_DES_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_DH_anon_EXPORT_WITH_RC4_40_MD5, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_DH_anon_EXPORT_WITH_DES40_CBC_SHA, TLS_KRB5_WITH_RC4_128_SHA, TLS_KRB5_WITH_RC4_128_MD5, TLS_KRB5_WITH_3DES_EDE_CBC_SHA, TLS_KRB5_WITH_3DES_EDE_CBC_MD5, TLS_KRB5_WITH_DES_CBC_SHA, TLS_KRB5_WITH_DES_CBC_MD5, TLS_KRB5_EXPORT_WITH_RC4_40_SHA, TLS_KRB5_EXPORT_WITH_RC4_40_MD5, TLS_KRB5_EXPORT_WITH_DES_CBC_40_SHA, TLS_KRB5_EXPORT_WITH_DES_CBC_40_MD5]
2013-07-15 14:15:05.845:DBUG:oejuc.AbstractLifeCycle:main: STARTED TestSSLContextFactory@13ded59(null,null)
2013-07-15 14:15:05.859:DBUG:oejuc.AbstractLifeCycle:main: STARTED SslConnectionFactory@1fc0f04{SSL-http/1.1}
2013-07-15 14:15:05.860:DBUG:oejuc.AbstractLifeCycle:main: starting HttpConnectionFactory@edeea8{HTTP/1.1}
2013-07-15 14:15:05.860:DBUG:oejuc.AbstractLifeCycle:main: STARTED HttpConnectionFactory@edeea8{HTTP/1.1}
2013-07-15 14:15:05.861:DBUG:oejuc.AbstractLifeCycle:main: starting org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@124e205
2013-07-15 14:15:05.873:DBUG:oejuc.AbstractLifeCycle:main: starting org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=-1 selected=-1
2013-07-15 14:15:05.894:DBUG:oejuc.AbstractLifeCycle:main: STARTED org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=0 selected=0
2013-07-15 14:15:05.895:DBUG:oejut.QueuedThreadPool:main: qtp4599696{STARTED,8<=8<=200,i=8,q=0} dispatched org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=0 selected=0
2013-07-15 14:15:05.897:DBUG:oejuc.AbstractLifeCycle:main: starting org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=-1 selected=-1
2013-07-15 14:15:05.897:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Starting Thread[qtp4599696-11-selector-0,5,main] on org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=0 selected=0
2013-07-15 14:15:05.899:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop waiting on select
2013-07-15 14:15:05.900:DBUG:oejuc.AbstractLifeCycle:main: STARTED org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=0 selected=0
2013-07-15 14:15:05.901:DBUG:oejut.QueuedThreadPool:main: qtp4599696{STARTED,8<=8<=200,i=7,q=0} dispatched org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=0 selected=0
2013-07-15 14:15:05.902:DBUG:oejuc.AbstractLifeCycle:main: STARTED org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@124e205
2013-07-15 14:15:05.902:DBUG:oeji.SelectorManager:qtp4599696-13-selector-1: Starting Thread[qtp4599696-13-selector-1,5,main] on org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=0 selected=0
2013-07-15 14:15:05.903:DBUG:oeji.SelectorManager:qtp4599696-13-selector-1: Selector loop waiting on select
2013-07-15 14:15:05.907:DBUG:oejut.QueuedThreadPool:main: qtp4599696{STARTED,8<=8<=200,i=6,q=0} dispatched org.eclipse.jetty.server.AbstractConnector$Acceptor@57607d
2013-07-15 14:15:05.908:INFO:oejs.ServerConnector:main: Started ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}
2013-07-15 14:15:05.908:DBUG:oejuc.AbstractLifeCycle:main: STARTED ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}
2013-07-15 14:15:05.909:DBUG:oejuc.AbstractLifeCycle:main: STARTED org.eclipse.jetty.server.Server@13968f1
suported cipher suites: [TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_SHA, TLS_ECDH_ECDSA_WITH_RC4_128_SHA, TLS_ECDH_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, TLS_DH_anon_WITH_AES_256_CBC_SHA256, TLS_ECDH_anon_WITH_AES_256_CBC_SHA, TLS_DH_anon_WITH_AES_256_CBC_SHA, TLS_DH_anon_WITH_AES_128_CBC_SHA256, TLS_ECDH_anon_WITH_AES_128_CBC_SHA, TLS_DH_anon_WITH_AES_128_CBC_SHA, TLS_ECDH_anon_WITH_RC4_128_SHA, SSL_DH_anon_WITH_RC4_128_MD5, TLS_ECDH_anon_WITH_3DES_EDE_CBC_SHA, SSL_DH_anon_WITH_3DES_EDE_CBC_SHA, TLS_RSA_WITH_NULL_SHA256, TLS_ECDHE_ECDSA_WITH_NULL_SHA, TLS_ECDHE_RSA_WITH_NULL_SHA, SSL_RSA_WITH_NULL_SHA, TLS_ECDH_ECDSA_WITH_NULL_SHA, TLS_ECDH_RSA_WITH_NULL_SHA, TLS_ECDH_anon_WITH_NULL_SHA, SSL_RSA_WITH_NULL_MD5, SSL_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_DH_anon_WITH_DES_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_DH_anon_EXPORT_WITH_RC4_40_MD5, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_DH_anon_EXPORT_WITH_DES40_CBC_SHA, TLS_KRB5_WITH_RC4_128_SHA, TLS_KRB5_WITH_RC4_128_MD5, TLS_KRB5_WITH_3DES_EDE_CBC_SHA, TLS_KRB5_WITH_3DES_EDE_CBC_MD5, TLS_KRB5_WITH_DES_CBC_SHA, TLS_KRB5_WITH_DES_CBC_MD5, TLS_KRB5_EXPORT_WITH_RC4_40_SHA, TLS_KRB5_EXPORT_WITH_RC4_40_MD5, TLS_KRB5_EXPORT_WITH_DES_CBC_40_SHA, TLS_KRB5_EXPORT_WITH_DES_CBC_40_MD5]
2013-07-15 14:15:05.931:DBUG:oeji.SelectorManager:qtp4599696-15-acceptor-0-ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}: Queued change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@1e03c55
2013-07-15 14:15:05.933:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop woken up from select, 0/0 selected
2013-07-15 14:15:05.933:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Running change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@1e03c55
2013-07-15 14:15:06.005:DBUG:oeji.AbstractEndPoint:qtp4599696-11-selector-0: onOpen SelectChannelEndPoint@1f30ea7{/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{null}{io=0,kio=0,kro=0}
2013-07-15 14:15:06.009:DBUG:oeji.IdleTimeout:qtp4599696-11-selector-0: SelectChannelEndPoint@1f30ea7{/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{null}{io=0,kio=0,kro=0} idle timeout check, elapsed: 36 ms, remaining: 29964 ms
2013-07-15 14:15:06.060:DBUG:oeji.IdleTimeout:qtp4599696-11-selector-0: DecryptedEndPoint@18d859a{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@3e7799{false,null},wf=WriteFlusher@11e03e3{IDLE},it=30000}{null}->SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{null}{io=0,kio=0,kro=0} idle timeout check, elapsed: 2 ms, remaining: 29998 ms
2013-07-15 14:15:06.220:DBUG:oejs.HttpConnection:qtp4599696-11-selector-0: New HTTP Connection HttpConnection@c017d{IDLE},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.229:DBUG:oeji.AbstractConnection:qtp4599696-11-selector-0: onOpen SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{IDLE},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.231:DBUG:oeji.AbstractConnection:qtp4599696-11-selector-0: onOpen HttpConnection@c017d{IDLE},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.232:DBUG:oeji.AbstractConnection:qtp4599696-11-selector-0: fillInterested HttpConnection@c017d{IDLE},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.235:DBUG:oeji.AbstractConnection:qtp4599696-11-selector-0: fillInterested SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.236:DBUG:oeji.SelectChannelEndPoint:qtp4599696-11-selector-0: Local interests updated 0 -> 1 for SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{true,AC.ExReadCB@10ec1a3},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=1,kio=0,kro=0}
2013-07-15 14:15:06.239:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Created SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{true,AC.ExReadCB@10ec1a3},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=1,kio=0,kro=0}
2013-07-15 14:15:06.243:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@ea2352
2013-07-15 14:15:06.243:DBUG:oeji.SelectChannelEndPoint:qtp4599696-11-selector-0: Key interests updated 0 -> 1
2013-07-15 14:15:06.244:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop waiting on select
2013-07-15 14:15:06.258:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop woken up from select, 1/1 selected
2013-07-15 14:15:06.259:DBUG:oeji.SelectChannelEndPoint:qtp4599696-11-selector-0: Key interests updated 1 -> 0
2013-07-15 14:15:06.259:DBUG:oeji.SelectChannelEndPoint:qtp4599696-11-selector-0: Local interests updated 1 -> 0 for SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{true,AC.ExReadCB@10ec1a3},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.261:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@ea2352
2013-07-15 14:15:06.262:DBUG:oejis.SslConnection:qtp4599696-11-selector-0: onFillable enter SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.265:DBUG:oejut.QueuedThreadPool:qtp4599696-11-selector-0: qtp4599696{STARTED,8<=8<=200,i=5,q=0} dispatched AC.ExReadCB@c017d
2013-07-15 14:15:06.265:DBUG:oejs.HttpConnection:qtp4599696-17: HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} onFillable org.eclipse.jetty.server.HttpChannelState@1b505fe@IDLE,initial
2013-07-15 14:15:06.265:DBUG:oejis.SslConnection:qtp4599696-11-selector-0: onFillable exit SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.269:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop waiting on select
2013-07-15 14:15:06.272:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} fill enter
2013-07-15 14:15:06.274:DBUG:oeji.ChannelEndPoint:qtp4599696-17: filled 168 SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=18264/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.277:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=168/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} filled 168 encrypted bytes
2013-07-15 14:15:06.283:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_TASK,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} unwrap Status = OK HandshakeStatus = NEED_TASK
bytesConsumed = 168 bytesProduced = 0
get server alias for keytype 'EC_EC'
get server alias for keytype 'RSA'
get private key for alias 'server'
get certificate chain for alias 'server'
2013-07-15 14:15:06.337:DBUG:oeji.ChannelEndPoint:qtp4599696-17: filled 0 SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_WRAP,eio=18432/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.340:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} filled 0 encrypted bytes
2013-07-15 14:15:06.341:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} unwrap Status = OK HandshakeStatus = NEED_WRAP
bytesConsumed = 0 bytesProduced = 0
2013-07-15 14:15:06.343:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} flush enter [java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]]
2013-07-15 14:15:06.345:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=0/17524,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} wrap Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 908
2013-07-15 14:15:06.347:DBUG:oejis.SslConnection:qtp4599696-17: DecryptedEndPoint@18d859a{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@3e7799{false,null},wf=WriteFlusher@11e03e3{IDLE},it=30000}{HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}->SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=0/908,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1} OK HeapByteBuffer@98212[p=0,l=908,c=18432,r=908]={<<<????????M??Q???j?...?|??????@??????>>>?????????????????...???????????????}
2013-07-15 14:15:06.357:DBUG:oeji.ChannelEndPoint:qtp4599696-17: flushed 908 SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=0/0,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.359:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=0/0,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} flush exit, consumed 0
2013-07-15 14:15:06.360:DBUG:oeji.ChannelEndPoint:qtp4599696-17: filled 0 SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=18432/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.362:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} filled 0 encrypted bytes
2013-07-15 14:15:06.363:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2013-07-15 14:15:06.365:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} fill exit
2013-07-15 14:15:06.365:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} fill enter
2013-07-15 14:15:06.367:DBUG:oeji.ChannelEndPoint:qtp4599696-17: filled 0 SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=18432/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.369:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} filled 0 encrypted bytes
2013-07-15 14:15:06.370:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2013-07-15 14:15:06.371:DBUG:oejis.SslConnection:qtp4599696-17: SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} fill exit
2013-07-15 14:15:06.372:DBUG:oejs.HttpConnection:qtp4599696-17: HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} filled 0
2013-07-15 14:15:06.373:DBUG:oeji.AbstractConnection:qtp4599696-17: fillInterested HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.374:DBUG:oeji.AbstractConnection:qtp4599696-17: fillInterested SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.375:DBUG:oeji.SelectChannelEndPoint:qtp4599696-17: Local interests updated 0 -> 1 for SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{true,AC.ExReadCB@10ec1a3},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=1,kio=0,kro=1}
2013-07-15 14:15:06.377:DBUG:oeji.SelectorManager:qtp4599696-17: Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@ea2352
2013-07-15 14:15:06.378:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop woken up from select, 0/1 selected
2013-07-15 14:15:06.378:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@ea2352
2013-07-15 14:15:06.379:DBUG:oeji.SelectChannelEndPoint:qtp4599696-11-selector-0: Key interests updated 0 -> 1
2013-07-15 14:15:06.379:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop waiting on select
check server trusted for auth type ECDHE_RSA
get client alias for keytype '[RSA, DSA, EC]'
2013-07-15 14:15:06.977:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop woken up from select, 1/1 selected
2013-07-15 14:15:06.977:DBUG:oeji.SelectChannelEndPoint:qtp4599696-11-selector-0: Key interests updated 1 -> 0
2013-07-15 14:15:06.978:DBUG:oeji.SelectChannelEndPoint:qtp4599696-11-selector-0: Local interests updated 1 -> 0 for SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{true,AC.ExReadCB@10ec1a3},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.980:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@ea2352
2013-07-15 14:15:06.981:DBUG:oejis.SslConnection:qtp4599696-11-selector-0: onFillable enter SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{INTERESTED},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.982:DBUG:oejut.QueuedThreadPool:qtp4599696-11-selector-0: qtp4599696{STARTED,8<=8<=200,i=5,q=0} dispatched AC.ExReadCB@c017d
2013-07-15 14:15:06.983:DBUG:oejs.HttpConnection:qtp4599696-18: HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} onFillable org.eclipse.jetty.server.HttpChannelState@1b505fe@IDLE,initial
2013-07-15 14:15:06.983:DBUG:oejis.SslConnection:qtp4599696-11-selector-0: onFillable exit SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.985:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop waiting on select
2013-07-15 14:15:06.984:DBUG:oejis.SslConnection:qtp4599696-18: SslConnection@10ec1a3{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} fill enter
2013-07-15 14:15:06.986:DBUG:oeji.ChannelEndPoint:qtp4599696-18: filled 82 SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_UNWRAP,eio=18350/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.989:DBUG:oejis.SslConnection:qtp4599696-18: SslConnection@10ec1a3{NEED_UNWRAP,eio=82/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} filled 82 encrypted bytes
2013-07-15 14:15:06.990:DBUG:oejis.SslConnection:qtp4599696-18: SslConnection@10ec1a3{NEED_TASK,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} unwrap Status = OK HandshakeStatus = NEED_TASK
bytesConsumed = 82 bytesProduced = 0
2013-07-15 14:15:06.992:DBUG:oeji.ChannelEndPoint:qtp4599696-18: filled 0 SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=true,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_WRAP,eio=18432/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.994:DBUG:oejis.SslConnection:qtp4599696-18: SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} filled 0 encrypted bytes
2013-07-15 14:15:06.996:DBUG:oeji.ChannelEndPoint:qtp4599696-18: close SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=false,is=false,os=false,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=0,kro=1}
2013-07-15 14:15:06.018:DBUG:oeji.SelectorManager:qtp4599696-18: Destroyed SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=false,is=true,os=true,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=-1,kro=-1}
2013-07-15 14:15:06.025:DBUG:oeji.AbstractConnection:qtp4599696-18: onClose HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.025:DBUG:oeji.AbstractConnection:qtp4599696-18: onClose SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}
2013-07-15 14:15:06.029:DBUG:oeji.AbstractEndPoint:qtp4599696-18: onClose SelectChannelEndPoint@1f30ea7{POLLY.lobster.de/192.168.213.183:52761<r-l>/192.168.213.192:12345,o=false,is=true,os=true,fi=FillInterest@46f6f0{false,null},wf=WriteFlusher@fe464e{IDLE},it=30000}{SslConnection@10ec1a3{NEED_WRAP,eio=0/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0}}{io=0,kio=-1,kro=-1}
2013-07-15 14:15:06.030:DBUG:oejis.SslConnection:qtp4599696-18: SslConnection@10ec1a3{NEED_WRAP,eio=-1/-1,di=-1} -> HttpConnection@c017d{FILLING},g=HttpGenerator{s=START},p=HttpParser{s=START,0 of 0} fill exit
2013-07-15 14:15:06.031:DBUG:oejs.HttpConnection:qtp4599696-18: 
org.eclipse.jetty.io.EofException
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:634)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:236)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:596)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:527)
	at java.lang.Thread.run(Thread.java:722)
Caused by: 
javax.net.ssl.SSLHandshakeException: null cert chain
	at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1362)
	at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:513)
	at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:790)
	at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:758)
	at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:506)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:236)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:596)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:527)
	at java.lang.Thread.run(Thread.java:722)
Caused by: 
javax.net.ssl.SSLHandshakeException: null cert chain
	at sun.security.ssl.Alerts.getSSLException(Alerts.java:192)
	at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1619)
	at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:278)
	at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:266)
	at sun.security.ssl.ServerHandshaker.clientCertificate(ServerHandshaker.java:1631)
	at sun.security.ssl.ServerHandshaker.processMessage(ServerHandshaker.java:176)
	at sun.security.ssl.Handshaker.processLoop(Handshaker.java:868)
	at sun.security.ssl.Handshaker$1.run(Handshaker.java:808)
	at sun.security.ssl.Handshaker$1.run(Handshaker.java:806)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1299)
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:587)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:236)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:596)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:527)
	at java.lang.Thread.run(Thread.java:722)
2013-07-15 14:15:11.740:DBUG:oejuc.AbstractLifeCycle:main: stopping org.eclipse.jetty.server.Server@13968f1
2013-07-15 14:15:11.741:DBUG:oejs.ServerConnector:qtp4599696-15-acceptor-0-ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}: 
java.nio.channels.AsynchronousCloseException
	at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:205)
	at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:233)
	at org.eclipse.jetty.server.ServerConnector.accept(ServerConnector.java:284)
	at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:460)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:596)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:527)
	at java.lang.Thread.run(Thread.java:722)
2013-07-15 14:15:11.743:DBUG:oejs.Server:main: Graceful shutdown org.eclipse.jetty.server.Server@13968f1 by  Mon Jul 15 14:15:41 CEST 2013
2013-07-15 14:15:11.746:DBUG:oejuc.AbstractLifeCycle:main: stopping ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}
2013-07-15 14:15:11.746:DBUG:oejuc.AbstractLifeCycle:main: stopping org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@124e205
2013-07-15 14:15:11.746:DBUG:oejuc.AbstractLifeCycle:main: stopping org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=1 selected=0
2013-07-15 14:15:11.746:DBUG:oeji.SelectorManager:main: Stopping org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=1 selected=0
2013-07-15 14:15:11.749:DBUG:oeji.SelectorManager:main: Queued change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Stop@1252d43
2013-07-15 14:15:11.749:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Selector loop woken up from select, 0/0 selected
2013-07-15 14:15:11.749:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Running change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Stop@1252d43
2013-07-15 14:15:11.750:DBUG:oeji.SelectorManager:main: Stopped org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=-1 selected=-1
2013-07-15 14:15:11.750:DBUG:oeji.SelectorManager:qtp4599696-11-selector-0: Stopped Thread[qtp4599696-11-selector-0,5,main] on org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=-1 selected=-1
2013-07-15 14:15:11.750:DBUG:oejuc.AbstractLifeCycle:main: STOPPED org.eclipse.jetty.io.SelectorManager$ManagedSelector@1ba1558 keys=-1 selected=-1
2013-07-15 14:15:11.751:DBUG:oejuc.AbstractLifeCycle:main: stopping org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=0 selected=0
2013-07-15 14:15:11.751:DBUG:oeji.SelectorManager:main: Stopping org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=0 selected=0
2013-07-15 14:15:11.751:DBUG:oeji.SelectorManager:main: Queued change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Stop@1be8a4b
2013-07-15 14:15:11.751:DBUG:oeji.SelectorManager:qtp4599696-13-selector-1: Selector loop woken up from select, 0/0 selected
2013-07-15 14:15:11.751:DBUG:oeji.SelectorManager:qtp4599696-13-selector-1: Running change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Stop@1be8a4b
2013-07-15 14:15:11.752:DBUG:oeji.SelectorManager:qtp4599696-13-selector-1: Stopped Thread[qtp4599696-13-selector-1,5,main] on org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=-1 selected=-1
2013-07-15 14:15:11.752:DBUG:oeji.SelectorManager:main: Stopped org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=-1 selected=-1
2013-07-15 14:15:11.752:DBUG:oejuc.AbstractLifeCycle:main: STOPPED org.eclipse.jetty.io.SelectorManager$ManagedSelector@1c8ee34 keys=-1 selected=-1
2013-07-15 14:15:11.752:DBUG:oejuc.AbstractLifeCycle:main: STOPPED org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@124e205
2013-07-15 14:15:11.753:DBUG:oejuc.AbstractLifeCycle:main: stopping HttpConnectionFactory@edeea8{HTTP/1.1}
2013-07-15 14:15:11.753:DBUG:oejuc.AbstractLifeCycle:main: STOPPED HttpConnectionFactory@edeea8{HTTP/1.1}
2013-07-15 14:15:11.753:DBUG:oejuc.AbstractLifeCycle:main: stopping SslConnectionFactory@1fc0f04{SSL-http/1.1}
2013-07-15 14:15:11.753:DBUG:oejuc.AbstractLifeCycle:main: stopping TestSSLContextFactory@13ded59(null,null)
2013-07-15 14:15:11.753:DBUG:oejuc.AbstractLifeCycle:main: STOPPED TestSSLContextFactory@13ded59(null,null)
2013-07-15 14:15:11.754:DBUG:oejuc.AbstractLifeCycle:main: STOPPED SslConnectionFactory@1fc0f04{SSL-http/1.1}
2013-07-15 14:15:11.754:DBUG:oejuc.AbstractLifeCycle:main: stopping org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@ac706a
2013-07-15 14:15:11.754:DBUG:oejuc.AbstractLifeCycle:main: STOPPED org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@ac706a
2013-07-15 14:15:11.754:INFO:oejs.ServerConnector:main: Stopped ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}
2013-07-15 14:15:11.754:DBUG:oejuc.AbstractLifeCycle:main: STOPPED ServerConnector@2083d{SSL-http/1.1}{0.0.0.0:12345}
2013-07-15 14:15:11.755:DBUG:oejsh.AbstractHandler:main: stopping org.eclipse.jetty.server.Server@13968f1
2013-07-15 14:15:11.755:DBUG:oejuc.AbstractLifeCycle:main: stopping org.eclipse.jetty.server.handler.ContextHandlerCollection@c21d01
2013-07-15 14:15:11.755:DBUG:oejsh.AbstractHandler:main: stopping org.eclipse.jetty.server.handler.ContextHandlerCollection@c21d01
2013-07-15 14:15:11.755:DBUG:oejuc.AbstractLifeCycle:main: STOPPED org.eclipse.jetty.server.handler.ContextHandlerCollection@c21d01
2013-07-15 14:15:11.755:DBUG:oejuc.AbstractLifeCycle:main: stopping qtp4599696{STARTED,8<=8<=200,i=8,q=0}
2013-07-15 14:15:11.759:DBUG:oejuc.AbstractLifeCycle:main: STOPPED qtp4599696{STOPPED,8<=0<=200,i=0,q=0}
2013-07-15 14:15:11.759:DBUG:oejuc.AbstractLifeCycle:main: STOPPED org.eclipse.jetty.server.Server@13968f1

Attachment: jetty9_bugtrace.pcap
Description: Binary data

import java.io.IOException;
import java.math.BigInteger;
import java.net.ServerSocket;
import java.net.Socket;
import java.security.InvalidKeyException;
import java.security.KeyPair;
import java.security.KeyPairGenerator;
import java.security.KeyStore;
import java.security.KeyStoreException;
import java.security.NoSuchAlgorithmException;
import java.security.NoSuchProviderException;
import java.security.Principal;
import java.security.PrivateKey;
import java.security.Security;
import java.security.SignatureException;
import java.security.cert.CRL;
import java.security.cert.Certificate;
import java.security.cert.CertificateException;
import java.security.cert.CertificateExpiredException;
import java.security.cert.CertificateNotYetValidException;
import java.security.cert.X509Certificate;
import java.util.Arrays;
import java.util.Collection;
import java.util.Date;
import java.util.Vector;

import javax.net.ssl.KeyManager;
import javax.net.ssl.SSLContext;
import javax.net.ssl.SSLEngine;
import javax.net.ssl.SSLHandshakeException;
import javax.net.ssl.SSLSocket;
import javax.net.ssl.SSLSocketFactory;
import javax.net.ssl.TrustManager;
import javax.net.ssl.X509ExtendedKeyManager;
import javax.net.ssl.X509TrustManager;

import org.bouncycastle.asn1.x509.ExtendedKeyUsage;
import org.bouncycastle.asn1.x509.KeyPurposeId;
import org.bouncycastle.asn1.x509.KeyUsage;
import org.bouncycastle.asn1.x509.X509Extensions;
import org.bouncycastle.jce.X509Principal;
import org.bouncycastle.jce.provider.BouncyCastleProvider;
import org.bouncycastle.x509.X509V3CertificateGenerator;
import org.eclipse.jetty.server.ConnectionFactory;
import org.eclipse.jetty.server.HttpConnectionFactory;
import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.server.ServerConnector;
import org.eclipse.jetty.server.SslConnectionFactory;
import org.eclipse.jetty.server.handler.ContextHandlerCollection;
import org.eclipse.jetty.util.log.Log;
import org.eclipse.jetty.util.log.StdErrLog;
import org.eclipse.jetty.util.ssl.SslContextFactory;

import junit.framework.TestCase;

/**
 * Class showing the bug in Jetty 9.0.3 (at least) when trying
 * to connect to a server being configured to require client certificates.
 * @author "Lothar Kimmeringer" &lt;job@xxxxxxxxxxxxxx>
 *
 */
public class __Test_Jetty9ClientAuthBug extends TestCase {
    private KeyStore keyStore;
    private KeyManager keyManager;
    private X509TrustManager trustManager;
    private Server server;
    private int port;
    private StdErrLog logger = new StdErrLog();
    
    @Override
    protected void setUp() throws Exception {
        logger.setDebugEnabled(false);
        Log.setLog(logger);
        Security.addProvider(new BouncyCastleProvider());
        ServerSocket ss = new ServerSocket(0);
        port = ss.getLocalPort();
        ss.close();
    }
    
    @Override
    protected void tearDown() throws Exception {
        try{
            server.stop();
        }
        catch(Exception e){
            // ignore
        }
    }

    public void testSslStandardConnection() throws Exception {
        TestSSLContextFactory conn = createServer(false, false);
        assertEquals("check status is started", true, conn.isStarted());
        
        SSLContext servercontext = conn.getSslContext();
        SSLSocketFactory fac = servercontext.getSocketFactory();
        System.err.println("suported cipher suites: " + Arrays.asList(fac.getSupportedCipherSuites()).toString());
        SSLSocket ssl = (SSLSocket) fac.createSocket("127.0.0.1", port);
        assertEquals("check connected", true, ssl.isConnected());
        ssl.setSoTimeout(120000);
        ssl.setUseClientMode(true);
        ssl.startHandshake();
        javax.security.cert.X509Certificate[] certs = ssl.getSession().getPeerCertificateChain();
        assertNotNull("check existance of returned chain", certs);
        assertEquals("check number of elements", 2, certs.length);
        assertEquals("check element subject", "CN=server", String.valueOf(certs[0].getSubjectDN()));
        assertEquals("check element subject", "CN=root", String.valueOf(certs[1].getSubjectDN()));
        assertNull("check non-existance of local certificates", ssl.getSession().getLocalCertificates());
        ssl.close();
    }

    public void testSslCAuthNeededConnection() throws Exception {
        TestSSLContextFactory conn = createServer(true, false);
        assertEquals("check status is started", true, conn.isStarted());
        
        SSLContext servercontext = conn.getSslContext();
        SSLSocketFactory fac = servercontext.getSocketFactory();
        System.err.println("suported cipher suites: " + Arrays.asList(fac.getSupportedCipherSuites()).toString());
        SSLSocket ssl = (SSLSocket) fac.createSocket("127.0.0.1", port);
        assertEquals("check connected", true, ssl.isConnected());
        ssl.setSoTimeout(5000);
        ssl.setUseClientMode(true);
        try{
            ssl.startHandshake();
            fail("exception expected");
        }
        catch(SSLHandshakeException she){
            // expected
        }
        javax.security.cert.X509Certificate[] certs = ssl.getSession().getPeerCertificateChain();
        assertNotNull("check existance of returned chain", certs);
        assertEquals("check number of elements", 2, certs.length);
        assertEquals("check element subject", "CN=server", String.valueOf(certs[0].getSubjectDN()));
        assertEquals("check element subject", "CN=root", String.valueOf(certs[1].getSubjectDN()));
        assertNull("check non-existance of local certificates", ssl.getSession().getLocalCertificates());
        ssl.close();
    }

    private TestSSLContextFactory createServer(boolean needClientAuth, boolean wantClientAuth) throws Exception {
        logger.setDebugEnabled(true);
        TestSSLContextFactory conn = new TestSSLContextFactory();
        conn.setNeedClientAuth(needClientAuth);
        conn.setWantClientAuth(wantClientAuth);
        server = new Server();
        ServerConnector sconn = new ServerConnector(server, new ConnectionFactory[]{
                new SslConnectionFactory(conn, "http/1.1"),
                new HttpConnectionFactory(),
        });
        sconn.setPort(port);
        server.addConnector(sconn);
        ContextHandlerCollection coll = new ContextHandlerCollection();
        server.setHandler(coll);
        
        server.start();
        return conn;
    }

    /**
     * Helper class providing the needed certficates for the server
     * @author "Lothar Kimmeringer" &lt;job@xxxxxxxxxxxxxx>
     *
     */
    private class TestSSLContextFactory extends SslContextFactory {

        @Override
        protected void doStart() throws Exception {
            performKeystoreCreation();
            super.doStart();
        }

        private void performKeystoreCreation() throws KeyStoreException,
                IOException, NoSuchAlgorithmException, CertificateException,
                NoSuchProviderException, SignatureException,
                InvalidKeyException, CertificateExpiredException,
                CertificateNotYetValidException {
            if (keyStore != null){
                return;
            }
            System.err.println("create test keystore");
            keyStore = KeyStore.getInstance("JKS");
            keyStore.load(null);
            KeyPair caPair = generateKeyPair(512);
            KeyPair serverPair = generateKeyPair(512);
            X509Certificate caCert = generateV3Certificate("CN=root", "CN=root", new Date(System.currentTimeMillis() - 1000000), new Date(System.currentTimeMillis() + 1000000), caPair, caPair, new BigInteger("1"), true, true, true, true);
            X509Certificate serverCert =generateV3Certificate("CN=root", "CN=server", new Date(System.currentTimeMillis() - 1000000), new Date(System.currentTimeMillis() + 1000000), serverPair, caPair, new BigInteger("c113", 16), true, true, true, true);
            keyStore.setKeyEntry("server", serverPair.getPrivate(), new char[0], new Certificate[]{serverCert, caCert});
            System.err.println("create test keymanager");
            keyManager = new X509ExtendedKeyManager() {
                
                public String[] getServerAliases(String keyType, Principal[] arg1) {
                    System.err.println("get server aliases for type '" + keyType + "'");
                    if (!keyType.equals("RSA")){
                        return null;
                    }
                    return new String[]{"server"};
                }
                
                public PrivateKey getPrivateKey(String alias) {
                    try{
                        System.err.println("get private key for alias '" + alias + "'");
                        return (PrivateKey) keyStore.getKey(alias, new char[0]);
                    }
                    catch(Exception e){
                        e.printStackTrace();
                    }
                    return null;
                }
                
                public String[] getClientAliases(String keyType, Principal[] arg1) {
                    System.err.println("get client aliases for keytype '" + keyType + "'");
                    return new String[0];
                }
                
                public X509Certificate[] getCertificateChain(String alias) {
                    System.err.println("get certificate chain for alias '" + alias + "'");
                    Certificate[] certs;
                    try{
                        certs = keyStore.getCertificateChain(alias);
                    }
                    catch(Exception e){
                        e.printStackTrace();
                        return null;
                    }
                    if (certs == null){
                        return null;
                    }
                    X509Certificate[] ret = new X509Certificate[certs.length];
                    System.arraycopy(certs, 0, ret, 0, ret.length);
                    return ret;
                }
                
                public String chooseServerAlias(String keyType, Principal[] arg1, Socket arg2) {
                    System.err.println("get server alias for keytype '" + keyType + "'");
                    if (!keyType.equalsIgnoreCase("RSA")){
                        return null;
                    }
                    return "server";
                }
                
                public String chooseClientAlias(String[] keyType, Principal[] arg1, Socket arg2) {
                    System.err.println("get client alias for keytype '" + Arrays.asList(keyType).toString() + "'");
                    return null;
                }

                @Override
                public String chooseEngineClientAlias(String[] arg0, Principal[] arg1, SSLEngine arg2) {
                    return chooseClientAlias(arg0, arg1, null);
                }

                @Override
                public String chooseEngineServerAlias(String arg0, Principal[] arg1, SSLEngine arg2) {
                    return chooseServerAlias(arg0, arg1, null);
                }
                
            };
            trustManager = new X509TrustManager() {
                
                public X509Certificate[] getAcceptedIssuers() {
                    return new X509Certificate[0];
                }
                
                public void checkServerTrusted(X509Certificate[] arg0, String authType) throws CertificateException {
                    System.err.println("check server trusted for auth type " + authType);
                }
                
                public void checkClientTrusted(X509Certificate[] arg0, String authType) throws CertificateException {
                    System.err.println("check server trusted for auth type " + authType);
                }
            };
            setKeyStore(keyStore);
            setTrustStore(keyStore);
            setCertAlias("server");
        }

        @Override
        protected KeyManager[] getKeyManagers(KeyStore arg0) throws Exception {
            System.err.println("get key manager for keystore " + arg0);
            performKeystoreCreation();
            return new KeyManager[]{keyManager};
        }

        @Override
        protected TrustManager[] getTrustManagers(KeyStore arg0, Collection<? extends CRL> arg1) throws Exception {
            System.err.println("get trust manager for keystore " + arg0);
            performKeystoreCreation();
            return new TrustManager[]{trustManager};
        }

        @Override
        protected KeyStore loadKeyStore() throws Exception {
            performKeystoreCreation();
            return keyStore;
        }

        @Override
        protected KeyStore loadTrustStore() throws Exception {
            performKeystoreCreation();
            return keyStore;
        }
        
        private KeyPair generateKeyPair(int size) throws NoSuchProviderException, NoSuchAlgorithmException{
            KeyPairGenerator gen = KeyPairGenerator.getInstance("RSA", BouncyCastleProvider.PROVIDER_NAME);
            gen.initialize(size);
            return gen.generateKeyPair();
        }
        
        private X509Certificate generateV3Certificate(String issuerDN, String subjectDN, Date validFrom, Date validTo, KeyPair keyPair, KeyPair sigKeyPair, BigInteger serialNumber, boolean usageSigning, boolean usageEncryption, boolean usageTLSClient, boolean usageTLSServer) throws SecurityException, SignatureException, InvalidKeyException, CertificateExpiredException, CertificateNotYetValidException, CertificateException, NoSuchAlgorithmException, NoSuchProviderException {
            X509V3CertificateGenerator certGen = new X509V3CertificateGenerator();
            certGen.setSerialNumber(serialNumber);
            certGen.setIssuerDN(new X509Principal(issuerDN));
            certGen.setNotBefore(validFrom);
            certGen.setNotAfter(validTo);
            certGen.setSubjectDN(new X509Principal(subjectDN));
            certGen.setPublicKey(keyPair.getPublic());
            certGen.setSignatureAlgorithm("SHA1With" + keyPair.getPublic().getAlgorithm());
            int usage = 0;
            Vector<KeyPurposeId> extendedUsages = new Vector<KeyPurposeId>();
            if (usageEncryption){
                usage |= KeyUsage.dataEncipherment | KeyUsage.keyEncipherment;
            }
            if (usageSigning){
                usage |= KeyUsage.digitalSignature;
                usage |= KeyUsage.keyCertSign;
            }
            if (usageTLSClient){
                extendedUsages.add(KeyPurposeId.id_kp_clientAuth);
            }
            if (usageTLSServer){
                extendedUsages.add(KeyPurposeId.id_kp_serverAuth);
            }
            if (usage != 0){
                certGen.addExtension(X509Extensions.KeyUsage, true, new KeyUsage(usage));
            }
            if (extendedUsages.size() != 0){
                certGen.addExtension(X509Extensions.ExtendedKeyUsage, true, new ExtendedKeyUsage(extendedUsages));
            }

            X509Certificate cert = certGen.generate(sigKeyPair == null ? keyPair.getPrivate() : sigKeyPair.getPrivate());
            cert.checkValidity(new Date());
            cert.verify(sigKeyPair == null ? keyPair.getPublic() : sigKeyPair.getPublic());
            return cert;
        }

    }
}

Back to the top