How can I get debug messages from Java's SSL handshake?-CodePudding

I'm trying to secure a Java Spring Boot REST service with Keycloak. Part of that involves communication between the service and Keycloak to get the well-known OpenID configuration.

When everything is unencrypted (over HTTP), things work fine. When I add an SSL certificate into the mix (technically on an nginx server in front of both services), I'm getting an SSL handshake error.

If I hit the REST service or Keycloak directly with my browser, there's no SSL error reported by the browser. Using curl from the rest server machine to the Keycloak machine looks fine as well, and I've tried having nginx force a TLS 1.2 or 1.3 response.

The error when the actual REST service tries to hit the Keycloak service looks like:

2022-03-21 19:30:59.526  WARN 27 --- [nio-8080-exec-3] o.keycloak.adapters.KeycloakDeployment   : Failed to load URLs from https://.../auth/realms/MyRealm/.well-known/openid-configuration

javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
        at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:131) ~[na:na]
...

I've been looking through a lot of other answers such as this one, but I can't seem to get the service to print any debug information beyond the actual exception. I've tried:

Adding -Djavax.net.debug=ssl to the command line that starts the server
Adding System.setProperty("javax.net.debug", "ssl"); to the main() function of the application
Adding logging.level.javax=TRACE and logging.level.net=TRACE to the application.properties

Nothing seems to get me anywhere. The output still just has the end of the server startup

2022-03-21 19:30:34.219  INFO 27 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-03-21 19:30:34.221  INFO 27 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 2 ms

followed by the error message

2022-03-21 19:30:59.526  WARN 27 --- [nio-8080-exec-3] o.keycloak.adapters.KeycloakDeployment   : Failed to load URLs from https://.../auth/realms/MyRealm/.well-known/openid-configuration

How do I get debugging enabled so I can figure out where the handshake is failing?

---- EDIT ----

Managed to get debug logging on - as comment below suggests, had to add the sub category, e.g.

System.setProperty("javax.net.debug", "ssl:handshake");

That produces a ton of output, I'm not sure I see much of it being helpful:

