Tag: gtf

Collecting and understanding a RACF GTF trace output

A RACF request can be

  • A callable service, such as IRRSDL00 which is used to extract information about keyrings. This can be used by High Level Languages. These have a trace type of OMVS
  • A RACROUTE request, an assembler macro interface, such as FASTAUTH. These have a trace type of RACF.

You get a trace entry PRE the call, and and a trace entry POST the call. A callable service would have an OMVSPRE, and an OMVSPOST entry.

When setting up your RACF trace you need to define which callable service, or which RACROUTE requests you want to trace.

Example of a callable server

Entry trace

Trace Identifier:             00000036 
Record Eyecatcher:            RTRACE 
Trace Type:                   OMVSPRE 
Ending Sequence:              ........ 
Calling address:              00000000  20801A0F 
Requestor/Subsystem:          ........  ........ 
Primary jobname:              IBMINC5 
Primary asid:                 00000029 
Primary ACEEP:                00000000  008FA8A8 
Home jobname:                 IBMINC5 
Home asid:                    00000029 
Home ACEEP:                   00000000  008FA8A8 
Task address:                 00000000  008D6A88 
Task ACEEP:                   00000000  00000000 
Time:                         DFF36A27  5460CC00 
Error class:                  ........ 
Service number:               00000029 
RACF Return code:             00000000 
RACF Reason code:             01000000 
Return area address:          00000000  00000000 
Parameter count:              00000021

Interesting information

  • Trace Type: OMVSPRE this is an entry trace
  • Primary jobname: IBMINC5
  • Home jobname: IBMINC5
  • The RACF return and reason code have no meaning on entry
  • Service number: 00000029 is hex so the service is 41. The RACF commands documentation says for a callable service, 41 is function number IRRSDL00.

Exit trace

Trace Identifier:             00000036 
Record Eyecatcher:            RTRACE 
Trace Type:                   OMVSPOST 
Ending Sequence:              ........ 
Calling address:              00000000  20801A0F 
Requestor/Subsystem:          ........  ........ 
Primary jobname:              IBMINC5 
Primary asid:                 00000029 
Primary ACEEP:                00000000  008FA8A8 
Home jobname:                 IBMINC5 
Home asid:                    00000029 
Home ACEEP:                   00000000  008FA8A8 
Task address:                 00000000  008D6A88 
Task ACEEP:                   00000000  00000000 
Time:                         DFF36A27  5468DC40 
Error class:                  ........ 
Service number:               00000029 
RACF Return code:             00000008 
RACF Reason code:             00000014 
Return area address:          00000000  00000000 
Parameter count:              00000021

Interesting fields

  • Trace Type: OMVSPOST this is the exit trace
  • As above service number 41 is function
  • The RACF Return code is 8
  • The RACF reason code is 14

Example of a RACROUTE trace

Entry

Trace Identifier:             00000036 
Record Eyecatcher:            RTRACE 
Trace Type:                   RACFPRE 
Ending Sequence:              ........ 
Calling address:              00000000  A096A08A 
Requestor/Subsystem:          CRYPTO    CRYPTO 
Primary jobname:              CSF 
Primary asid:                 00000038 
Primary ACEEP:                00000000  008F6B98 
Home jobname:                 IBMEXP 
Home asid:                    00000029 
Home ACEEP:                   00000000  008FA8A8 
Task address:                 00000000  008D6A88 
Task ACEEP:                   00000000  00000000 
Time:                         DFF37DD1  AB7FF040 
Error class:                  ........ 
Service number:               00000002 
RACF Return code:             00000000 
RACF Reason code:             00000000 
Return area address:          00000000  00000000 
Parameter count:              00000009

This trace entry was from a batch job IBMEXP, using an ICSF service to access an encryption key.

Interesting fields

  • RACFPRE this is a RACROUTE before entry
  • Requestor/Subsystem: CRYPTO which z/OS component
  • Primary jobname: CSF This was the address space which issued the RACROUTE request
  • Home jobname: IBMEXP This was the job requesting an ICSF service
  • Service number: 2. The RACF commands documentation says for a RACROUTE service, 2 is FASTAUTH
  • Ignore RACF return and RACF reason codes. They are set on exit,

Exit

Trace Identifier:             00000036 
Record Eyecatcher:            RTRACE 
Trace Type:                   RACFPOST 
Ending Sequence:              ........ 
Calling address:              00000000  A096A08A 
Requestor/Subsystem:          CRYPTO    CRYPTO 
Primary jobname:              CSF 
Primary asid:                 00000038 
Primary ACEEP:                00000000  008F6B98 
Home jobname:                 IBMEXP 
Home asid:                    00000029 
Home ACEEP:                   00000000  008FA8A8 
Task address:                 00000000  008D6A88 
Task ACEEP:                   00000000  00000000 
Time:                         DFF37DD1  AB85DE40 
Error class:                  ........ 
Service number:               00000002 
RACF Return code:             00000008 
RACF Reason code:             00000000 
Return area address:          00000000  00000000 
Parameter count:              00000009

This trace entry was from a batch job IBMEXP, using an ICSF service to access an encryption key.

Interesting fields

  • RACFPOST this is a RACROUTE after exit entry
  • Requestor/Subsystem: CRYPTO which z/OS component
  • Primary jobname: CSF This was the address space which issued the RACROUTE request
  • Home jobname: IBMEXP This was the job requesting an ICSF service
  • Service number: 2. The RACF commands documentation says for a RACFROUTE service, 2 is FASTAUTH
  • RACF Return code: 00000008, RACF Reason code: 00000000 This shows there was a problem. The documentation for FASTAUTH shows
    • RC=8 -> the user or group is not authorized to use the resource.
    • RS=0 -> The invoker does not need to log the request.

