I wrote a blog post Ongoing issues with Surveys (FEB) and IBM Connections which detailed some problems a customer was having with Surveys. This dragged on and resulted in a couple of PMR’s being raised with IBM but I am hopefully at the end of it now.

Recently IBM provided me with a modified .jar to provide additional output when the problem occurred. I needed to add to the ear file. I did this as follows

# cd /opt/IBM/WebSphere/AppServer/profiles/Dmgr01/bin/
# ./wsadmin.sh -lang jython
wsadmin>AdminApp.export(‘Forms Experience Builder’, ‘/tmp/Forms Experience Builder.ear’)
# cp /tmp/Forms\ Experience\ Builder.ear /tmp/Forms\ Experience\ Builder.ear.orig
# mkdir /tmp/feb_expanded
# mkdir /tmp/feb_collapsed
# /opt/IBM/WebSphere/AppServer/bin/EARExpander.sh -ear /tmp/Forms\ Experience\ Builder.ear -operationDir /tmp/feb_expanded/ -operation expand
ADMA4006I: Expanding enterprise archive (EAR) file /tmp/Forms Experience Builder.ear to directory /tmp/feb_expanded/.
# mkdir /tmp/feb_backup
# mv /tmp/feb_expanded/builder.war/WEB-INF/lib/ibm.fsp.core.service.startup-8.0.1.35.jar/ /tmp/feb_backup/
# cp -R /home/ldap/BenW/17891.033.866.ibm.fsp.core.service.startup-8.0.1.81/ /tmp/feb_expanded/builder.war/WEB-INF/lib/ibm.fsp.core.service.startup-8.0.1.35.jar
# /opt/IBM/WebSphere/AppServer/bin/EARExpander.sh -ear ‘/tmp/feb_collapsed/Forms Experience Builder.ear’ -operationDir /tmp/feb_expanded/ -operation collapse
ADMA4007I: Collapsing the contents of directory /tmp/feb_expanded/ to enterprise archive (EAR) file /tmp/feb_collapsed/Forms Experience Builder.ear.
Update the current application using the ISC pointing to /tmp/feb_collapsed/Forms Experience Builder.ear and selecting the default values.

What I found in the SystemOut.log after a period of time was a different error which in the UI was not allowing me to create new surveys but I could complete existing ones which was slightly different to what I was seeing when I raised the PMR. The exception was

[7/11/16 10:34:12:359 BST] 00001b1e StandardExcep E com.ibm.form.nitro.platform.StandardExceptionMapper toResponse ac7d3dec-57f7-482f-83e5-9eaf77c82cbb
java.lang.RuntimeException: Error reading from /tmp/ibm.fsp.temp.1466513524000/fspjars, isDirectory = false, exists = false, canRead = false
at com.ibm.form.platform.service.startup.IsolatingClassLoader.getFileList(IsolatingClassLoader.java:1577)
at com.ibm.form.platform.service.startup.IsolatingClassLoader.access$100(IsolatingClassLoader.java:47)…………..

I created /tmp/ibm.fsp.temp.1466513524000/fspjars and some functionality returned but it wasn’t until I restarted the JVM that it started to work properly.

IBM told me that the problem here is that the /tmp/ directory is getting cleared out and removing the aforementioned directory causing a problem for FEB.

After a bit of Googling I found that tmpwatch was clearing out files/directories that haven’t been edited for 10 days. To stop this I added the bold text.

# vi /etc/cron.daily/tmpwatch
#! /bin/sh
flags=-umc
/usr/sbin/tmpwatch "$flags" -x /tmp/.X11-unix -x /tmp/.XIM-unix \
        -x /tmp/.font-unix -x /tmp/.ICE-unix -x /tmp/.Test-unix \
        -X '/tmp/hsperfdata_*' -X '/tmp/.hdb*lock' -X '/tmp/.sapstartsrv*.log' \
        -X '/tmp/ibm.fsp.*' -X '/tmp/pymp-*' 10d /tmp
/usr/sbin/tmpwatch "$flags" 30d /var/tmp
for d in /var/{cache/man,catman}/{cat?,X11R6/cat?,local/cat?}; do
    if [ -d "$d" ]; then
        /usr/sbin/tmpwatch "$flags" -f 30d "$d"
    fi
done

After a few weeks the problem hadn’t manifested again and IBM told me that the cause of the initial PMR was the /tmp directory being emptied. I was dubious at first but then found https://developer.ibm.com/answers/questions/219765/periodically-my-feb-server-stops-working-properly.html which describes problems due the /tmp directory being cleaned out.

As other stuff gets written to the /tmp directory which is what WAS will use by default I decided to use the java.io.tmpdir custom property to instruct WAS to use a directory under /opt/ where it won’t be cleaned by tmpwatch.

