Example of formatted GTF trace output

This section contains screen images that show GTF records. IPCS produced the screens from an example dump. These records are in comprehensive format and are time stamped.

The GTFTRACE subcommand was issued on the IPCS Subcommand Entry panel shown in Figure 1.

Figure 1. Example: IPCS subcommand entry panel for GTFTRACE

 IPCS OUTPUT STREAM ------------------------------------------ LINE 0 COLS 1 78
 COMMAND ===>                                                  SCROLL ===> CSR

  ****************************** TOP OF DATA ***********************************

    **** GTFTRACE DISPLAY OPTIONS IN EFFECT ****
  SSCH=ALL  IO=ALL  CCW=SI
  SVC=ALL  PI=ALL
  EXT  RNIO  SRM  RR  DSP  SLIP
  **** GTF DATA COLLECTION OPTIONS IN EFFECT: ****
  Minimum tracing for IO, SSCH, SVC, PI, EXT, and FRR events
  All GTRACE events requested
  All events associated with the execution should be traced
  All DISPATCHER events traced
  PCI events are to be traced
  System resource manager events traced
                                                                                    
               **** GTF TRACING ENVIRONMENT ****                                    
         Release: SP7.8.0   FMID: HBB7780   System name: FIRST                      
         CPU Model: 2097  Version: FF  Serial no. 170067                            
    SVC   CODE.... 002      ASCB.... 00FB8100 CPU..... 0000                         
                            PSW..... 07041000 80000002 00000000 0557C0D0            
                            TCB..... 006F0BF8 R15..... 00FDCAEA R0...... 00000000   
                            R1...... 806F2BE0                                       
                   GMT-01/09/2011 00:21:13.668101  LOC-01/08/2011 19:21:13.668101   
    SVCR  CODE.... 002      ASCB.... 00FB8100 CPU..... 0000                         
                            PSW..... 07041000 80000002 00000000 0557C0D0            
                            TCB..... 006F0BF8 R15..... 813BCF7C R0...... 813BCF7C   
                            R1...... 02514607                                       
                   GMT-01/09/2011 00:21:13.668143  LOC-01/08/2011 19:21:13.668143

Figure 2 shows records for the start subchannel operation (SSCH) event.

Figure 2. Example: GTF record for SSCH events

 IPCS OUTPUT STREAM ------------------------------------------ LINE 0 COLS 1 78
 COMMAND ===>                                                  SCROLL ===> CSR 
  SRB   ASCB.... 00FC1500 CPU..... 0000                                        
                          PSW..... 07040000 80000000 00000022 0217E07C         
                          R15..... 8217E050 SRB..... I                         
                          TYPE.... INITIAL DISPATCH OF SRB                     
                 GMT-01/09/2011 00:39:44.155668  LOC-01/08/2011 19:39:44.155668
  DSP   ASCB.... 00FC1500 CPU..... 0000                                        
                          PSW..... 07040000 80000078 00000000 013AB828         
                          TCB..... 006FF148 R15..... 813AB828 R0...... 006E1BC0
                          R1...... 0217E050                                    
                 GMT-01/09/2011 00:39:44.155742  LOC-01/08/2011 19:39:44.155742
  SSCH.... 00982    ASCB.... 00FB8880 CPUID... 0000     JOBN.... JES2          
                    RST..... 0FC27620 VST..... 02626620 DSID.... 006DCFEC      
                    CC...... 00       SEEKA... 00000000 15000D07               
                    GPMSK... 00       OPT..... 00       FMSK.... 00            
                    DVRID... 02       IOSLVL.. 01       UCBLVL.. 01            
                    UCBWGT.. 00       BASE.... 00982                           
                    ORB..... 00F1D4E0 13C2D081 0F1FDC68 0000FE00 00000000      
                             00000000 00000000 00000000                        
                GMT-01/09/2011 00:21:32.948888  LOC-01/08/2011 19:21:32.948888

The screen images in Figure 3 and Figure 3 show records for two input/output (IO) interruption events. The last two rows in the I/O statistics section will only appear for zHPF I/O events.

