Debugging AT-TLS session problems

I deliberately misconfigured AT-TLS to see how easy it would be to identify and resolve the problems from an AT-TLS perspective. It turned out worse than I expected. There is little information on the z/OS to help you.

I configured TTLSEnvironmentAction {trace 255 } (see the bottom of this blog) and refreshed the PAGENT. I had configured SYSLOGD so records for *.TCPIP.*.* went to /var/log/TCPIP.

I reran my MQ client application and got

  • from MQ on Linux, in file /var/mqm/errors/AMQERR01.LOG return code 2393 (MQRC_SSL_INITIALIZATION_ERROR).
  • On Linux there was a file /var/mqm/trace/AMQ.SSL.TRC – which only IBM can format!
  • From TCPIP on z/OS EZD1287I TTLS Error RC: 402 Initial Handshake LOCAL: REMOTE: JOBNAME: CSQ9CHIN RULE: REMOTE-TO-CSQ1 USERID: START1 GRPID: 0000001B ENVID: 0000000B CONNID: 0000006E This give
    • the address of my client,
    • the name of the chinit
    • which AT-TLS rule was used

The message EZD1287I TTLS Error RC: 402 Initial Handshake pointed me to Cryptographic Services System Secure Sockets Layer Programming – No SSL cipher specifications. The first reason was

The client and server cipher specifications do not contain at least one value in common. Client and server cipher specifications might be limited depending on which System SSL FMIDs are installed. See Cipher suite definitions for more information. Server cipher specifications are dependent on the type of algorithms that are used by the server certificate (RSA, DSA, ECDSA, or Diffie-Hellman), which might limit the options available during cipher negotiation.

MQ Trace

I took an MQ trace and formatted it. I used grep to find which file had “Cipher” in it.

Within this file I searched for Start of GSKit TLS Handshake Transcript.

This had information sent to the server as part of the handshake, and further down it had the reason code. You can see from the example that the fields and their values have been displayed (so cipher spec 003c is displayed as tls_rsa_with_aes_128_cbc_sha256)

Start of GSKit TLS Handshake Transcript (1119 bytes)
   Length: 28
   3E 5B 45 66 EE A3 C1 9F FB 81 0C 2F 38 19 DF 95     >[Ef......./8...
   5A 1B 54 CC B8 CB B6 C9 87 39 5E 88                 Z.T......9^.
 Length: 00
 Length: 04
 00 FF 00 3C                                         ...<
 Length: 01
 00                                                  .
 Length: 74
 00 0D 00 18 00 16 06 01 05 01 04 01 03 01 02 01     ................
 06 03 05 03 04 03 03 03 02 03 02 02 00 00 00 2A     ...............*
 00 28 00 00 25 73 79 73 74 65 6D 32 65 2D 64 65     .(..%system2e-de
 66 32 65 2D 73 76 72 63 6F 6E 6E 2E 63 68 6C 2E     f2e-svrconn.chl.
 6D 71 2E 69 62 6D 2E 63 6F 6D             
  Extension Count: 2
  signature_algorithms 13
  server_name 0
End of GSKit TLS Handshake Transcript
{  rriEvent
 RetCode = 20009665, rc1 = 420, rc2 = 0, Comment1='SYSTEM.DEF.SVRCONN', 
 Comment2='gsk_secure_soc_init', Comment3=''

With this trace, I am able to see what was sent to z/OS.

The AT-TLS Trace

The trace ( configured in syslogd to be in /var/log/TCPIP) had a one line entry with (I’ve reformatted it to make it easier to read).

Map CONNID: 0000006B 
TYPE: InBound 
STATUS: Enabled 

and data

RC: 0 Connection Init
RC: 0 Call GSK_SECURE_SOCKET_OPEN - 00000052FD6228F0
RC: 0 Set GSK_FD(300) - 000000000000006B
RC: 0 Set GSK_USER_DATA(200) - 000000007EC32430
RECV CIPHER 160303007B 

and one loooong record with

SEND CIPHER 15030300020228 

From the AT-TLS trace of the data received from the client, it is the data as received, and has not been split down into useful fields.

I could not find any documentation on how to format this string. It is not easy to create a program to format this (and get it right), for example converting cipher spec 003c to TLS_RSA_WITH_AES_128_CBC_SHA256. However I have a REXX exec which works in ISPF and decodes the data into fields, but not the contents of the fields – so the cipher spec is reported as 003c

I had some success taking this data, and creating a file which Wireshark could process. See Wireshark – using external data: Bodging a hex dump file. This was not always successful, as it looks like the data is truncated, and can have non hex data in the hex stream.

Note, the System SSL server started task, GSKSRVR, can capture System SSL trace. The output is like

Job TCPIP     Process 0101001D  Thread 00000001  read_v3_client_hello            
Received CLIENT-HELLO message                                                  

with no detailed information

Tracing just one session

If you have a busy system you could get trace data for many sessions. You may want to set up a TLS rule, so you use a “debug port”, or you specify the remote host IP address, and port, using information from the error message

EZD1287I TTLS Error RC: 402 Initial Handshake LOCAL: REMOTE:

And dont forget…

And do not forget to reset the TTLSEnvironmentAction entry to reset the trace, and to refresh the PAGENT.

Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s