javax.net.ssl|INFO|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.238 UTC|AlpnExtension.java:182|No available application protocols
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.243 UTC|SSLExtensions.java:260|Ignore, context unavailable extension: application_layer_protocol_negotiation
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.243 UTC|SessionTicketExtension.java:408|Stateless resumption supported
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.244 UTC|SSLExtensions.java:260|Ignore, context unavailable extension: cookie
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.248 UTC|SSLExtensions.java:260|Ignore, context unavailable extension: renegotiation_info
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.248 UTC|PreSharedKeyExtension.java:662|No session to resume.
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.248 UTC|SSLExtensions.java:260|Ignore, context unavailable extension: pre_shared_key
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.250 UTC|ClientHello.java:652|Produced ClientHello handshake message (
"ClientHello": {
  "client version"      : "TLSv1.2",
  "random"              : "53 1B D2 D9 42 52 1C 8F E5 B0 E8 6A 88 0D A5 97 ED 22 83 1B CA C1 D4 26 1B 14 59 84 63 3C 99 5B",
  "session id"          : "4C 90 11 23 81 57 BD B5 AE 68 25 5F 32 E8 75 2B E2 8F A2 85 3A D7 76 4C F9 4C F7 16 5E 7C 02 B0",
  "cipher suites"       : "[TLS_AES_256_GCM_SHA384(0x1302), TLS_AES_128_GCM_SHA256(0x1301), TLS_CHACHA20_POLY1305_SHA256(0x1303), TLS_DHE_RSA_WITH_AES_256_GCM_SHA384(0x009F), TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256(0xCCAA), TLS_DH
E_DSS_WITH_AES_256_GCM_SHA384(0x00A3), TLS_DHE_RSA_WITH_AES_128_GCM_SHA256(0x009E), TLS_DHE_DSS_WITH_AES_128_GCM_SHA256(0x00A2), TLS_DHE_RSA_WITH_AES_256_CBC_SHA256(0x006B), TLS_DHE_DSS_WITH_AES_256_CBC_SHA256(0x006A), TLS_DHE_RSA_W
ITH_AES_128_CBC_SHA256(0x0067), TLS_DHE_DSS_WITH_AES_128_CBC_SHA256(0x0040), TLS_DHE_RSA_WITH_AES_256_CBC_SHA(0x0039), TLS_DHE_DSS_WITH_AES_256_CBC_SHA(0x0038), TLS_DHE_RSA_WITH_AES_128_CBC_SHA(0x0033), TLS_DHE_DSS_WITH_AES_128_CBC_
SHA(0x0032), TLS_RSA_WITH_AES_256_GCM_SHA384(0x009D), TLS_RSA_WITH_AES_128_GCM_SHA256(0x009C), TLS_RSA_WITH_AES_256_CBC_SHA256(0x003D), TLS_RSA_WITH_AES_128_CBC_SHA256(0x003C), TLS_RSA_WITH_AES_256_CBC_SHA(0x0035), TLS_RSA_WITH_AES_
128_CBC_SHA(0x002F), TLS_EMPTY_RENEGOTIATION_INFO_SCSV(0x00FF)]",
  "compression methods" : "00",
  "extensions"          : [
    "server_name (0)": {
      type=host_name (0), value=auth-service.mycompany.com
    },
    "status_request (5)": {
      "certificate status type": ocsp
      "OCSP status request": {
        "responder_id": <empty>
        "request extensions": {
          <empty>
        }
      }
    },
    "supported_groups (10)": {
      "versions": [ffdhe2048, ffdhe3072, ffdhe4096, ffdhe6144, ffdhe8192]
    },
    "ec_point_formats (11)": {
      "formats": [uncompressed]
    },
    "signature_algorithms (13)": {
      "signature schemes": [rsa_pss_rsae_sha256, rsa_pss_rsae_sha384, rsa_pss_rsae_sha512, rsa_pss_pss_sha256, rsa_pss_pss_sha384, rsa_pss_pss_sha512, rsa_pkcs1_sha256, rsa_pkcs1_sha384, rsa_pkcs1_sha512, dsa_sha256, rsa_sha224, dsa
_sha224, rsa_pkcs1_sha1, dsa_sha1]
    },
    "signature_algorithms_cert (50)": {
      "signature schemes": [rsa_pss_rsae_sha256, rsa_pss_rsae_sha384, rsa_pss_rsae_sha512, rsa_pss_pss_sha256, rsa_pss_pss_sha384, rsa_pss_pss_sha512, rsa_pkcs1_sha256, rsa_pkcs1_sha384, rsa_pkcs1_sha512, dsa_sha256, rsa_sha224, dsa
_sha224, rsa_pkcs1_sha1, dsa_sha1]
    },
    "status_request_v2 (17)": {
      "cert status request": {
        "certificate status type": ocsp_multi
        "OCSP status request": {
          "responder_id": <empty>
          "request extensions": {
            <empty>
          }
        }
      }
    },
    "extended_master_secret (23)": {
      <empty>
    },
    "session_ticket (35)": {
      <empty>
    },
    "supported_versions (43)": {
      "versions": [TLSv1.3, TLSv1.2]
    },
    "psk_key_exchange_modes (45)": {
      "ke_modes": [psk_dhe_ke]
    },
    "key_share (51)": {
      "client_shares": [
        {
          "named group": ffdhe2048
          "key_exchange": {
            0000: 8A B0 45 9E 04 62 D4 52   2F 35 E7 60 03 77 ED 8D  ..E..b.R/5.`.w..
            ...
          }
        },
      ]
    }
  ]
}
)
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.252 UTC|Alert.java:238|Received alert message (
"Alert": {
  "level"      : "fatal",
  "description": "handshake_failure"
}
)
javax.net.ssl|ERROR|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.253 UTC|TransportContext.java:361|Fatal (HANDSHAKE_FAILURE): Received fatal alert: handshake_failure (
"throwable" : {
  javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
        at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:131)
...
)
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.253 UTC|SSLSocketImpl.java:1755|close the underlying socket
javax.net.ssl|DEBUG|1C|http-nio-8080-exec-7|2022-03-21 22:37:28.253 UTC|SSLSocketImpl.java:1774|close the SSL connection (initiative)
2022-03-21 22:37:28.255  WARN 26 --- [nio-8080-exec-7] o.keycloak.adapters.KeycloakDeployment   : Failed to load URLs from https://auth-service.mycompany.com/auth/realms/MyRealm/.well-known/openid-configuration

CodePudding user response：

The syntax to enable SSL debugging has apparently changed a little bit. This worked for me:

System.setProperty("javax.net.debug", "ssl:handshake");

Full documentation here.