[jboss-jira] [JBoss JIRA] (WFLY-3252) First HTTPS / SSL request after startup of Wildfly 8.0.0.Final is blocked for many seconds

bene.net (JIRA) issues at jboss.org
Mon Apr 14 04:58:34 EDT 2014


     [ https://issues.jboss.org/browse/WFLY-3252?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

bene.net updated WFLY-3252:
---------------------------

    Attachment: server_keystore.jks
                standalone-full.xml


I was able to reproduce the problem on a fresh Windows 7 installation without deploying an own application into Wildfly.
Steps to reproduce:
1) use jre-7u51-windows-i586.exe (I could reproduce with JDK8 as well)
2) use wildfly-8.0.0.Final.zip distribution
3) replace standalone\configuration\standalone-full.xml by attaced file
4) add attached server_keystore.jks to standalone\configuration\
5) Startup Wildfly
6) Startup JConsole
7) Call curl -i -k -X GET "https://localhost:8443"
8) It takes many seconds (even minutes) to get the Wildfly Welcome Page as a response
9) While the call is blocked you can use JConsole to look at the stacktrace. In most cases it is thread "default I/O-3". 

Please note that bouncycastle is used by default. According to the thead
https://community.jboss.org/thread/237897?_sscc=t
the order of JCE providers has changed from WildFly 8.0.0.CR1 to 8.0.0.Final. SunJCE provider is used by default in WildFly 8.0.0.CR1 (I did not test this myself), whereas BouncyCastle is used by default in 8.0.0.Final.

                
> First HTTPS / SSL request after startup of Wildfly 8.0.0.Final is blocked for many seconds
> ------------------------------------------------------------------------------------------
>
>                 Key: WFLY-3252
>                 URL: https://issues.jboss.org/browse/WFLY-3252
>             Project: WildFly
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>    Affects Versions: 8.0.0.Final
>         Environment: Win7, Java 1.7.0_51 and 1.8.0
>            Reporter: bene.net
>            Priority: Critical
>              Labels: Blocked, HTTPS, JAX-RS, Performance, SSL, Start-Up
>         Attachments: server_keystore.jks, standalone-full.xml
>
>
> The first HTTPS / SSL request after startup of Wildfly 8.0.0.Final is blocked for many seconds.
> Please note that subsequent requests perform normally. HTTP requests also perform fine.
> We use curl to call a JAX-RS service (just in case this matters).
> My first thought was, that we had hit the following bug:
> https://issues.jboss.org/browse/XNIO-226?jql=
> However, I can also reproduce the problem with xnio-3.2.2.Final (which contains a fix for bug XNIO-226).
> So I inserted some logging statements in
> {code:title=AbstractAcceptingSslChannel.java}
>         System.out.println("calling createSSLEngine...");
>         long t1 = System.currentTimeMillis();
>         final SSLEngine engine = sslContext.createSSLEngine(JsseSslUtils.getHostNameNoResolve(peerAddress), peerAddress.getPort());
>         long t2 = System.currentTimeMillis();
>         long duration = t2 - t1;
>         System.out.println("createSSLEngine took "+duration+" ms. ");
> {code}
> and in
> {code:title=JsseSslConduitEngine.java}
>                 case NEED_TASK: {
>                     Runnable task;
>                     synchronized (engine) {
>                         // run the tasks needed for handshaking
>                         while ((task = engine.getDelegatedTask()) != null) {
>                             try {
>                                 System.out.println("calling task.run() in handleHandshake...");
>                                 long t1 = System.currentTimeMillis();
>                                 task.run();
>                                 long t2 = System.currentTimeMillis();
>                                 long duration = t2 - t1;
>                                 System.out.println("task.run() in handleHandshake took "+duration+" ms. ");
>                             } catch (Exception e) {
>                                 throw new IOException(e);
>                             }
>                         }
>                     }
>                     // caller should try to wrap/unwrap again
>                     return true;
>                 }
> {code}
> I found out, that sslContext.createSSLEngine in AbstractAcceptingSslChannel.java is quite slow (468ms) but it is not the cause
> for the blocking request. Instead org.xnio.ssl.JsseSslConduitEngine.handleHandshake(JsseSslConduitEngine.java:512) needs
> 95 seconds to return!!!
> Here is the relevant part from my log file:
> {noformat}
> INFO ; 2014-04-11 18:29:52,115; [Controller Boot Thread              ]; JBAS015874: WildFly 8.0.0.Final "WildFly" started in 6477ms - Started 334 of 386 services (107 services are lazy, passive or on-demand); [org.jboss.as.server.BootstrapListener.done(BootstrapListener.java:93)]; ; 
> INFO ; 2014-04-11 18:30:05,566; [default I/O-3                       ]; calling createSSLEngine...
> ; [org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)]; ; 
> INFO ; 2014-04-11 18:30:06,035; [default I/O-3                       ]; createSSLEngine took 468 ms. 
> ; [org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)]; ; 
> INFO ; 2014-04-11 18:30:06,066; [default I/O-3                       ]; calling task.run() in handleHandshake...
> ; [org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)]; ; 
> INFO ; 2014-04-11 18:31:41,128; [default I/O-3                       ]; task.run() in handleHandshake took 95061 ms. 
> ; [org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)]; ; 
> INFO ; 2014-04-11 18:31:41,133; [default I/O-3                       ]; calling task.run() in handleHandshake...
> ; [org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)]; ; 
> INFO ; 2014-04-11 18:31:41,145; [default I/O-3                       ]; task.run() in handleHandshake took 10 ms. 
> ; [org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)]; ; 
> INFO ; 2014-04-11 18:31:41,573; [default task-1                      ]; SecurityFilter received request. ; [de.head.vetsone.rest_ifc.SecurityFilter.filter(SecurityFilter.java:62)]; ; 
> {noformat}
> Using JConsole I could extract the full stacktrace:
> Name: default I/O-2
> State: RUNNABLE
> Total blocked: 0  Total waited: 2
> Stack trace: 
> {noformat}
> java.math.BigInteger.oddModPow(BigInteger.java:2700)
> java.math.BigInteger.modPow(BigInteger.java:2443)
> java.math.BigInteger.passesMillerRabin(BigInteger.java:1019)
> java.math.BigInteger.primeToCertainty(BigInteger.java:875)
> java.math.BitSieve.retrieve(BitSieve.java:203)
> java.math.BigInteger.largePrime(BigInteger.java:744)
> java.math.BigInteger.<init>(BigInteger.java:650)
> org.bouncycastle.crypto.generators.DHParametersHelper.generateSafePrimes(Unknown Source)
> org.bouncycastle.crypto.generators.DHParametersGenerator.generateParameters(Unknown Source)
> org.bouncycastle.jce.provider.JDKKeyPairGenerator$DH.generateKeyPair(Unknown Source)
> sun.security.ssl.DHCrypt.generateDHPublicKeySpec(DHCrypt.java:225)
> sun.security.ssl.DHCrypt.<init>(DHCrypt.java:101)
> sun.security.ssl.ServerHandshaker.setupEphemeralDHKeys(ServerHandshaker.java:1350)
> sun.security.ssl.ServerHandshaker.trySetCipherSuite(ServerHandshaker.java:1194)
> sun.security.ssl.ServerHandshaker.chooseCipherSuite(ServerHandshaker.java:1002)
> sun.security.ssl.ServerHandshaker.clientHello(ServerHandshaker.java:724)
> sun.security.ssl.ServerHandshaker.processMessage(ServerHandshaker.java:213)
> sun.security.ssl.Handshaker.processLoop(Handshaker.java:925)
> sun.security.ssl.Handshaker$1.run(Handshaker.java:865)
> sun.security.ssl.Handshaker$1.run(Handshaker.java:862)
> java.security.AccessController.doPrivileged(Native Method)
> sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1302)
>    - locked sun.security.ssl.SSLEngineImpl at 3f3d2d55
> org.xnio.ssl.JsseSslConduitEngine.handleHandshake(JsseSslConduitEngine.java:512)
>    - locked sun.security.ssl.SSLEngineImpl at 3f3d2d55
> org.xnio.ssl.JsseSslConduitEngine.unwrap(JsseSslConduitEngine.java:595)
> org.xnio.ssl.JsseSslConduitEngine.unwrap(JsseSslConduitEngine.java:543)
> org.xnio.ssl.JsseSslStreamSourceConduit.read(JsseSslStreamSourceConduit.java:89)
> org.xnio.conduits.ConduitStreamSourceChannel.read(ConduitStreamSourceChannel.java:127)
> io.undertow.server.protocol.http.HttpReadListener.handleEvent(HttpReadListener.java:111)
> io.undertow.server.protocol.http.HttpOpenListener.handleEvent(HttpOpenListener.java:69)
> io.undertow.server.protocol.http.HttpOpenListener.handleEvent(HttpOpenListener.java:38)
> org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
> org.xnio.ChannelListeners$10.handleEvent(ChannelListeners.java:291)
> org.xnio.ChannelListeners$10.handleEvent(ChannelListeners.java:286)
> org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
> org.xnio.ChannelListeners$DelegatingChannelListener.handleEvent(ChannelListeners.java:1092)
> org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
> org.xnio.nio.NioTcpServerHandle.handleReady(NioTcpServerHandle.java:53)
> org.xnio.nio.WorkerThread.run(WorkerThread.java:531)
> {noformat}

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira


More information about the jboss-jira mailing list