The RACF trace command for this was

#SET TRACE(JOBNAME(csf),callable(none),RACROUTE(type(2)))

and the following commands

S GTF.GTF
R 1,trace=usrp
R 2,USR=(F44) 
R 3,END
R 4,U

Fast start GTF

I can use 

S GTF.GTF,M=GTFRACF

Where my GTF proc has

//GTFNEW  PROC M=GTFPARM,ID=SYS1 
//DELETE  EXEC PGM=IEFBR14 
//IEFRDER DD   DSNAME=&ID..TRACE,UNIT=SYSDA,SPACE=(TRK,20),           
//             DISP=(MOD,DELETE) 
//IEFPROC EXEC PGM=AHLGTF,PARM='MODE=EXT,DEBUG=NO,TIME=YES,NP', 
//  TIME=1440,REGION=2880K 
//IEFRDER DD   DSNAME=&ID..TRACE,UNIT=SYSDA,SPACE=(TRK,20),     
//             DISP=(NEW,KEEP) 
//SYSLIB  DD   DSNAME=USER.Z24C.PROCLIB(&M),DISP=SHR

I have a member in USER.Z24C.PROCLIB(GTFRACF)

TRACE=USRP 
USR=(F44) 
END

How to take (and process) a RACF GTF trace with Java

When trying to resolve a certificate problem in a Java program, see here, I tried unsuccessfully to take a RACF trace to see what calls were being issued, and what reason codes were being returned.

The RACF GTF had no entries for the Java program!

Start RACF trace

My started task was called OZUSRV4. I had to specify a jobname to RACF trace of OZUSRV4* because Java spawns address spaces, and it was a spawned address space that did all of the Java work. If your started task is 8 characters long – just specify the 8 character name.

The trace command was the RACF SET TRACE command, where # is my RACF subsystem recognition character.

#SET TRACE(CALLABLE(TYPE(41))JOBNAME(OZUSVR4*))

Where type(41) is for IRRSDL00 which performs the R_datalib, keyring processing.

Start GTF

S GTF.GTF
R 1,trace=usrp
R 2,USR=(F44) 
R 3,END
R 4,U

Run the test

I ran my started task, and stopped the RACF trace 

#SET TRACE(CALLABLE(NONE))JOBNAME(OZUSVR4*)) 
#set list

The output of the #set list command included

TRACE OPTIONS                   - NOIMAGE                                    
                                - NOAPPC                                     
                                - NOSYSTEMSSL                                
                                - NORRSF                                     
                                - NORACROUTE                                 
                                - NOCALLABLE                                 
                                - NOPDCALLABLE                               
                                - NODATABASE                                 
                                - NOGENERICANCHOR                            
                                - NOASID                                     
                                - JOBNAME                                    
                                   OZUSVR4*                                  
                                - NOCLASS                                    
                                - NOUSERID                                   
SUBSYSTEM USERID                - START1

So the traces are off…. but it still has a reference to OZUSVR4 – strange.

Process the GTF file.

I used IPCS to look at the GTF file

  • =0 and specify the GTF file name
  • =6 dropd to drop any saved status from last time that dataset was used
  • gtf usr(all) It displays the output in an editor like window.
  • report view displays it in ISPF editor, view mod.
  • You can the do things like
    • x all
    • f ‘RACF Reason code’ all

To display the records with non zero return codes.

The output is very chatty – and it was hard to find the data I wanted from data with a hex dump of the string “OFFSET” etc. For example

Trace Identifier:             00000036                           
Record Eyecatcher:            RTRACE                             
Trace Type:                   OMVSPRE                            
Ending Sequence:              ........                           
Calling address:              00000000  79403A2D                 
Requestor/Subsystem:          ........  ........                 
Primary jobname:              OZUSVR44                           
Primary asid:                 00000035                           
Primary ACEEP:                00000000  008FC8A0                 
Home jobname:                 OZUSVR44                           
Home asid:                    00000035                           
Home ACEEP:                   00000000  008FC8A0                 
Task address:                 00000000  008CF298                 
Task ACEEP:                   00000000  00000000                 
Time:                         DDD4C11D  776E2A40                 
Error class:                  ........                           
Service number:               00000029                           
RACF Return code:             00000000                           
RACF Reason code:             00000000                           
Return area address:          00000000  00000000                 
Parameter count:              0000002B    
...                       
Area length:                  00000008                                                                                
                                                                                                                      
Area value:                                                                                                  
D6C6C6E2  C5E30050                               | OFFSET.&                         |  
                                                                                                                      
Area length:                  00000007                                                                                
                                                                                                                      
Area value:                                                                                                           
06E2E3C1  D9E3F1                                 | .START1                          |

I wrote a REXX exec which post processes the output and removes what I think is irrelevant data.

An example of what I think is useful is below. Non zero return codes have ! in column 1

! Return code: 00000008 8 
! Reason code: 00000004 4  4 Parameter list error occurred. 
-  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  - 
! Return code: 00000008 8 
! Reason code: 0000002C 44 44 No certificate found with the specified status 
-  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  - 
Area value: 
00000050  10AFC67C  ...
...
  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  - 
Area value:          | .START1                          | 
06E2E3C1  D9E3F1                                                
Area value:          | .MQRING                          | 
06D4D8D9  C9D5C7

You can download the rexx exec from

racfgtfDownload

You need to upload it to a CLIST available to ISPF.