Fingers crossed this is the end of it.

I wrote about the effects using DHE ciphers can have depending on the size of the SSL certificate used by iNotes when IBM Connections Mail is in play in IBM Connections Mail and Ephemeral Diffie-Hellman key size error

In this blog I suggested the work around was to use the following notes.ini setting.

SSL_DH_KEYSIZE=2048

Our Domino admins weren’t too keen on lowering the key size so I had to look into a way of forcing the server to use a different cipher instead of one of the DHE ciphers.

This is the output from Domino when the DHE cipher is in play.

[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested RSA_WITH_AES_128_CBC_SHA (0x002F)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Best common cipherspec 0x002F (so far)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Best common non-EC cipherspec 0x002F (so far)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested RSA_WITH_AES_256_CBC_SHA (0x0035)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Best common cipherspec 0x0035 (so far)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Best common non-EC cipherspec 0x0035 (so far)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested DHE_RSA_WITH_AES_128_CBC_SHA (0x0033)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested DHE_RSA_WITH_AES_256_CBC_SHA (0x0039)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Best common cipherspec 0x0039 (so far)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Best common non-EC cipherspec 0x0039 (so far)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested DHE_DSS_WITH_AES_128_CBC_SHA (0x0032)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested DHE_DSS_WITH_AES_256_CBC_SHA (0x0038)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested RSA_WITH_3DES_EDE_CBC_SHA (0x000A)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested DHE_RSA_WITH_3DES_EDE_CBC_SHA (0x0016)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested Unknown Cipher (0x0013)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client requested TLS_EMPTY_RENEGOTIATION_INFO_SCSV (0x00FF)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> TLS_EMPTY_RENEGOTIATION_INFO_SCSV found
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Extensions found in this message
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Processing TLS signature algorithms extension
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> Client supports hash mask 0x007E; server cert chain has mask 0x0030
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> hash/alg in certchain  fSupHasAlg:0000
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessClientHello> We selected cipher DHE_RSA_WITH_AES_256_CBC_SHA (0x0039)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLProcessHandshakeMessage Exit> Message: ClientHello (1) State: HandshakeServerIdle (3) Key Exchange: 9 Cipher: DHE_RSA_WITH_AES_256_CBC_SHA (0x0039)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLAdvanceHandshake Enter> Processed: ClientHello (1) State: HandshakeServerIdle (3)
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLAdvanceHandshake client_hello> SGC FLAG: 0   Count = 2
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeServerHello
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLEncodeServerHello> Sending empty renegotiation_info (0xff01) extension
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeCertificate
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLEncodeCertificate> Generating a certificate message with 3 certs
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeServerKeyExchange
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLEncodeDHKeyParams> Server RSA key size 4096 bits
[00403:00011-2285692672] 07/15/2016 11:07:54.94 AM SSLEncodeDHKeyParams> Using a DH key size of 4096 bits
[00403:00011-2285692672] 07/15/2016 11:07:55.01 AM SSLEncodeRSAServerKeyExchange> Signing ServerKeyExchange using RSAWithSHA256
[00403:00011-2285692672] 07/15/2016 11:07:55.04 AM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeServerHelloDone
[00403:00011-2285692672] 07/15/2016 11:07:55.04 AM SSLAdvanceHandshake Exit> State HandshakeClientKeyExchange (11)
[00403:00011-2285692672] 07/15/2016 11:07:55.04 AM SSL_Handshake> After handshake state = HandshakeClientKeyExchange (11); Status = -5000
[00403:00011-2285692672] 07/15/2016 11:07:55.04 AM int_MapSSLError> Mapping SSL error -5000 to 4176 [SSLHandshakeNoDone]
[00403:00011-2285692672] 07/15/2016 11:07:55.06 AM SSLProcessProtocolMessage> Record Content: Alert (21)
[00403:00011-2285692672] 07/15/2016 11:07:55.06 AM SSLProcessAlert> Got an alert of 0x50 (internal_error) level 0x2 (fatal)
[00403:00011-2285692672] 07/15/2016 11:07:55.06 AM SSL_Handshake> After handshake2 state HandshakeClientKeyExchange (11)
[00403:00011-2285692672] 07/15/2016 11:07:55.06 AM SSL_Handshake> SSL Error: -6994
[00403:00011-2285692672] 07/15/2016 11:07:55.06 AM int_MapSSLError> Mapping SSL error -6994 to 4171 [SSLFatalAlert]

The idea was to remove the DHE_RSA_WITH_AES_256_CBC_SHA (0x0039) from the list of supported ciphers.

You can do this by dictating all the ciphers Domino uses using the SSLCipherSpec notes.ini setting.

I stopped Domino and added to the notes.ini the following and then started Domino.

SSLCipherSpec=C030009FC02F009EC028006BC014C0270067C013009D009C003D0035003C02F000A

You can see in the string 0039 is not listed. This means that Domino will not use DHE_RSA_WITH_AES_256_CBC_SHA and another cipher will be negotiated.

On restart you can see that the cipher RSA_WITH_AES_256_CBC_SHA is now selected and that is being used which works.

[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLInitContext> Ignoring invalid SSLCipherSpec value F0
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLInitContext> User is forcing 0xFFF3800 cipher spec bitmask for 15 ciphers
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_TRUSTPOLICY>  bits for signature hashes: 0030
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM int_MapSSLError> Mapping SSL error 0 to 0 [SSLNoErr]
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> outgoing ->protocolVersion: 0303
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessProtocolMessage> Record Content: Handshake (22)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessHandshakeMessage Enter> Message: ClientHello (1) State: HandshakeServerIdle (3) Key Exchange: 0 Cipher: Unknown Cipher (0x0000)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessHandshakeMessage client_hello> SGC FLAG: 0 CTX state = 3 SGCCount = 0
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> clientVersion: 0303
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> SSL/TLS protocol clientVersion 0x0303, serverVersion 0x0303
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> 10 ciphers requested by client
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested RSA_WITH_AES_128_CBC_SHA (0x002F)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested RSA_WITH_AES_256_CBC_SHA (0x0035)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Best common cipherspec 0x0035 (so far)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Best common non-EC cipherspec 0x0035 (so far)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested DHE_RSA_WITH_AES_128_CBC_SHA (0x0033)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested DHE_RSA_WITH_AES_256_CBC_SHA (0x0039)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested DHE_DSS_WITH_AES_128_CBC_SHA (0x0032)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested DHE_DSS_WITH_AES_256_CBC_SHA (0x0038)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested RSA_WITH_3DES_EDE_CBC_SHA (0x000A)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested DHE_RSA_WITH_3DES_EDE_CBC_SHA (0x0016)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested Unknown Cipher (0x0013)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client requested TLS_EMPTY_RENEGOTIATION_INFO_SCSV (0x00FF)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> TLS_EMPTY_RENEGOTIATION_INFO_SCSV found
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Extensions found in this message
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Processing TLS signature algorithms extension
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> Client supports hash mask 0x007E; server cert chain has mask 0x0030
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> hash/alg in certchain  fSupHasAlg:0000
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessClientHello> We selected cipher RSA_WITH_AES_256_CBC_SHA (0x0035)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessHandshakeMessage Exit> Message: ClientHello (1) State: HandshakeServerIdle (3) Key Exchange: 1 Cipher: RSA_WITH_AES_256_CBC_SHA (0x0035)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake Enter> Processed: ClientHello (1) State: HandshakeServerIdle (3)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake client_hello> SGC FLAG: 0   Count = 2
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake client_hello> Using resumed SSL/TLS Session
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeServerHello
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLEncodeServerHello> Sending empty renegotiation_info (0xff01) extension
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeChangeCipherSpec
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeFinishedMessage
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLCalculateTLS12FinishedMessage Enter> senderID: server finished, PRF using SHA256
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake Exit> State HandshakeChangeCipherSpec (13)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> After handshake state = HandshakeChangeCipherSpec (13); Status = -5000
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM int_MapSSLError> Mapping SSL error -5000 to 4176 [SSLHandshakeNoDone]
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessProtocolMessage> Record Content: Change cipher spec (20)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> After handshake2 state HandshakeFinished (14)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM int_MapSSLError> Mapping SSL error -5000 to 4176 [SSLHandshakeNoDone]
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessProtocolMessage> Record Content: Handshake (22)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessHandshakeMessage Enter> Message: Finished (20) State: HandshakeFinished (14) Key Exchange: 1 Cipher: RSA_WITH_AES_256_CBC_SHA (0x0035)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLCalculateTLS12FinishedMessage Enter> senderID: client finished, PRF using SHA256
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLProcessHandshakeMessage Exit> Message: Finished (20) State: HandshakeFinished (14) Key Exchange: 1 Cipher: RSA_WITH_AES_256_CBC_SHA (0x0035)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake Enter> Processed: Finished (20) State: HandshakeFinished (14)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSLAdvanceHandshake Exit> State HandshakeServerIdle (3)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> After handshake2 state HandshakeServerIdle (3)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> Using resumed SSL/TLS session
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> Protocol Version = TLS1.2 (0x303)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> Cipher = RSA_WITH_AES_256_CBC_SHA (0x0035)
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> KeySize = 256 bits
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> Server RSA key size = 4096 bits
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM SSL_Handshake> TLS/SSL Handshake completed successfully
[06035:00011-2986616576] 07/15/2016 12:30:35.85 PM int_MapSSLError> Mapping SSL error 0 to 0 [SSLNoErr]

The string below includes all the ECDHE ciphers which is detailed in https://www-10.lotus.com/ldd/dominowiki.nsf/dx/TLS_Cipher_Configuration but not the DHE cipher that was tripping me up.

SSLCipherSpec=C030009FC02F009EC028006BC014C0270067C013009D009C003D0035003C02F000A

It work’s now and I have tested it with all major browsers. I’m happy and so are the Domino guys too🙂

I had to force TLSv1.2 across all of Connections to fix a problem with RTE as I detailed in Rich Content widget widget stops working due to mix matched SSL protocols but after testing I’ve found that this breaks Textbox.io in Chrome and Surveys.

The process is well documented in How to Force IBM Connections 5.5 CR1 to Use TLSv1.2 but after making the changes the following happens.

Textbox.io

In IE and FF Textbox.io works fine but in Chrome the spell check service fails.

1

In Fiddler trace is saw Spelling server error:  Could not load url “https://connections.acme.com/ephox-spelling/1/correction”: 500 Internal Server Error

In the SystemOut.log I saw

[6/29/16 10:00:38:507 BST] 00000200 SystemOut     O ironbark-akka.actor.default-dispatcher-17, RECV TLSv1 ALERT:  fatal, handshake_failure
[6/29/16 10:00:38:507 BST] 00000200 SystemOut     O ironbark-akka.actor.default-dispatcher-17, fatal: engine already closed.  Rethrowing javax.net.ssl.SSLException: Received fatal alert: handshake_failure

spray.can.Http$ConnectionException: Aborted
    at spray.can.client.HttpHostConnectionSlot.reportDisconnection(HttpHostConnectionSlot.scala:228) ~[spray-can_2.11-1.3.3.jar:na]
    at spray.can.client.HttpHostConnectionSlot$$anonfun$connected$1.applyOrElse(HttpHostConnectionSlot.scala:161) ~[spray-can_2.11-1.3.3.jar:na]
    at akka.actor.Actor$class.aroundReceive(Actor.scala:465) ~[akka-actor_2.11-2.3.9.jar:na]

IBM asked me to put on SSL trace, *=info:SSL=all. It seems that the client is sending TLSv1.0 which of course is not allowed now TLSv1.2 has been forced.

[7/11/16 9:31:17:286 BST] 00000115 SystemOut     O   ironbark-akka.actor.default-dispatcher-7, READ: TLSv1.2 Alert, length = 2
[7/11/16 9:31:17:286 BST] 00000115 SystemOut     O   ironbark-akka.actor.default-dispatcher-7, RECV TLSv1 ALERT:  fatal, handshake_failure
[7/11/16 9:31:17:286 BST] 00000115 SystemOut     O   ironbark-akka.actor.default-dispatcher-7, fatal: engine already closed.  Rethrowing javax.net.ssl.SSLException: Received fatal alert: handshake_failure

IBM have logged a ticket with Ephox as well as investigating it from there end.

Surveys

When in a community with previous surveys I can not see any of the historical surveys nor could I create new ones.

In the SystemOut.log I saw the following

[6/29/16 10:01:56:542 BST] 0000033b StandardExcep E com.ibm.form.nitro.platform.StandardExceptionMapper toResponse eaa8e54e-7c38-4edb-a5ca-bcbd6d7f6c64
                                 com.ibm.form.platform.service.framework.exception.ServicesPlatformException: com.ibm.connections.directory.services.exception.DSException: com.ibm.connections.directory.services.exception.DSOutOfServiceException: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure

Caused by: com.ibm.connections.directory.services.exception.DSException: com.ibm.connections.directory.services.exception.DSOutOfServiceException: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure

Caused by: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure

Again, it seems like it’s sending TLSv1.0.

There’s at least one other person I know of who’s logged a PMR for these problems. It’s fairly urgent due to a problem with the RTE application which is only fixed when TLS1.2 is enforced. I’m hoping that these problems can be resolved sharpish so I can resolve the RTE problem for a customer.

I’m building an IBM Connections 5.5 server to replace our internal Connections server and when configuring the Mail plug-in I came up against problems with the error “Mail server cannot be reached.”

1

The Domino iNotes server is configured to accept SSL and have SSLv3 disabled via DISABLE_SSLV3=1. SSO works in both directions between the two application servers.

I checked the discoveryservlet URL (https://connections.acme.com/connections/resources/discovery/DiscoveryServlet?email=ben.williams@chooseportal.com) which returned valid data so I know the configuration in socialmail-discovery-config.xml was good but there was very little to go on. Even after I enabled *=info:com.ibm.social.pim.discovery.*=all there was nothing much to go on.

I reached out and Michele Buccarello responded and pointed me towards one of his documents http://www.slideshare.net/michelebuccarello/connections-mail-with-exchange-backend. The document is written primarily for an Exchange server but it describes brilliantly what is happening and a bit of trace that came to my rescue.

I enabled *=info:com.ibm.social.pim.discovery.*=all:com.ibm.cre.*=all and all of a sudden I saw what was happening.

[7/12/16 13:49:33:787 BST] 00000220 CREURLConnect 2   An unhandled exception occured connecting to the target host
                                 javax.net.ssl.SSLException: java.lang.RuntimeException: Could not generate DH keypair

Caused by: java.lang.RuntimeException: Could not generate DH keypair

Caused by: java.security.InvalidAlgorithmParameterException: Prime size must be multiple of 64, and can only range from 256 to 2048 (inclusive)

I read around the various ciphers and I must admit I was a little lost and it’s been a while since I’ve delved deeply into Domino but some googling got me to some Daniel Nashed blogs.

http://blog.nashcom.de/nashcomblog.nsf/dx/first-perfect-forward-secrecy-ciphers-shipped-with-9.0.1-fp3-if2.htm?opendocument&comments#anc1

http://blog.nashcom.de/nashcomblog.nsf/dx/dha-with-more-than-1024-key-size-and-java-still-works.htm?opendocument&comments#anc1

The second had a comment about the Mail plug-in not working so I knew I was getting closer. This put various stackoverflow posts into perspective such as

http://stackoverflow.com/questions/6851461/java-why-does-ssl-handshake-give-could-not-generate-dh-keypair-exception

I stopped Domino and added the following before starting it again and the plug-in started working and I could access my mail and calendar.

SSL_DH_KEYSIZE=1024

I upped the value to 2048 since a previous error said “Prime size must be multiple of 64, and can only range from 256 to 2048 (inclusive).”

On restart of Domino it continued to work. I tried increasing the value to 3072 but this broke the plug-in.

The certificate I was provided was a 4096 bit certificate and not 2048 like I handle more often.

In https://www-10.lotus.com/ldd/dominowiki.nsf/dx/TLS_Cipher_Configuration it states, “By default, these ciphers will use a DH key with a size equivalent to the RSA keysize, so a server running with a 2048 bit SSL certificate would use a 2048 bit DH group.” This means that the DH key being used is 4096 which IBM’s implementation of Java doesn’t support, hence the need to add SSL_DH_KEYSIZE=2048.

I then found the following Domino trace.

DEBUG_SSL_CIPHERS=2
DEBUG_SSL_DHE=2
DEBUG_SSL_HANDSHAKE=2
DEBUG_SSL_IO=0

When I recreate the problem I see in the console.log the following which shows the DH key size.

[11856:00011-1753671424] 07/12/2016 01:50:03.16 PM SSLEncodeDHKeyParams> Server RSA key size 4096 bits
[11856:00011-1753671424] 07/12/2016 01:50:03.16 PM SSLEncodeDHKeyParams> Using a DH key size of 4096 bits
[11856:00011-1753671424] 07/12/2016 01:50:03.26 PM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeServerHelloDone
[11856:00011-1753671424] 07/12/2016 01:50:03.26 PM SSLAdvanceHandshake Exit> State HandshakeClientKeyExchange (11)
[11856:00011-1753671424] 07/12/2016 01:50:03.26 PM SSL_Handshake> After handshake state = HandshakeClientKeyExchange (11); Status = -5000
[11856:00011-1753671424] 07/12/2016 01:50:03.26 PM int_MapSSLError> Mapping SSL error -5000 to 4176 [SSLHandshakeNoDone]
[11856:00011-1753671424] 07/12/2016 01:50:03.27 PM SSLProcessProtocolMessage> Record Content: Alert (21)
[11856:00011-1753671424] 07/12/2016 01:50:03.27 PM SSLProcessAlert> Got an alert of 0x50 (internal_error) level 0x2 (fatal)
[11856:00011-1753671424] 07/12/2016 01:50:03.27 PM SSL_Handshake> After handshake2 state HandshakeClientKeyExchange (11)
[11856:00011-1753671424] 07/12/2016 01:50:03.27 PM SSL_Handshake> SSL Error: -6994
[11856:00011-1753671424] 07/12/2016 01:50:03.27 PM int_MapSSLError> Mapping SSL error -6994 to 4171 [SSLFatalAlert]

In https://www-10.lotus.com/ldd/dominowiki.nsf/dx/TLS_Cipher_Configuration it also states, “When using Domino 9.0.1 FP3 IF2 one can and should disable DHE_RSA_WITH_AES_128_CBC_SHA (33) which should make those old clients fall back to using RSA_WITH_AES_128_CBC_SHA (2F) instead.”

I tried the below setting which removes “33” to see whether it worked but it did not. I would like to fiddle more with this to try and find a cipher that WAS and Domino can use in common that avoids setting the DH key too low but I suspect I will run out of time.

SSLCIPHERSPEC=9D9C3D3C352F0A39676B9E9F

BTW – I did all this after I had forced TLS1.2 via How to Force IBM Connections 5.5 CR1 to Use TLSv1.2 which is nice to know that Mail is not broken after enforcing TLS1.2 unlike Textbox.io and Surveys…..

Oh, in Domino when it is successful it will look something like this.

[17825:00011-575325952] 07/12/2016 03:12:00.31 PM SSLEncodeDHKeyParams> Server RSA key size 4096 bits
[17825:00011-575325952] 07/12/2016 03:12:00.31 PM SSLEncodeDHKeyParams> Using a DH key size of 2048 bits
[17825:00011-575325952] 07/12/2016 03:12:00.32 PM SSLEncodeRSAServerKeyExchange> Signing ServerKeyExchange using RSAWithSHA256
[17825:00011-575325952] 07/12/2016 03:12:00.36 PM SSLAdvanceHandshake calling SSLPrepareAndQueueMessage> SSLEncodeServerHelloDone

[17825:00011-575325952] 07/12/2016 03:12:00.41 PM SSL_Handshake> After handshake2 state HandshakeServerIdle (3)
[17825:00011-575325952] 07/12/2016 03:12:00.41 PM SSL_Handshake> Protocol Version = TLS1.2 (0x303)
[17825:00011-575325952] 07/12/2016 03:12:00.41 PM SSL_Handshake> Cipher = DHE_RSA_WITH_AES_256_CBC_SHA (0x0039)
[17825:00011-575325952] 07/12/2016 03:12:00.41 PM SSL_Handshake> KeySize = 256 bits
[17825:00011-575325952] 07/12/2016 03:12:00.41 PM SSL_Handshake> Ephemeral Diffie-Hellman key size = 2048 bits
[17825:00011-575325952] 07/12/2016 03:12:00.41 PM SSL_Handshake> Server RSA key size = 4096 bits
[17825:00011-575325952] 07/12/2016 03:12:00.41 PM SSL_Handshake> TLS/SSL Handshake completed successfully

You won’t see much difference in trace.log.

If anyone has a better way to get around this without changing the value of the DH key size then please shout.

Additional information

I should mention that a useful tip Michele Buccarello pointed me towards taking a Fiddler trace.

You’ll see a call to /connections/opensocial/gadgets/makeRequest. Within that entry in Fiddler I saw 502 Bad Gateway

throw 1; < ‘invalid javascript’ >{“https://webmail.acme.com/mail/bwilliam.nsf/iNotes/Proxy/?OpenDocument&Form=f_SessionInfo_Data&_icmb=20160425-0501&#8221;:{“rc”:502,”body”:”&amp;amp;lt;HTML&amp;amp;gt;&amp;amp;lt;TITLE&amp;amp;gt;502&amp;amp;nbsp;-&amp;amp;nbsp;Bad&amp;amp;nbsp;Gateway&amp;amp;lt;/TITLE&amp;amp;gt;&amp;amp;lt;BODY&amp;amp;gt;&amp;amp;lt;h1&amp;amp;gt;502&amp;amp;nbsp;An&amp;amp;nbsp;unhandled&amp;amp;nbsp;exception&amp;amp;nbsp;occured&amp;amp;nbsp;connecting&amp;amp;nbsp;to&amp;amp;nbsp;the&amp;amp;nbsp;target&amp;amp;nbsp;host&amp;amp;lt;/h1&amp;amp;gt;&amp;amp;lt;/BODY&amp;amp;gt;&amp;amp;lt;/HTML&amp;amp;gt;”,”headers”:{“date”:[“Mon, 11 Jul 2016 21:30:46 GMT”],”content-type”:[“text/html; charset=UTF-8″]},”DataHash”:”jslu7s57e7d899jbtr7p1d033g”}}

You can also look at the JSON section to see it in a different format.

The above is also seen in the trace.log with *=info:com.ibm.social.pim.discovery.*=all:com.ibm.cre.*=all

[7/12/16 8:49:30:670 BST] 000001bb CREURLConnect 2   IOException caught, response code is 502, Exception was java.io.IOException: Server returned HTTP response code: 502 for URL: https://webmail.acme.com/mail/bwilliam.nsf/iNotes/Proxy/?OpenDocument&Form=s_ReadViewEntries_JSON&PresetFields=FolderName;($Inbox),UnreadOnly;1,UnreadCountInfo;1,hc;$98&Count=1&resortdescendingpn=$70&TZType=UTC&KeyType=time&_icmb=20160425-0501
[7/12/16 8:49:30:671 BST] 000001bb CREURLConnect 2   Retry error while in streaming mode: 502, java.io.IOException: Server returned HTTP response code: 502 for URL: https://webmail.acme.com/mail/bwilliam.nsf/iNotes/Proxy/?OpenDocument&Form=s_ReadViewEntries_JSON&PresetFields=FolderName;($Inbox),UnreadOnly;1,UnreadCountInfo;1,hc;$98&Count=1&resortdescendingpn=$70&TZType=UTC&KeyType=time&_icmb=20160425-0501

I noticed on another deployment of IBM Connections 5.5 which includes Solr (Type Ahead Search) the Admin dashboard reported less information as before. The difference is that I used the JRE with WebSphere.

It seems that the output provided in the dashboard is less when using the JRE with WebSphere. There is no stipulation of which JRE should be used but it seems sensible to install Oracle Java since some of the data is missing. Take a look at the screen shots below.

Oracle JRE

1

IBM JRE

2

I wanted to put together a script to allow me to start, stop and restart Solr so I managed to cobble together the below version which seems to work pretty well. I am sure there are others who will read this that have better *nix scripting skills who may want to improve it.

In this case I am using JRE that comes with WebSphere but you could use Oracle Java.

# vim /etc/init.d/solr

#!/bin/sh
#
# apache
#
# chkconfig: 5 90 10
# description: Restart script for Apache Solr created by Ben.Williams@chooseportal.com
SOLR_DIR=”/opt/IBM/solr/solr-4.7.2/node1″
JAVA_STOP_OPTIONS=”-DSTOP.PORT=8079 -DSTOP.KEY=mysecret -jar start.jar”
JAVA_START_OPTIONS=”-DSTOP.PORT=8079 -DSTOP.KEY=mysecret -Djetty.ssl.clientAuth=true -Dhost=$(hostname –fqdn) -Dcollection.configName=myConf -DzkRun -DnumShards=1 -Dbootstrap_confdir=/opt/IBM/solr/solr-4.7.2/node1/solr/quick-results-collection/conf -Dsolr.solr.home=/opt/IBM/solr/solr-4.7.2/node1/solr -jar start.jar”
#LOG_FILE=”/opt/IBM/solr/solr-4.7.2/node1/logs/solr.log”
JAVA_HOME=”/opt/IBM/WebSphere/AppServer/java/bin/java”
RETVAL=$?
case $1 in
    start)
        echo “Starting Solr”
        cd $SOLR_DIR
        $JAVA_HOME $JAVA_START_OPTIONS >/dev/null 2>&1 &
        ;;
    stop)
        echo “Stopping Solr”
        cd $SOLR_DIR
        $JAVA_HOME $JAVA_STOP_OPTIONS –stop >/dev/null 2>&1 &
        ;;
    restart)
        $0 stop
        sleep 10
        $0 start
        ;;
    *)
        echo “Usage: $0 {start|stop|restart}” >&2
        exit 1
        ;;
