To whom it may concern: Issue: I encountered a protocol_version SSLException when a remote server rebooted and transitioned from only supporting TLS 1.0 to only supporting TLS 1.2. From my understanding the exception means that a common TLS version could not be negotiated.
I investigated the ClientHello messages using Wireshark and indeed noticed that a TLS 1.0 ClientHello was being sent. What I found strange was that upon restarting the JVM a TLS 1.2 ClientHello was sent to the remote server and the SSL handshake completed successfully. I spent a few hours looking into the source code to understand what might be going on but was unable to find anything conclusive. I did however find some DEBUG level log messages that I think are relevant. Here is the output during the failure: 2017-10-25T03:50:39.437+00:00 floodlight: DEBUG [RequestAddCookies:Slrest-http-285] CookieSpec selected: default 2017-10-25T03:50:39.439+00:00 floodlight: DEBUG [RequestAuthCache:Slrest-http-285] Re-using cached 'basic' auth scheme for https://[fe80::5054:ff:fe32:d659%ens4]:443 2017-10-25T03:50:39.439+00:00 floodlight: DEBUG [PoolingHttpClientConnectionManager:Slrest-http-285] Connection request: [route: {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 50] 2017-10-25T03:50:39.439+00:00 floodlight: DEBUG [PoolingHttpClientConnectionManager:Slrest-http-285] Connection leased: [id: 278][route: {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 50] 2017-10-25T03:50:39.439+00:00 floodlight: DEBUG [MainClientExec:Slrest-http-285] Opening connection {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443 2017-10-25T03:50:39.439+00:00 floodlight: DEBUG [DefaultHttpClientConnectionOperator:Slrest-http-285] Connecting to /fe80:0:0:0:5054:ff:fe32:d659%ens4:443 2017-10-25T03:50:39.440+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-285] Connecting socket to /fe80:0:0:0:5054:ff:fe32:d659%ens4:443 with timeout 2000 2017-10-25T03:50:39.441+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-285] Enabled protocols: [TLSv1, TLSv1.1, TLSv1.2] 2017-10-25T03:50:39.441+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-285] Enabled cipher suites:[TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, ... (redacted for brevity)] 2017-10-25T03:50:39.441+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-285] Starting handshake 2017-10-25T03:50:39.444+00:00 floodlight: DEBUG [DefaultManagedHttpClientConnection:Slrest-http-285] http-outgoing-278: Shutdown connection 2017-10-25T03:50:39.444+00:00 floodlight: DEBUG [MainClientExec:Slrest-http-285] Connection discarded 2017-10-25T03:50:39.444+00:00 floodlight: DEBUG [PoolingHttpClientConnectionManager:Slrest-http-285] Connection released: [id: 278][route: {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 50] Here is the successful output after restarting the JVM: 2017-10-25T03:53:30.245+00:00 floodlight: DEBUG [RequestAddCookies:Slrest-http-3] CookieSpec selected: default 2017-10-25T03:53:30.247+00:00 floodlight: DEBUG [RequestAuthCache:Slrest-http-3] Re-using cached 'basic' auth scheme for https://[fe80::5054:ff:fe32:d659%ens4]:443 2017-10-25T03:53:30.247+00:00 floodlight: DEBUG [PoolingHttpClientConnectionManager:Slrest-http-3] Connection request: [route: {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 50] 2017-10-25T03:53:30.250+00:00 floodlight: DEBUG [DefaultManagedHttpClientConnection:Slrest-http-3] http-outgoing-2: Close connection 2017-10-25T03:53:30.250+00:00 floodlight: DEBUG [PoolingHttpClientConnectionManager:Slrest-http-3] Connection leased: [id: 3][route: {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 50] 2017-10-25T03:53:30.250+00:00 floodlight: DEBUG [MainClientExec:Slrest-http-3] Opening connection {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443 2017-10-25T03:53:30.251+00:00 floodlight: DEBUG [DefaultHttpClientConnectionOperator:Slrest-http-3] Connecting to /fe80:0:0:0:5054:ff:fe32:d659%ens4:443 2017-10-25T03:53:30.251+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-3] Connecting socket to /fe80:0:0:0:5054:ff:fe32:d659%ens4:443 with timeout 2000 2017-10-25T03:53:30.252+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-3] Enabled protocols: [TLSv1, TLSv1.1, TLSv1.2] 2017-10-25T03:53:30.252+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-3] Enabled cipher suites:[TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, .. (redacted for brevity)] 2017-10-25T03:53:30.252+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-3] Starting handshake 2017-10-25T03:53:30.273+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-3] Secure session established 2017-10-25T03:53:30.273+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-3] negotiated protocol: TLSv1.2 2017-10-25T03:53:30.273+00:00 floodlight: DEBUG [SSLConnectionSocketFactory:Slrest-http-3] negotiated cipher suite: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 2017-10-25T03:53:31.117+00:00 floodlight: DEBUG [MainClientExec:Slrest-http-3] Connection can be kept alive indefinitely 2017-10-25T03:53:31.117+00:00 floodlight: DEBUG [HttpAuthenticator:Slrest-http-3] Authentication succeeded 2017-10-25T03:53:31.117+00:00 floodlight: DEBUG [TargetAuthenticationStrategy:Slrest-http-3] Caching 'basic' auth scheme for https://[fe80::5054:ff:fe32:d659%ens4]:443 2017-10-25T03:53:31.119+00:00 floodlight: DEBUG [PoolingHttpClientConnectionManager:Slrest-http-3] Connection [id: 3][route: {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443] can be kept alive indefinitely 2017-10-25T03:53:31.119+00:00 floodlight: DEBUG [PoolingHttpClientConnectionManager:Slrest-http-3] Connection released: [id: 3][route: {s}->https://[fe80::5054:ff:fe32:d659%ens4]:443][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 50] >From the log messages it looks like TLS 1.0, 1.1, and 1.2 are available but still, a ClientHello with version TLS 1.0 is sent. Question: Does HttpClient perform any caching that would explain this behavior? Libraries: HttpCore v4.4.6 + HttpClient v4.5.3 Thanks for your time. -- Jason Parraga --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
