Getting a system ssl trace for httpd server on z/OS

I had a problem getting the httpd server to work on z/OS. It did not like my certificate – but reported messages about ICSF security not being set up. I got to learn a lot about traces, but could not find how to trace System SSL (GSK) and httpd.

I specified SSLTRACE in my vhost*.conf file which gave me a little information – but not at the System SSL Level.

Other applications using System SSL, can set environment variables

GSK_TRACE=0xff 
GSK_TRACE_FILE=/tmp/gskssl.%.trc 

but this does not work with http. (I think the environment variables are not passed on to any spawned thread).

You have to use the gsksrvr task, and collect the trace through CTRACE.

Set up gsk trace.

I have used gsk trace before, and described setting it up.

I had to create a parmlib member

TRACEOPTS 
          WTRSTART(ctwtr) 
          on 
          wtr(ctwtr) 
jobname(httpcp) 
          OPTIONS('LEVEL=255,JOBSUFFIX=ANY') 

I start my http server with the S HTTPCP command, and specified httpcp in the jobname of the parmlib.

I got out no trace. I tried the various jobnames until it produced a trace. My trace was produced from jobname httpcp8! I could not find a way of displaying which of my httpcp* job was used, so I had to try them all.

If I had had a long name eg httpcpxx then specifying jobname(httpcpxx) should have worked.

Starting the trace

I used

TRACE CT,ON,COMP=GSKSRVR,PARM=CTGSKON

where my parmlib member was CTGSKOK

It produced

TRACE CT,ON,COMP=GSKSRVR,PARM=CTGSKON
IEE252I MEMBER CTGSKON FOUND IN USER.Z24C.PARMLIB
GSK01040I SSL component trace started.
ITT038I ALL OF THE TRANSACTIONS REQUESTED VIA THE TRACE CT COMMAND WERE
SUCCESSFULLY EXECUTED.

and the CTWTR started up.

What is the status of the trace?

d trace,comp=gsksrvr

gave me

IEE843I 08.32.25  TRACE DISPLAY       
  COMPONENT     MODE BUFFER HEAD SUBS                                  
 --------------------------------------------------------------        
  GSKSRVR       ON   0064K                                             
     ASIDS      *NOT SUPPORTED*                                        
     JOBNAMES   HTTPCP8 ,HTTPCP1 ,HTTPCP2 ,HTTPCP3 ,HTTPCP4 ,          
                HTTPCP5 ,HTTPCP6 ,HTTPCP7                              
     OPTIONS    LEVEL=255                                              
     WRITER     CTWTR                                                  

Run my test

When I ran my test, some System SSL messages were produced on the console from the gsksrvr address space

GSK01047I SSL component trace started for HTTPCP8/STC01000.
GSK01050I SSL component trace started for HTTPCP8/STC01000/05010022.

Stop the trace

TRACE CT,OFF,COMP=GSKSRVR

Wait until you get

GSK01041I SSL component trace ended.

from the gsksrvr address space, and stop the trace writer.

D TRACE,WTR=ALL
TRACE CT,WTRSTOP=CTWTR

This seems to take a few seconds to run. It outputs

IEF196I AHL904I THE FOLLOWING TRACE DATASETS CONTAIN TRACE DATA : 
IEF196I           IBMUSER.CTRACE1 
ITT111I CTRACE WRITER CTWTR TERMINATED BECAUSE OF A WTRSTOP REQUEST.  
IEF404I CTWTR - ENDED - TIME=08.40.21                                                                 

Format the trace

You need to use IPCS to format it

• =0 – and enter the data set name (IBMUSER.CTRACE1)
• =6 – to get to the ipcs command screen
• dropd – to tell IPCS to forget any historical information it may know about for the dataset
• CTRACE COMP(GSKSRVR) full – this displays any System SSL CTRACE data
• m PF8 – go to the bottom of the data
• report view – to go into ISPF View mode on the data set
• X ALL – to hide all of the data
• f SSL_ERROR ALL – this shows any error codes
• if you get any lines displayed, you can tab down to the hidden command and use the line prefix command f4 to display the first 4 hidden lines.

The errors I got were

 S0W1      MESSAGE   00000004  08:35:55.049451  SSL_ERROR 
   Job HTTPCP8   Process 05010022  Thread 00000005  crypto_ec_token_private_key_sign 
   ICSF service failure: CSFPPKS retCode = 0x8, rsnCode = 0x2b00 
                                                                                                              
 S0W1      MESSAGE   00000004  08:35:55.049733  SSL_ERROR 
   Job HTTPCP8   Process 05010022  Thread 00000005  crypto_sign_data 
   crypto_ec_sign_data() failed: Error 0x03353084 
                                                                                                              
 S0W1      MESSAGE   00000004  08:35:55.050012  SSL_ERROR 
   Job HTTPCP8   Process 05010022  Thread 00000005  construct_tls13_certificate_verify_message 
   Unable to generate certificate verify message: Error 0x03353084 
                                                                                                              
 S0W1      MESSAGE   00000004  08:35:55.050393  SSL_ERROR 
   Job HTTPCP8   Process 05010022  Thread 00000005  send_tls13_alert 
   Sent TLS 1.3 alert 51 to ::ffff:10.1.0.2.45432. 
                                                                                                              

The Alert 51 matches what my browser received.

File /usr/include/gskcms.h had #define CMSERR_ICSF_SERVICE_FAILURE 0x03353084

CSFPPKS is PKCS #11 Private Key Sign.

The return code 0x2b00 (from here) gives:

User action: You might need to re-create the token by using the PKA key token build or PKA key import callable service or regenerate the key values on another platform.

or in other words, it did not like my certificate created with NISTECC SIZE(256) but did like NISTECC SIZE(521).