esac
exit $RETVAL

# chmod 755 /etc/init.d/solr
# chkconfig –add solr
# chkconfig –level 35 solr on

Here is an Oracle JRE suitable version.

#!/bin/sh
#
# apache
#
# chkconfig: 5 90 10
# description: Restart script for Apache Solr created by Ben.Williams@chooseportal.com
SOLR_DIR=”/opt/IBM/solr/solr-4.7.2/node1″
JAVA_STOP_OPTIONS=”-DSTOP.PORT=8079 -DSTOP.KEY=mysecret -jar start.jar”
JAVA_START_OPTIONS=”-DSTOP.PORT=8079 -DSTOP.KEY=mysecret -Djetty.ssl.clientAuth=true -Dhost=$(hostname –fqdn) -Dcollection.configName=myConf -DzkRun -DnumShards=1 -Dbootstrap_confdir=/opt/IBM/solr/solr-4.7.2/node1/solr/quick-results-collection/conf -Dsolr.solr.home=/opt/IBM/solr/solr-4.7.2/node1/solr -jar start.jar”
JAVA_HOME=”/usr/lib/jvm/jre/bin/java”
RETVAL=$?
case $1 in
    start)
        echo “Starting Solr”
        cd $SOLR_DIR
        $JAVA_HOME $JAVA_START_OPTIONS >/dev/null 2>&1 &
        ;;
    stop)
        echo “Stopping Solr”
        cd $SOLR_DIR
        $JAVA_HOME $JAVA_STOP_OPTIONS –stop >/dev/null 2>&1 &
        ;;
    restart)
        $0 stop
        sleep 10
        $0 start
        ;;
    *)
        echo “Usage: $0 {start|stop|restart}” >&2
        exit 1
        ;;
