GSK SSL trace

GSK SSL (also known as System SSL) is used by the RSE daemon. The RSE server uses Java™ SSL.

Set the following variables in rsed.envvars:

GSK_TRACE_FILE=/var/zexpl/logs/gskssl.trc
GSK_TRACE=0xFF

Note: By default, the GSK_TRACE is written to /tmp/gskssl.%.trc, where % is the process ID.

Recreate the problem.

Format the trace. (Trace is sent to DD STDOUT.)

//GSKTRACE JOB CLASS=A,MSGCLASS=A,MSGLEVEL=(1,1),NOTIFY=&SYSUID
//*
//* SHOW FORMATTED GSKTRACE
//*
// SET FILE='/var/zexpl/logs/gskssl.trc'
//*
//FORMAT EXEC PGM=BPXBATCH,REGION=0M,TIME=NOLIMIT,
// PARM='SH ls -l &FILE;echo;gsktrace &FILE'
//STDOUT DD SYSOUT=*
//STDERR DD SYSOUT=*
//*

Expected output:

rsedaemon.log:

08:40:26.523 [corejni.c:1036 0xdf45ac0]  
  Java_com_ibm_etools_zos_server_CoreJNI_createSocket() Entered
key=enable_ssl
value=true
key=daemon_keydb_file
value=rsessl.racf
key=daemon_key_label
value=rsehost
key=server_keystore_file
value=rsessl.racf
key=server_keystore_label
value=rsehost
key=server_keystore_type
value=JCERACFKS
key=enable_ssl, value=true
Java_com_ibm_etools_zos_server_CoreJNI_createSocket() Exited
08:40:35.418 [corejni.c:1103 0xdf45ac0] 
Java_com_ibm_etools_zos_server_CoreJNI_acceptSocket() Entered 
08:41:09.968 [corejni.c:1117 0xdf45ac0]
Java_com_ibm_etools_zos_server_CoreJNI_acceptSocket() Exited
key=daemon_keydb_file, value=rsessl.racf 
key=daemon_keydb_password, value= 
key=daemon_key_label, value=rsehost
Java_com_ibm_etools_zos_server_CoreJNI_readSocket() Entered
Java_com_ibm_etools_zos_server_CoreJNI_readSocket() Exited

rseserver.log:

Wed Jan 06 08:40:21 EST 2010 
INFO RseDaemon: startProcesses(): spawn command result=16777795:132
INFO RseDaemon: startProcesses(): send Query to the Server process 
———————————————————————————————- 
Wed Jan 06 08:40:35 EST 2010 
INFO RseDaemon: startProcesses(): Server process started. (processId=583) 
INFO LogHandler: Thread poolProcess:583: KeyStore=JCERACFKS, rsessl.racf, 
INFO : ProcessId=583, Memory_Usage=4%, Used_Memory=2771KB, threads=3, TCBs=14 
———————————————————————————————- 
Wed Jan 06 08:41:11 EST 2010 
INFO LogHandler: 583:smile:8070256:0:6291103
INFO LogHandler: ProcessId=583: port 1837 assigned to smile
INFO : ProcessId=583, Memory_Usage=6%, Used_Memory=4028KB, threads=6, TCBs=18 
INFO LogHandler: ProcessId=583: smile logged on