Debugging TLS Protocol Failures in BC-FIPS and Spring Applications

Debugging TLS protocol failures can be a nightmare.  With JSSE, you can use the old standby java JVM option: 
    -Djavax.net.debug=ssl,handshake,
data,trustmanager,help
 
to get detailed reporting of what is happening.  Usually that provides more than enough (in fact too much) information to debug the protocol problem, but when using BCFIPS, guess what, it doesn't work anymore.  Why? Well, while these command line arguments make debugging easier, they also transmit decrypted information to the console, which is a huge leak of encrypted information.

So, what's a developer to do?

BCFIPS uses java.util.logging to provide reports on protocol failures.  These reports do NOT include decrypted information, but do include enough information to tell you exactly where the protocol failure happened.  But to enable java.util.logging to work with a SpringBoot application using Logback as its logging agent you have to jump through just a few small hoops.

First, you need to include jul-to-slf4j in your dependencies.  This is a bridge between java.util.logging and SLF4J implementations.

        <dependency>
          <groupId>org.slf4j</groupId>
          <artifactId>jul-to-slf4j</artifactId>
        </dependency>

Next you'll need to activate the bridge during application startup.  It's a good idea to do this as early as possible (before bean loading even).

      import org.slf4j.bridge.SLF4JBridgeHandler;

        ...

      public static void main(String ... args) {
          SLF4JBridgeHandler.removeHandlersForRootLogger();
          SLF4JBridgeHandler.install();

          ...

Once you've done all of the above, you will start getting BCFIPS logs reported via Logback.  But Logback and the SLF4J Bridge has a cost, so you want to add a bit of optimization.  You'll want to avoid some of the extra cost by implementing the LevelChangePropagator to propogate LogBack configuration back to JUL so that you don't have to worry about some of the overhead for disabled logging methods. 

<configuration>
  <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator">
    <!-- reset all previous level configurations of all j.u.l. loggers -->
    <resetJUL>true</resetJUL>
  </contextListener>

To enable reporting on protocol errors, 

  <!-- Enable BC Debug Logging by setting level to DEBUG or TRACE -->
  <logger name="org.bouncycastle.jsse.provider" level="INFO"/>

Once you've done all of the above, you will start getting your logs reported to Logback.

I tracked down my problem to an issue with TLS 1.2 Renegotiation, where my client was trying to connect to a server that first allowed the connection, and then renegotiated with client authentication to get to my client certificate.  BCFIPS disables renegotiation by default, to enable it under a limited set of circumstances (that are secure) you can add:
    -Dorg.bouncycastle.jsse.client.acceptRenegotiation=true
to your java command line, or set it in System properties at application startup.