esac
exit $RETVAL

For an IBM Connections 5.5 customer I found that periodically the Rich Content widget (RTE) stops working showing “The page could not be created due to an error” like the image below.

1

The following exceptions are seen in the SystemOut.log and access.log.

[6/21/16 10:10:34:889 CEST] 00000282 ConnectContro W org.springframework.social.connect.web.ConnectController oauth2Callback Exception while handling OAuth2 callback (I/O error on POST request for “https://connections.acme.com/oauth2/endpoint/connectionsProvider/token&#8221;:Server returned wrong cipher suite for session; nested exception is javax.net.ssl.SSLProtocolException: Server returned wrong cipher suite for session). Redirecting to IBMConnections connection status page.
[6/21/16 10:10:34:904 CEST] 00001811 ServletWrappe E com.ibm.ws.webcontainer.servlet.ServletWrapper service SRVE0014E: Uncaught service() exception root cause rteServlet: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name ‘scopedTarget.ibmConnections’ defined in com.ibm.lconn.rte.config.SocialConfig: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.social.connections.api.IBMConnections]: Factory method ‘ibmConnections’ threw exception; nested exception is java.lang.IndexOutOfBoundsException
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:982)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:575)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:668)

46.58.58.130 – – [21/Jun/2016:10:10:34 +0200] “GET /oauth2/endpoint/connectionsProvider/authorize?client_id=conn-rte&response_type=code&acls=true&callback_uri=https%253A%252F%252Fconnections.acme.com%252Fconnections%252Frte%252Fcommunity%252F8e3190fe-fb3e-4ebd-83d4-1f319e7a5522%252Fentry&_oauth_client_auto_authorize=true&scope=Connections HTTP/1.1” 302 –
46.58.104.37 – – [21/Jun/2016:10:10:34 +0200] “GET /dm/atom/people/feed?self=true&format=json&anonymousCheck=true&membershipTimestamp=1461057779000&dojo.preventCache=1466496635731 HTTP/1.1” 200 404
46.58.58.130 – – [21/Jun/2016:10:10:34 +0200] “GET /connections/rte/connect?code=iK97VSiDgGJzorfylyBpEVt3OJ800r HTTP/1.1” 202 104
46.58.104.37 – – [21/Jun/2016:10:10:34 +0200] “GET /connections/rte/community/8e3190fe-fb3e-4ebd-83d4-1f319e7a5522/entry?acls=true HTTP/1.1” 500 615

