APAR PJ46309 includes several enhancements that enrich the data in ECB trace. This enriched data provides a foundation to improve the understanding of the flow and processing that is done by an application running on the z/TPF system. All of the enriched data is available in z/TPF dumps as well as in trace log output.
Copy-on-write trace
A copy-on-write event happens when a z/TPF program updates a static variable. The static variable is in the program rather than on the ECB stack. Because z/TPF programs must be reentrant and because the static variable is in the program, a copy of the 4 KB page where the static variable resides is made when the variable is updated. The copy of the 4 KB page is used by the ECB and the actual contents of the program are not changed.
Before PJ46309, it is easy to know that copy-on-write events are happening. Data collection has copy-on-write rates. The owner names that start with ICOW for extended system work blocks (XWBs) indicate that copy-on-write events are currently being used. However, it is difficult to know exactly where the copy-on-write events are happening.
With PJ46309, copy-on-write trace is available. When copy-on-write trace is active, copy-on-write events will be reported in ECB trace in dumps, in the trace log, and in ZDECB TR command displays. The trace shows the address of the instruction that caused the copy-on-write to happen. Also, the trace shows the address of the 4 KB page that was copied.
The following example is taken from a trace log output. The PG value is the address of the page that was copied. The A value is the address of the instruction that caused the copy-on-write event.
IBM_DEFT QZZ5YZ LOADSET-DRIVER01 OBJECT-qzz5
64PU1 1 A0 QZZ5 C-O-W PG-000000009EB19000 DAA8C230 1320E86A
A-000000009EB16A58
The ZSTRC command is used to manage copy-on-write trace. To display the current status, enter the ZSTRC DISPLAY command:
==> ZSTRC DISPLAY
CSMP0097I 17.03.12 CPU-B SS-BSS SSU-HPN IS-01
STRC0013I 17.03.12 SYSTEM TRACE OPTIONS
TYPE OF SYSTEM TRACE KEYWORD STATUS
ECB TRACE TRACE ON
FUNCTION TRACE FUNCTR ON
EXTENDED FUNCTION FUNCEXT ON _
SKIP FUNCTION FUNCSKIP OFF
TPF ENTER/BACK TRACE ENTER ON
TPFDF ENTER/BACK TRACE DFENTER ON
IO TRACE IO ON
CCW TRACE CCW OFF
SYSTEM LOG SYSLOG ON
BRANCH TRACE BRANCH ON _
ECB HEAP TRACE EHEAP ON
HEAP CHECK HEAPCHECK ON
SOCKET TRACE SOCTRACE OFF
REGISTERS REGS ON
BLOCK CHECK BLKCHK ON
IBM DEBUGC TEST DEBUGIT OFF
IBM DEBUGC LOG DEBUGIL OFF _
USER DEBUGC TEST DEBUGUT OFF
USER DEBUGC LOG DEBUGUL OFF
BRANCH RELATIVE TARGET CHECK BRCHECK OFF
IDLE TIMER IDLETMR OFF
STACK VALIDATION STACKVAL ON
MYMALLOC API PROCESSING MYMALLOC ON
I-STREAM COLLAPSE TEST MODE TESTCLPS OFF _
TEST AUTOMATION TESTAUTO ON
COPY-ON-WRITE TRACE COPYWRT OFF
END OF DISPLAY+
To activate copy-on-write trace, ECB TRACE must be on and enter the ZSTRC ALTER COPYWRT command:
==> ZSTRC ALTER COPYWRT
CSMP0097I 17.03.19 CPU-B SS-BSS SSU-HPN IS-01
STRC0013I 17.03.19 SYSTEM TRACE OPTIONS
TYPE OF SYSTEM TRACE KEYWORD STATUS
ECB TRACE TRACE ON
FUNCTION TRACE FUNCTR ON
EXTENDED FUNCTION FUNCEXT ON _
SKIP FUNCTION FUNCSKIP OFF
TPF ENTER/BACK TRACE ENTER ON
TPFDF ENTER/BACK TRACE DFENTER ON
IO TRACE IO ON
CCW TRACE CCW OFF
SYSTEM LOG SYSLOG ON
BRANCH TRACE BRANCH ON _
ECB HEAP TRACE EHEAP ON
HEAP CHECK HEAPCHECK ON
SOCKET TRACE SOCTRACE OFF
REGISTERS REGS ON
BLOCK CHECK BLKCHK ON
IBM DEBUGC TEST DEBUGIT OFF
IBM DEBUGC LOG DEBUGIL OFF _
USER DEBUGC TEST DEBUGUT OFF
USER DEBUGC LOG DEBUGUL OFF
BRANCH RELATIVE TARGET CHECK BRCHECK OFF
IDLE TIMER IDLETMR OFF
STACK VALIDATION STACKVAL ON
MYMALLOC API PROCESSING MYMALLOC ON
I-STREAM COLLAPSE TEST MODE TESTCLPS OFF _
TEST AUTOMATION TESTAUTO ON
COPY-ON-WRITE TRACE COPYWRT ON
END OF DISPLAY+
Copy-on-write trace uses trace entries in macro trace.
ECB time slice
Before PJ46309, if time slice is enabled for an ECB, it is difficult to determine whether an ECB has been time sliced and how frequently an ECB has been time sliced.
With PJ46309, when an ECB is time sliced, a trace entry is added to macro trace. ECB time slice tracing is managed through ECB macro trace. If ECB macro trace is enabled, ECB time slice trace entries are available in dumps, in the trace log, and in ZDECB TR command displays.
The following example is taken from a trace log output:
IBM_DEFT QZZ5YZ LOADSET-DRIVER01 OBJECT-qzz5
64PU1 1 B0 QZZ5 SUSPND ECB SUSPENDED BY TIME SLICE DAA8C230 135B00A4
64PU1 1 AC QZZ5 SUSPND ECB SUSPENDED BY TIME SLICE DAA8C230 13D88898
Enrich variable macro parameters of various TPF macros
In ECB macro trace, most macros have variable information that provides details about the specific macro call. With PJ46309, the additional information is available for the following macros:
- CEBIC: The resultant subsystem (SS) name and subsystem user (SSU) name are included.
- CINFC: the type of request such as R, W, or K and the name of the CINFC label are included.
- CORHC: An indicator is included that reports whether the resource was held by another ECB when the CORHC macro was called. In addition, the amount of time in microseconds that the ECB waited before holding the resource is provided.
- ENQC: An indicator is included that reports whether the resource was held by another ECB when the ENQC was called. In addition, the amount of time in microseconds that the ECB waited before holding the resource is provided.
- EOWNRC: The owner name that was set is included.
- File type macros: An indicator is included that reports whether the record was only put into VFA (e.g. delay file) or whether the record was written to DASD.
- Find type macros: An indicator is included that reports whether the record was retrieved from VFA or DASD.
- SANQC: An indicator is included that reports whether the resource was held by another ECB when the SANQC macro was called. In addition, the amount of time in microseconds that the ECB waited before holding the resource is provided.
The example, which is taken from a trace log output, shows a few of the macros.
IBM_DEFT QZZ0YZ LOADSET-DRIVER01 OBJECT-qzz0
31PU1 1 24E QZZ0 EOWNRC DAA8D08B 5EEE768A
31PU1 1 250 QZZ0 OWNER CHANGE ITEST QZZ5 CHILD DAA8D08B 5EEE7F76
ECB
31PU1 1 25A QZZ0 CEBIC SS-BSS SSU-HPN DAA8D08B 5EEEA028
31PU1 1 268 QZZ0 EVNTC CORHC N-000000000FC2EE78 DAA8D08B 5EEEA400
HELD-Y T-2011189
31PU1 1 274 QZZ0 POSTC CORUC N-000000000FC2EE78 DAA8D08D 49F21F98
31PU1 1 29C QZZ0 FIWHC F-00000000D4030000 L-D2 DAA8D08D 49F25D22
ID-C1C1 VFA
31PU1 1 2A4 QZZ0 FILUC F-00000000D4030000 L-D2 DAA8D08D 49F32308
ID-C1C1 DASD
For more information about PJ46309, see the APEDIT.