You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by "George S." <ge...@mhsoftware.com> on 2017/10/27 14:55:26 UTC

Tomcat 8.5.23 Initialization PRNG/SSL

I'm seeing some strange ssl errors. They're not reproducible 
consistently, and I think they're because the PRNG is initializing after 
the Connector. Here's some log output:

26-Oct-2017 17:04:08.380 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
26-Oct-2017 17:04:08.429 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["https-jsse-nio-443"]
26-Oct-2017 17:04:08.459 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
26-Oct-2017 17:04:08.492 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 56903 ms
26-Oct-2017 17:05:16.364 WARNING [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [118,978] milliseconds.

The exception is:

javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Unknown Source)
at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.recvAlert(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown Source)
at sun.net.www.protocol.https.HttpsClient.afterConnect(Unknown Source)
at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(Unknown Source)
at sun.net.www.protocol.http.HttpURLConnection.getOutputStream(Unknown Source)
at sun.net.www.protocol.https.HttpsURLConnectionImpl.getOutputStream(Unknown Source)

Has anyone else seen something like this? The app is making an internal 
SSL connection to another servlet. I don't know why they didn't use a 
RequestDispatcher and do .include(), but it's not my code.

Anyhow, am I right that the exception is probably related to the 
connectors coming up before the PRNG?

-- 
George S.
*MH Software, Inc.*
Voice: 303 438 9585
http://www.connectdaily.com

Re: Tomcat 8.5.23 Initialization PRNG/SSL

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

George,

On 10/27/17 10:55 AM, George S. wrote:
> I'm seeing some strange ssl errors. They're not reproducible 
> consistently, and I think they're because the PRNG is initializing
> after the Connector. Here's some log output:
> 
> 26-Oct-2017 17:04:08.380 INFO [main] 
> org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler 
> ["http-nio-8080"] 26-Oct-2017 17:04:08.429 INFO [main] 
> org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler 
> ["https-jsse-nio-443"] 26-Oct-2017 17:04:08.459 INFO [main] 
> org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler 
> ["ajp-nio-8009"] 26-Oct-2017 17:04:08.492 INFO [main] 
> org.apache.catalina.startup.Catalina.start Server startup in 56903
> ms 26-Oct-2017 17:05:16.364 WARNING [localhost-startStop-1] 
> org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom 
> Creation of SecureRandom instance for session ID generation using 
> [SHA1PRNG] took [118,978] milliseconds.
> 
> The exception is:
> 
> javax.net.ssl.SSLHandshakeException: Received fatal alert: 
> handshake_failure at
> com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Unknown
> Source) at
> com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Unknown
> Source) at
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.recvAlert(Unknown
> Source) at
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown
> Source) at 
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(Unk
nown
>
> 
Source)
> at
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown 
> Source) at
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown 
> Source) at
> sun.net.www.protocol.https.HttpsClient.afterConnect(Unknown
> Source) at 
> sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(
Unknown
>
> 
Source)
> at
> sun.net.www.protocol.http.HttpURLConnection.getOutputStream(Unknown
>
> 
Source)
> at 
> sun.net.www.protocol.https.HttpsURLConnectionImpl.getOutputStream(Unkn
own
> Source)
> 
> 
> Has anyone else seen something like this? The app is making an
> internal SSL connection to another servlet. I don't know why they
> didn't use a RequestDispatcher and do .include(), but it's not my
> code.
> 
> Anyhow, am I right that the exception is probably related to the 
> connectors coming up before the PRNG?

These things are not connected -- this is just a coincidence. The
startup time you are seeing is for seeding the secure random-number
generator that produces session identifiers.

The error has to do with TLS cipher suite negotiations: there is
either a mismatch between protocols/cipher suites supported by both
client and server, or you are connecting to a service which requires a
client certificate and none has been provided.

I would scan the service to see what protocols/cipher suites are
actually supported and then check to see what the client has been
configured to support. My experience is that nobody ever bothers to
configure the client, and that the defaults are "connect to
anything!", so this does seem a little odd.

More information is necessary at this point.

