IAM October 7, 2016 hans No comments

Debugging ISAM Java Runtime SSL handhake issues in WebSphere

This is a repost of a blogpost I made some time ago.  Since the time of originally posting this, the blog has been removed.   The issue described below has to do with IBM’s Federated SSO product – Tivoli Federated Identity Manager – aka TFIM.   Since the release of ISAM v9 (IBM Security Access Manager) most of the Federated SSO functionalities found in TFIM are added to the ISAM appliance.

However the ISAM PD.jar can still be used by other applications (both custom developed, or part of other IBM products).  So someone might still benefit from these pointers.

 

As I was building a TFIM lab environment to perform some testing for a customer issue, I came across a problem where I could not get my TFIM Node configured.

While the installation of TFIM and the domain creation itself went smoothly, the node configuration failed with an FBTCON138E error message on the WebSphere Console.

imageerror_fbtcon138e

The error message reported on the WebSphere console was

An error occurred during the configure operation. If the domain is using Tivoli Access Manager check that the policy server is reachable and that you have provided the correct username and password.

But more useful information can be found in the SystemOut.log of the WAS profile that hosts the TFIM runtime.

In there the error message that caught my attention was:

Caused by:
Wrappered Exception:
javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
[
HPDJA0116E   Cannot contact server.
]
at com.tivoli.pd.jutil.ob.a(ob.java:7)
at com.tivoli.pd.jts.h.b(h.java:6)
at com.tivoli.pd.jts.h.a(h.java:87)
at com.tivoli.pd.jts.e.a(e.java:19)
at com.tivoli.pd.jutil.p$0.run(p$0.java)
at java.security.AccessController.doPrivileged(AccessController.java:327)
at com.tivoli.pd.jutil.p.b(p.java:97)
at com.tivoli.pd.jutil.p.a(p.java:75)
at com.tivoli.pd.jutil.PDContext.c(PDContext.java)
at com.tivoli.pd.jutil.PDContext.<init>(PDContext.java:25)
at com.tivoli.pd.jadmin.PDAppSvrConfig.unconfigureAppSvr(PDAppSvrConfig.java:706)
at com.tivoli.am.fim.rte.util.ConfigureAccessManagerNode.unconfigureSvrSsl(ConfigureAccessManagerNode.java:657)
… 155 more
Caused by: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
at com.ibm.jsse2.o.a(o.java:30)
at com.ibm.jsse2.o.a(o.java:23)
at com.ibm.jsse2.SSLSocketImpl.b(SSLSocketImpl.java:356)
at com.ibm.jsse2.SSLSocketImpl.a(SSLSocketImpl.java:58)
at com.ibm.jsse2.SSLSocketImpl.h(SSLSocketImpl.java:63)
at com.ibm.jsse2.SSLSocketImpl.a(SSLSocketImpl.java:200)
at com.ibm.jsse2.k.write(k.java:11)
at com.tivoli.pd.jts.h.b(h.java:133)
… 165 more

One point to consider here is the versions of the full software stack involved in a TFIM environment.  On the recreate environment I needed to use:

  • ISAM for Web 8.0.1.0
  • WebSphere Application Server 8.0.0.9
  • Tivoli Federated Identity Manager 6.2.2.12

Now what is important here is that ISAM for Web 8.0.1.0  (and 7.0.0.10 – fixpack 10 for the 7.0 version) contain the remediation for CVE-2014-3566 (aka the POODLE attack).  Link to the Security Bulletin – http://www-01.ibm.com/support/docview.wss?uid=swg21691604

A very useful trace parameter for debugging SSL handshake problems (like the entry in the SystemOut.log was indicating) is -Djavax.net.debug=ssl,handshake,

In the Administration Console select Servers
Expand Server Type and select WebSphere application servers
Click on the name of your server
Expand Java and Process Management and select Process Definition.
Under the Additional Properties section, click Java Virtual Machine.
Scroll down and locate the textbox for Generic JVM arguments.

debugssl

After restarting the WAS profile, and running the FIM Node configuration step again, the SystemOut.log starts to log more details about the SSL handshake problem.