Figure 3. Example: GTF records for IO interruption events

   IO...... 00982    ASCB.... 00FB8880 CPUID... 0000     JOBN.... JES2         
                     PSW..... 07041000 80000000 00000000 05722F66              
                     IRB..... 10C04007 0FC27360 0C000000 00800002 00000000     
                     TCB..... 006FF368 SENSE... N/A      FLA..... 40           
                     OPT..... 00       DVRID... 02       IOSLVL.. 01           
                     UCBLVL.. 01       UCBWGT.. 00       BASE.... 00982        
                                                                               
                     I/O Statistics:                                           
                     Connect. 00000000 Pending. 01BE0000 Discon.. 01A80000     
                     CUQ..... 00000000 DAO..... 00000000 Devbsy.. 00000000     
                     ICMR.... 00000000 StartCt. 00000000 SamplCt. 0BEF0000     
                     ZTotdev. D7C20000 ZDefer.. 01310000 ZCUQ.... 00000000     
                     ZDevBsy. 00000000 ZDAO.... 00000000 
                     IntrDly. hhhhhhhh
                  GMT-01/09/2011 00:21:32.944548  LOC-01/08/2011 19:21:32.944548
                                                                               
   **** GTFTRACE DISPLAY OPTIONS IN EFFECT ****
 SSCH=ALL  IO=ALL  CCW=SI
 SVC=ALL  PI=ALL
 EXT  RNIO  SRM  RR  DSP  SLIP
  **** GTF DATA COLLECTION OPTIONS IN EFFECT: ****
 IO filtering requested
 CCW trace prompting
 IO CCW records
 SSCH CCW records
 All records timestamped
 SSCH prompting
 *** DATE/TIME: GMT-01/09/11 21:14:10    LOC-01/09/11 21:14:10.009827

Figure 4. Example: More GTF records for IO interruption events

                GMT-01/09/11 21:14:10.009803    LOC-01/09/11 21:14:10.009803   
  PCI..... 0000     ASCB.... 00000000 CPUID... 0000     JOBN.... ........      
                    PSW..... 00000000 00000000 00000000 00000000               
                    IRB..... 00000000 00000000 00000000 00000000 00000000      
                    TCB..... 00000000 SENSE... 0000     FLA..... 00            
                    OPT..... 00       DVRID... 00       IOSLVL.. 00            
                    UCBLVL.. 00       UCBWGT.. 00       BASE.... 00000         
                GMT-01/09/11 21:14:10.009955    LOC-01/09/11 21:14:10.009955   
  EOS..... 10000    ASCB.... 00000000 CPUID... 8861     JOBN.... ........      
                    PSW..... 00000000 00000000 00000000 00000000               
                    IRB..... 00000000 00000000 00000000 00000000 00000000      
                    TCB..... 00000000 SENSE... 0000     FLA..... 00            
                    OPT..... 00       DVRID... 00       IOSLVL.. 00            
                    UCBLVL.. 00       UCBWGT.. 00       BASE.... 00000         
                GMT-01/09/11 21:14:10.078486    LOC-01/09/11 21:14:10.078486   
  CSCH.... 10000    ASCB.... 00000000 CPUID... 0000     JOBN.... ........      
                    DEV..... 0000     SFLS.... 0000     SID..... 00000000      
                    CC...... 00       DVRID... 00       ARDID... 00            
                    IOSLVL.. 00       UCBLVL.. 00       UCBWGT.. 00            
                    BASE.... 00000                                             
                GMT-01/09/11 21:14:10.099752    LOC-01/09/11 21:14:10.099752   
  HSCH.... 10000    ASCB.... 00000000 CPUID... 8861     JOBN.... ........      
                    DEV..... 0000     SFLS.... 0000     SID..... 00000000      
                    CC...... 00       DVRID... 00       ARDID... 00            
                    IOSLVL.. 00       UCBLVL.. 00       UCBWGT.. 00            
                    BASE.... 00000                                             
                GMT-01/09/11 21:14:10.119803    LOC-01/09/11 21:14:10.119803   
   ****************************** END OF DATA ***********************************