- -chris
-----BEGIN PGP SIGNATURE-----
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAln3M2cACgkQHPApP6U8
pFg78w//Y+hte1gG6rS6QC50pdvB1juLW6wD1JIhF/mrc6BPZYjlFhsS5LrJfHSM
Nb65m+9T6ic+LKnRhC8ftWQf4/BY2ZgFqOoWxnYydwa8TANSC43OhhskzKYq/mlR
4yRkQ0mi7tSB0EuF+z15v8y1myWz5RYQ/Eaj+XMjJn0p4mQHocU5QtZ1YxjMM15M
l4oXxAJeUjb6OSotTwv+GaiIfNDICL169pQcDZiUVTEOkONrhDWe0Nfv64u9QWRc
SzLx0zSSJleLuVBI8Uu7IvrB9MUw1HSAOh4bdpcw8b69HTK1Dw7lPA35ACmqzmm1
TbmltyCTLSBPHMb+R3Q71tUAfDTz+1DNPn97Ai5453l1Z/vmwqfo7vyr6tV3P2Zg
Td3XdL1wD3ICiR/z1tgubeGEHUwlljmnaARoHUU6lfLBj/wjVppw/8d3ODCr+kb1
biwNRKj/Tac7abRD/+K/ZUk1K0iPt5cOZBIRuvYr5FmuMQyxalLDikUM7UR5MWiW
mfT8tEubk85D36EfL0nljFGCOFzjpSEmZUC4RzSZTQT/UQjuriPPze8+NvsDIL/1
Jt3uy3fUk0plaPg/0cEs5dhw9dF4XxHsyYjTV/fQXI/HnMR2x8Ct5QmkynPNEnCu
NGTMEhMJL2cYN3fWbVcvUHfHn5uLQpMaUNj3uB3ArECikeDMgJM=
=YzS7
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat 8.5.23 Initialization PRNG/SSL

Posted by "André Warnier (tomcat)" <aw...@ice-sa.com>.
On 27.10.2017 16:55, George S. wrote:
> I'm seeing some strange ssl errors. They're not reproducible consistently, and I think
> they're because the PRNG is initializing after the Connector. Here's some log output:
>
> 26-Oct-2017 17:04:08.380 INFO [main] org.apache.coyote.AbstractProtocol.start Starting
> ProtocolHandler ["http-nio-8080"]
> 26-Oct-2017 17:04:08.429 INFO [main] org.apache.coyote.AbstractProtocol.start Starting
> ProtocolHandler ["https-jsse-nio-443"]
> 26-Oct-2017 17:04:08.459 INFO [main] org.apache.coyote.AbstractProtocol.start Starting
> ProtocolHandler ["ajp-nio-8009"]
> 26-Oct-2017 17:04:08.492 INFO [main] org.apache.catalina.startup.Catalina.start Server
> startup in 56903 ms
> 26-Oct-2017 17:05:16.364 WARNING [localhost-startStop-1]
> org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of
> SecureRandom instance for session ID generation using [SHA1PRNG] took [118,978] milliseconds.

If that means actually 118 thousand 978 milliseconds (just shy of 2 minutes), that looks 
like a lot.  According to the little I have been able to grab while perusing this list, 
that would indicate some serious difficulty for that host in generating sufficient entropy.
Maybe time to read the FAQ :
https://wiki.apache.org/tomcat/HowTo/FasterStartUp
Item 3.

>
> The exception is:
>
> javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
> at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Unknown Source)
> at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Unknown Source)
> at com.sun.net.ssl.internal.ssl.SSLSocketImpl.recvAlert(Unknown Source)
> at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown Source)
> at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(Unknown Source)
> at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown Source)
> at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown Source)
> at sun.net.www.protocol.https.HttpsClient.afterConnect(Unknown Source)
> at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(Unknown Source)
> at sun.net.www.protocol.http.HttpURLConnection.getOutputStream(Unknown Source)
> at sun.net.www.protocol.https.HttpsURLConnectionImpl.getOutputStream(Unknown Source)
>
> Has anyone else seen something like this? The app is making an internal SSL connection to
> another servlet.

That does indeed not seem to make a lot of sense, unless this servlet could possibly be 
running on another server.

I don't know why they didn't use a RequestDispatcher and do .include(),
> but it's not my code.
>
> Anyhow, am I right that the exception is probably related to the connectors coming up
> before the PRNG?
>
Tomcat is starting a Connector ["https-jsse-nio-443"], for which I suppose it also needs 
entropy.  Does the log say when that Connector is actually finished with starting up ?


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org