Searching for the string ‘handshake_failure’ reveals the relevant parts of the trace:

Is initial handshake: true
[7/2/15 8:12:31:520 EDT] 00000021 SystemOut     O Ignoring unsupported cipher suite: SSL_RSA_WITH_AES_128_CBC_SHA
[7/2/15 8:12:31:520 EDT] 00000021 SystemOut     O Ignoring unsupported cipher suite: SSL_DHE_RSA_WITH_AES_128_CBC_SHA
[7/2/15 8:12:31:520 EDT] 00000021 SystemOut     O Ignoring unsupported cipher suite: SSL_DHE_DSS_WITH_AES_128_CBC_SHA
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O %% No cached client session
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O *** ClientHello, SSLv3
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O RandomCookie:  GMT: 1419061679 bytes = { 100, 31, 207, 208, 107, 152, 131, 240, 200, 204, 32, 9, 182, 55, 4, 176, 243, 187, 223, 49, 69, 24, 231, 203, 176, 244, 233, 182 }
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O Session ID:  {}
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O Cipher Suites: [SSL_RSA_WITH_RC4_128_MD5, SSL_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_FIPS_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_RC4_128_SHA, SSL_RSA_WITH_DES_CBC_SHA, SSL_RSA_FIPS_WITH_DES_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_RENEGO_PROTECTION_REQUEST]
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O Compression Methods:  { 0 }
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O ***
[7/2/15 8:12:31:521 EDT] 00000021 SystemOut     O WebContainer : 0, WRITE: SSLv3 Handshake, length = 75
[7/2/15 8:12:31:522 EDT] 00000021 SystemOut     O WebContainer : 0, READ: TLSv1.2 Alert, length = 2
[7/2/15 8:12:31:522 EDT] 00000021 SystemOut     O WebContainer : 0, RECV TLSv1 ALERT:  fatal, handshake_failure
[7/2/15 8:12:31:522 EDT] 00000021 SystemOut     O WebContainer : 0, called closeSocket()
[7/2/15 8:12:31:522 EDT] 00000021 SystemOut     O WebContainer : 0, handling exception: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
[7/2/15 8:12:31:522 EDT] 00000021 SystemOut     O WebContainer : 0, IOException in getSession():  javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
[7/2/15 8:12:31:528 EDT] 00000021 ConfigureAcce I com.tivoli.am.fim.rte.util.ConfigureAccessManagerNode configureSvrSsl com.tivoli.am.fim.rte.config.exception.RuntimeConfiguratonAccessManagerSvrSslCfgException: +
[com.tivoli.pd.jutil.b: HPDBA0235I   The server lost the client’s authentication, probably because of session expiration.
]

Wrappered Exception:
com.tivoli.pd.jutil.b: HPDBA0235I   The server lost the client’s authentication, probably because of session expiration.
at com.tivoli.am.fim.rte.util.ConfigureAccessManagerNode.configureSvrSsl(ConfigureAccessManagerNode.java:371)
at com.tivoli.am.fim.rte.util.ConfigureAccessManagerNode.configure(ConfigureAccessManagerNode.java:157)
at com.tivoli.am.fim.rte.config.mbean.ITFIMRteImpl.configure(ITFIMRteImpl.java:191)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

What is happening here is, the ISAM for Web 8.0.1.0 Policy Server no longer wants to accept ssl-v3 connections.

You can confirm this in the ivmgrd.conf on the Appliance, where ssl-v3 is commented out:

# Enable or disable SSL version 3 protocol for administration operations
# This setting is ignored and set disabled when FIPS is enabled
#ssl-v3-enable = yes

Now for TFIM (or other IBM applications, as well as other in-house developed applications) to communicate (administration and/or authorisation commands) with the ISAM Policy Server, it has to use the TAM/ISAM PD.jar.

Now,  a default WAS 8.0.0.9 installation comes with an older PD.jar.    Here’s a quick way to find the PD.jar level in use:

sles1:~ # find /opt/IBM/WebSphere/ -name  PD.jar*
/opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar

