longpelaexpertise.com.au/ezine/TraceBeginners.php?ezinemode=printfriend

LongEx Mainframe Quarterly - May 2012

technical: z/OS Tracing for Beginners

One of the best kept secrets about z/OS are its tracing features. z/OS comes with free, powerful tracing features that in many ways match those of expensive monitoring products. In this article, we look at the z/OS tracing options.

System Trace

Got an abend, and want to know what was happening just before it? You need the z/OS System Trace. The z/OS System Trace is a trace that tracks basic z/OS events, things like:

  • SVC calls
  • Abends
  • I/O to disk or tape
  • Cross Memory calls
The good news is that the System Trace does not use up much CPU, and it is always on. No way to turn it off. System Trace entries are recorded in the Trace address space, and included in any system dump - including an SVC dump and SYSMDUMP. To look at System Trace entries, you can use IPCS to analyse an unformatted dump, or browse a formatted dump (like SYSUDUMP). The IPCS SYSTRACE command formats the System Trace entries, producing something like this. 
--------------------------------------------------- SYSTEM TRACE TABLE ---
--                                                  ------------------   
--                                                  ------------------   
PR ASID WU-ADDR- IDENT  CD/D PSW----- ADDRESS-  UNIQUE-1 UNIQUE-2 UNIQUE-3
                                                UNIQUE-4 UNIQUE-5 UNIQUE-6
 
00-004C 008EA818  SVC      1 078D1000 815c684A  00055BB0 00000001 FFFAA150
00-004C 008EA818  SVCR     1 078D1000 815c684A  808DD798 00000001 FFFAA150
00-004C 01E8A508  SRB        070C0000 815c694A  0000003E 11089E00 11089E2C
                                                008ABCE0 80  
00-004C 00000000  SSRV     2          815c6968  00069350 7F000000 00000000
                                                00000000

At first glance this looks daunting, but it's not that difficult to understand. The System Trace works on every processor, and then merged together. So you'll see the processor ID in the PR column. The date and time is also shown, as well as the event. In this case, you can see events such as SVC 1 (Wait), SRB an SRB was scheduled), and SVCR (return from SVC). You may also see SVC D for an abend (SVC 13) - this is the actual abend itself.

The IPCS SYSTRACE command will format the entire System Trace, which will be very large. Most users will want to use the IPCS SYSTRACE ASID(xxx) to limit the traces to a specific address space. IPCS also has a panel to selectively format the system trace.

The System Trace can also be setup to trace any branches (BASR, BALR, BASSM and BAKR) using the z/OS TRACE console command. Branch tracing is expensive - your entire CPU usage will jump dramatically. In reality, you will never use this.

You can find out more about the System Trace from Jerry Ng's excellent presentation at the August 2011 SHARE conference.

The z/OS Diagnostic Tools and Service Aids manual gives all the information about the System Trace, and how to read it.

Master Trace

The Master Trace is a trace of recently issued z/OS system messages. It is automatically activated, but can be turned on and off using the z/OS TRACE console command. It is a good idea, and standard practice to leave the Master Trace running at all times - it doesn't use much CPU.

The Master Trace is really helpful when determining what was happening in the z/OS system just before an event. For example, finding out if any errors occurred just before an abend. The Master Trace is included in any system dump. IPCS is the weapon of choice for seeing Master Trace entries - using the IPCS VERBEXIT MTRACE command to format the entries.

Generalized Trace Facility (GTF)

If you need more detail than the System Trace gives, GTF is the next tool to pull from your toolbox. GTF is an incredibly powerful tracing facility. GTF doesn't run by default, and that's because it uses a lot of CPU to run. GTF is only run for short periods to analyse a problem, and then stopped.

By default GTF records pretty much the same information as the System Trace, but in less detail. But GTF has facilities to tailor exactly what will be traced: which events, which tasks and which address spaces. For example, you can trace any abends or I/O operations for an individual job. Some z/OS components also can send trace information to GTF. For example, GTF can trace every VTAM operation, or every dataset open and close. GTF can also be setup to trace any storage getmain or freemain - a very handy tool for diagnosing storage problems. This special purpose GTF trace is called the Getmain Freemain Storage trace, or GFS trace, and is activated using the TRACE command, or from DIAGxx parmlib members. GTF's tracing features step up a gear when used with z/OS SLIP traps. SLIP traps can be setup to trap events such as when an abend occurs, a range of addresses in storage is accessed, or a certain module (or part of a module) is executed. This SLIP information can be recorded by GTF. However these facilities should be used with caution - they will use up a lot of CPU.

User programs can also use the power of GTF. The z/OS GTRACE macro can be used to send trace entries to GTF (if it is running). Some program products use this as a tracing mechanism for problem determination.

GTF is started as a started task - started with the z/OS START command, stopped with the STOP command. Data collection parameters are in SYS1.PARMLIB, or set by replying to the GTF outstanding z/OS message when GTF starts. GTF Trace entries are written to storage in the GTF address space (less expensive) or to a dataset on disk (far more expensive). GTF data in storage can be included in any system dump, and formatted from IPCS using the IPCS GTFTRACE command. GTF VTAM commands are formatted using the VTAM ACF/TAP program.

The z/OS Diagnostic Tools and Service Aids manual is the place to find out all about GTF, and how to read the GTF output.

Component Traces

Component Traces are component-specific traces that are intended for use by vendor support staff. Although not intended for normal use, they can be handy on the rare occasions when you need to know a little more about what is happening under the covers. The Component Trace is really a z/OS facility that any software product can use - though currently the main users are z/OS components.

The z/OS D TRACE command shows the component traces that are active. z/OS has many component traces that are active by default, and it's a good idea to leave these as they are. These default values are usually efficient and don't use up much CPU. Adding extra component traces can be very expensive, and should only be done if your vendor's support staff request it, and turned off soon after. They are activated using the z/OS CT command, with options and parameters in SYS1.PARMLIB members. Component Traces are formatted and viewed from IPCS using the IPCS CTRACE command. TCP/IP is an example of how Component Traces can be handy. When performing TCP/IP problem determination, network engineers may need to start an IP packet trace: a Component Trace specific to TCP/IP.

Transaction Trace

The Transaction Trace is a relatively new z/OS feature designed as a central point for tracking application units of work that run on more than one system. For example, an IMS transaction that accesses IMS databases in a remote IMS subsystem.

It doesn't provide a lot of detail, but is useful to find out where a unit of work was processed. Transaction Trace entries are viewed from IPCS using the IPCS CTRACE COMP(SYSTTRC) command.

Conclusion

It's easy to forget about the z/OS trace options - you're not going to use them very often. However these options are really powerful, and can be invaluable when you have that difficult problem to figure out. IBM manuals hold the information you need in a format that isn't too difficult to read. Redbooks such as the z/OS Diagnostic Data Collection and Analysis can also help.


David Stephens