There was an interesting thread in the Socially Integrated blog which was along the same lines but not a match so I raised a PMR. The ever dependable Dave McCarthy and Kevin Holohan shed some light on what was happening.

“According to a chat I had with L3, this is a bug in the JVM. If a connection is established with TLS 1.0 to a specific host (like say host1.ibm.com) then it caches the TLS cipher that was exchanged with the host so that it doesn’t have to do negotiate again. Now if another app in JVM tries to establish connections with TLS 1.2 to the same host (host1.ibm.com) the cached info is reused. This causes the problem. Host1.ibm.com is requesting TLS 1.2 but cached connection in JVM is at TLS 1.0”

It seems that the RTE application is not honouring the protocol as detailed in the Quality of protection (QoP) settings in the ISC and is trying to connect using TLS 1.2. This has triggered Technote How to Force IBM Connections 5.5 CR1 to Use TLSv1.2.

Furthermore I was made aware of LO89164 which is an update to RTE so that it utilises the intraservice URLs for each of the connections components and is be able to direct the HTTP requests issued by RTE component to the appropriate internal endpoint URLs, as referenced in the LCC.xml.

LO89164 can only be applied to CR01 which the customer is not running yet. LO89164 will be included in CR02. This ifix is only available from IBM by logging a PMR, it’s not on Fix Central.

When I am given a maintenance window I need to do the following:

  1. WAS FP8
  2. CR01
  3. Apply LO89164 (included in 5.5 CR2)
  4. Change QoP settings

This should cover off this problem. CR01 also includes other identified bugs in RTE which I won’t go into here but it’s worth applying….