sles1:~ # unzip /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar META-INF/MANIFEST.MF
Archive:  /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar
inflating: META-INF/MANIFEST.MF
sles1:~ # grep “Implementation-Version” META-INF/MANIFEST.MF
Implementation-Version: 6.1.0.9

Generally speaking, it’s a good idea to replace the WAS PD.jar with a version closer to the ISAM Policy Server version.  Which is exactly what I’m doing here.

imageisam8010jrte

You can find a copy of the ‘latest’ PD.jar within the pdjrte package that you can download from your ISAM appliance.

sles1:~ # unzip /root/Desktop/pdjrte/java/export/pdjrte/PD.jar META-INF/MANIFEST.MF
Archive:  /root/Desktop/pdjrte/java/export/pdjrte/PD.jar
inflating: META-INF/MANIFEST.MF
sles1:~ # grep “Implementation-Version” META-INF/MANIFEST.MF
Implementation-Version: 8.0.1.0

Take note of the ‘old’ PD.jar permissions:

sles1:~ # ls -al /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar
-rwxr-xr-x 1 root root 1151688 Jun 30 13:48 /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar

Save a copy of the ‘old’ PD.jar (in case you need to revert back to it), and copy the new PD.jar to the correct location (which is under ../tivoli/tam/PD.jar starting from WAS 8.0)

sles1:~ # mv /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar /root/Desktop/backup_pd.jar
sles1:~ # cp /root/Desktop/pdjrte/java/export/pdjrte/PD.jar /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar

Make sure to verify the ‘new’ PD.jar permissions match the old ones.

sles1:~ # ls -al /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar
-rwxr-xr-x 1 root root 2830721 Jul  2 08:21 /opt/IBM/WebSphere/AppServer1/tivoli/tam/PD.jar

Now you can start WAS again.    Patience… we’re almost there…!

Still having the -Djavax.net.debug=ssl,handshake debug turned on, this time with the 8.0.1.0 PD.jar in place, we can retry the TFIM Node configuration.   This time we see the SSL handshake doing a TLSv1 ClientHello (which is more to the likes of ISAM 8.0.1.0)

7/2/15 8:23:46:536 EDT] 00000025 SystemOut     O WebContainer : 3, closeOutboundInternal()
beforeconfiguringtfim
[7/2/15 8:23:56:259 EDT] 00000024 SystemOut     O Using SSLEngineImpl.
[7/2/15 8:23:56:260 EDT] 00000024 SystemOut     O
Is initial handshake: true
[7/2/15 8:23:56:260 EDT] 00000024 SystemOut     O Ignoring unsupported cipher suite: SSL_RSA_WITH_AES_128_GCM_SHA256
[7/2/15 8:23:56:260 EDT] 00000024 SystemOut     O Ignoring unsupported cipher suite: SSL_RSA_WITH_AES_128_CBC_SHA256
[7/2/15 8:23:56:260 EDT] 00000024 SystemOut     O Ignoring unsupported cipher suite: SSL_DHE_RSA_WITH_AES_128_GCM_SHA256
[7/2/15 8:23:56:260 EDT] 00000024 SystemOut     O Ignoring unsupported cipher suite: SSL_DHE_RSA_WITH_AES_128_CBC_SHA256
[7/2/15 8:23:56:260 EDT] 00000024 SystemOut     O Ignoring unsupported cipher suite: SSL_DHE_DSS_WITH_AES_128_GCM_SHA256
[7/2/15 8:23:56:260 EDT] 00000024 SystemOut     O Ignoring unsupported cipher suite: SSL_DHE_DSS_WITH_AES_128_CBC_SHA256
[7/2/15 8:23:56:263 EDT] 00000024 SystemOut     O WebContainer : 2, READ: TLSv1 Handshake, length = 177
[7/2/15 8:23:56:263 EDT] 00000024 SystemOut     O *** ClientHello, TLSv1
[7/2/15 8:23:56:263 EDT] 00000024 SystemOut     O RandomCookie:  GMT: 318233047 bytes = { 34, 180, 151, 200, 250, 108, 26, 65, 53, 21, 3, 159, 5, 146, 107, 97, 204, 27, 70, 15, 135, 191, 82, 237, 112, 6, 171, 40 }
[7/2/15 8:23:56:264 EDT] 00000024 SystemOut     O Session ID:  {85, 149, 45, 30, 38, 200, 8, 63, 34, 27, 254, 220, 16, 97, 107, 81, 51, 145, 5, 130, 139, 144, 95, 184, 30, 197, 42, 139, 247, 89, 244, 45}
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Cipher Suites: [SSL_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, SSL_ECDHE_RSA_WITH_AES_128_GCM_SHA256, SSL_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, SSL_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, SSL_ECDHE_RSA_WITH_AES_128_CBC_SHA, SSL_ECDHE_RSA_WITH_AES_256_CBC_SHA, SSL_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_ECDHE_ECDSA_WITH_RC4_128_SHA, SSL_ECDHE_RSA_WITH_RC4_128_SHA, SSL_DHE_RSA_WITH_AES_128_CBC_SHA, SSL_DHE_DSS_WITH_AES_128_CBC_SHA, Unknown 0x0:0x45, SSL_DHE_RSA_WITH_AES_256_CBC_SHA, SSL_DHE_DSS_WITH_AES_256_CBC_SHA, Unknown 0x0:0x88, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_AES_128_CBC_SHA, Unknown 0x0:0x41, SSL_RSA_WITH_AES_256_CBC_SHA, Unknown 0x0:0x84, SSL_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_MD5]
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Compression Methods:  { 0 }
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Unsupported extension server_name, [host_name: sles1]
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Extension renegotiation_info, ri_length: 0, ri_connection_data: { null }
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Extension elliptic_curves, curve names: {secp256r1, secp384r1, secp521r1}
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Extension ec_point_formats, formats: [uncompressed]
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Unsupported extension type_35, data:
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Unsupported extension type_13172, data:
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O Unsupported extension status_request, data: 01:00:00:00:00
[7/2/15 8:23:56:265 EDT] 00000024 SystemOut     O ***
[7/2/15 8:23:56:266 EDT] 00000024 SystemOut     O JsseJCE:  Using MessageDigest MD5 from provider IBMJCE version 1.2
[7/2/15 8:23:56:266 EDT] 00000024 SystemOut     O JsseJCE:  Using MessageDigest SHA from provider IBMJCE version 1.2
[7/2/15 8:23:56:266 EDT] 00000024 SystemOut     O %% Resuming [Session-1, SSL_DHE_RSA_WITH_AES_128_CBC_SHA]
[7/2/15 8:23:56:266 EDT] 00000024 SystemOut     O *** ServerHello, TLSv1

After a while, you should see something like this in the SystemOut.log, indicating the TFIM node was succesfully configured:

[7/2/15 8:23:58:905 EDT] 0000001d ITFIMRteImpl  I com.tivoli.am.fim.rte.config.mbean.ITFIMRteImpl configure(Map) FBTRTE028I The node was successfully configured.
[7/2/15 8:23:58:906 EDT] 0000001d RuntimeConfig I com.tivoli.am.fim.rte.config.impl.RuntimeConfigurationManagementServiceImpl configureNode FBTRTE028I The node was successfully configured.

** here’s another useful tip when trying to find your way in the sometimes very large SystemOut or trace.logs of WAS.  I’ve highlighted above a random string beforeconfiguringtfim in the SystemOut.log.  Right before doing a step that results in an problem, echo some random text to the trace.  That will allow you to easily find your way in the trace, e.g:

sles1:~ # echo beforeconfiguringtfim >> /opt/IBM/WebSphere/AppServer1/profiles/AppSrv01/logs/server1/SystemOut.log

While most of the steps above focus around TFIM, the same -Djavax.net.debug=ssl,handshake debug can be used for things like Trust Association (TAI++, eTAI) or custom applications using the ISAM JRTE.

Have fun debugging!

Leave a Reply

Your email address will not be published. Required fields are marked *