In this section: |
When you submit a report request, the adapter generates calls to the IMS DBMS on your behalf. You can use the adapter trace facilities to view these calls and their results.
A trace is helpful for debugging a procedure or for adapter performance analysis. The FSTRACE, FSTRACE2, and FSTRACE4 facilities are easy to invoke and require no changes to either the adapter or user request. The trace facilities have no effect on how the adapter functions.
The adapter provides the following trace facilities:
To activate one or both of the trace facilities, allocate the corresponding trace output as described in Allocating Adapter Traces.
Note: FSTRACE, FSTRACE2 and FSTRACE4 are intended for use in query optimization and problem debugging. Do not write application programs that depend on the format or content of any trace, as these may change in later releases.
You can use FSTRACE, FSTRACE2, and FSTRACE4 in conjunction with all report requests. You can store trace output in a sequential dataset or display it online at the terminal. Use the system editor to view the file containing the trace information.
To capture trace data in a file, issue the appropriate statement from the FOCUS command level
{MVS|TSO} ALLOC F(ddname) DA('userid.ddname') SHR REU LRECL(80) RECFM(F)
or
DYNAM ALLOC FILE ddname DATASET userid.ddname - SHR REUSE LRECL 80 RECFM F
or
CMS FILEDEF ddname DISK ddname DATA A (LRECL 80 RECFM F
where:
Is FSTRACE, FSTRACE2, or FSTRACE4.
To display trace data online, specify the appropriate statement from the FOCUS command level:
{MVS|TSO} ALLOC F(ddname) DA(*) SHR REU
or
DYNAM ALLOC FILE ddname DA *
or
CMS FILEDEF ddname TERMINAL
where:
Is FSTRACE, FSTRACE2, or FSTRACE4.
To disable FSTRACE, FSTRACE2 or FSTRACE4, clear the associated allocation
{MVS|TSO} FREE F(ddname)
or
DYNAM FREE FILE ddname
or
CMS FILEDEF ddname CLEAR
where:
Is FSTRACE, FSTRACE2 or FSTRACE4.
In batch, you can write trace results to a sequential file, a partitioned dataset, or, as in the following sample allocation, to SYSOUT
//ddname DD SYSOUT=*,DCB=BLKSIZE=80
where:
Is FSTRACE, FSTRACE2, or FSTRACE4.
The following example writes the trace results to an MVS sequential dataset
//FSBATCH EXEC PGM=FOCUS //ddname DD DISP=(NEW,CATLG,KEEP),DSN=userid.ddname, // UNIT=SYSDA,VOL=SER=volid,SPACE=(TRK,(p,s)), // DCB=(LRECL=80,BLKSIZE=1600,RECFM=F)
where:
Is the user ID.
Is FSTRACE, FSTRACE2, or FSTRACE4.
Is the volume ID of the dataset that will receive the trace output.
Is the number of tracks in the primary space allocation.
Is the number of tracks in the secondary space allocation.
This TSO session traces the retrieval process for a report request. FSTRACE is allocated before the report request is issued; its results display online.
The request is as follows:
> > DYNAM ALLOC FILE FSTRACE DA * > > SET IMS=NEW > > TSO IMS SET IMSPZP 00 > > TSO IMS SET DBCTL ON > > TSO IMS SET PSB FOCSD > > TABLE FILE DI21PART > PRINT PARTKEY STANKEY > WHERE PARTKEY IN ('02AN960C10','02JAN1N976B') > END
A trace can produce extensive output; therefore, you may want to use a RECORDLIMIT test in your request to reduce the amount of redundant information you will have to examine.
The following annotated example illustrates FSTRACE results for the request. Because this particular request includes the SET commands that turn DBCTL on and select the PSB, the calls to initialize the DRA (Database Resource Adapter) and schedule the PSB are included in the trace.
Trace output is separated into sections for each call to DBCTL. Dotted lines mark the beginning and end of every section. Each individual section is also separated into two parts. The top part depicts information that the adapter passes to DBCTL. The bottom part presents the results of the call.
The numbers on the left refer to explanatory notes listed at the end of the trace.
-------------------------Calling DBCTL------------------------------ 1. Function = Initialize DRA ImdSrv=5439070 usid=USER1 ,sufx=00,susp=5486ad0,resm=5486af8,cntl=5486a28,tstx=0 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------ Function = Initialize DRA 2. ctok=1e8e8,retc=0,dbct=IMS3,usid=USER1 ,mint=0,maxt=0,timo=999 ---------------------------------------------------------------------- -------------------------Control Exit Info----------------------------- ImdSrv=5439070 func=2,sfnc=0,retc=0,rcod=0 dbct=IMS3,jobn=IMS ,rslt=0,rgty= 2,mtcb=1,dsid= 62 idtk=z::,.:9:,rsen= ,jsid= ,mxn2=0,min2=0,hit2=0,tim2=0,mxt2=0 ----------------------------------------------------------------------- -------------------------Calling DBCTL-------------------------------- 3.Function = Schedule PSB ImdSrv=5439070, ImdUsr=5456848 ctok=1e8e8,ttok=5456848,psb=FOCSD ,wrth= 1,cflg= 0,alan= 2,stat=0 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------ Function = Schedule PSB retc=0,ctk2=5457aa8,pcbl=35cc0,fpcb=35ccc,iosz=600,plan= 6,mkey=33 ---------------------------------------------------------------------- ** Before IMS call 4. There are 4 args cmd is (GU ) PCB: DI21PART00 GO 5. ssa 1 D7C1D9E3 D9D6D6E3 5C604DD7 C1D9E3D2 *PARTROOT*-(PARTK* C5E8407E 40F0F2C1 D5F9F6F0 C3F1F040 *EY = 02AN960C10 * 40404040 40405D40 * ) * -------------------------Calling DBCTL-------------------------------- Function = DLI request ImdSrv=5439070, ImdUsr=5456848 ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f9e8,alan= 2 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------ Function = DLI request ImdSrv=5439070, ImdUsr=5456848 retc=0,segl=50 ---------------------------------------------------------------------- ** After IMS call .
6. PCB: DI21PART01 GO feedback len is (17) feedback area: F0F2C1D5 F9F6F0C3 F1F04040 40404040 *02AN960C10 * 40 * * 7. io buff: F0F2C1D5 F9F6F0C3 F1F04040 40404040 *02AN960C10 * 40404040 40404040 4040E6C1 E2C8C5D9 * WASHER* 40404040 40404040 40404040 40404040 * * 40400000 00000000 00000000 00000000 * * 00000000 00000000 00000000 00000000 * * ** Before IMS call 8. There are 5 args cmd is (GU ) PCB: DI21PART01 GO 9. ssa 1: PARTROOT*U ssa 2 E2E3C1D5 C9D5C6D6 5C604040 *STANINFO*- * -------------------------Calling DBCTL-------------------------------- Function = DLI request ImdSrv=5439070, ImdUsr=5456848 ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f710,alan= 2 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------- Function = DLI request ImdSrv=5439070, ImdUsr=5456848 retc=0,segl=85 ---------------------------------------------------------------------- ** After IMS call ** PCB: DI21PART02 GO feedback len is (19) feedback area: F0F2C1D5 F9F6F0C3 F1F04040 40404040 *02AN960C10 * 40F0F2 * 02 * io buff: F0F24040 40404040 40404040 40404040 *02 * 4040F7F4 F2404040 40404040 40404040 * 742 * 40404040 40404040 40404040 404040F1 * 1* F2F0F040 40F1F440 40404040 40F0F6C3 *200 14 06C* 40404040 4040F0F6 C3404040 40404040 * 06C * ** Before IMS call
10.There are 5 args cmd is (GN ) PCB: DI21PART02 GO ssa 1: PARTROOT*U ssa 2 E2E3C1D5 C9D5C6D6 5C604040 *STANINFO*- * -------------------------Calling DBCTL-------------------------------- Function = DLI request ImdSrv=5439070, ImdUsr=5456848 ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f710,alan= 2 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------ Function = DLI request ImdSrv=5439070, ImdUsr=5456848 retc=0,segl=0 ---------------------------------------------------------------------- ** After IMS call 11. PCB: DI21PART01GEGO feedback len is (17) feedback area: F0F2C1D5 F9F6F0C3 F1F04040 40404040 *02AN960C10 * 40 * * io buff: F0F24040 40404040 40404040 40404040 *02 * 4040F7F4 F2404040 40404040 40404040 * 742 * 40404040 40404040 40404040 404040F1 * 1* F2F0F040 40F1F440 40404040 40F0F6C3 *200 14 06C* 40404040 4040F0F6 C3404040 40404040 * 06C * ** Before IMS call ** There are 4 args cmd is (GN ) PCB: DI21PART01GEGO ssa 1 D7C1D9E3 D9D6D6E3 5C604DD7 C1D9E3D2 *PARTROOT*-(PARTK* C5E8407E 40F0F2C1 D5F9F6F0 C3F1F040 *EY = 02AN960C10 * 40404040 40405D40 * ) *
-------------------------Calling DBCTL--------------------------------
Function = DLI request
ImdSrv=5439070, ImdUsr=5456848
ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f9e8,alan= 2
----------------------------------------------------------------------
-------------------------Back from DBCTL------------------------------
Function = DLI request
ImdSrv=5439070, ImdUsr=5456848
retc=0,segl=0
----------------------------------------------------------------------
** After IMS call **
PCB: DI21PART00GEGO
feedback len is (0)
feedback area:
io buff:
F0F24040 40404040 40404040 40404040 *02 *
4040F7F4 F2404040 40404040 40404040 * 742 *
40404040 40404040 40404040 404040F1 * 1*
F2F0F040 40F1F440 40404040 40F0F6C3 *200 14 06C*
40404040 4040F0F6 C3404040 40404040 * 06C *
** Before IMS call
12.There are 4 args
cmd is (GU )
PCB: DI21PART00GEGO
ssa 1
D7C1D9E3 D9D6D6E3 5C604DD7 C1D9E3D2 *PARTROOT*-(PARTK*
C5E8407E 40F0F2D1 C1D5F1D5 F9F7F6C2 *EY = 02JAN1N976B*
40404040 40405D40 * ) *
-------------------------Calling DBCTL--------------------------------
Function = DLI request
ImdSrv=5439070, ImdUsr=5456848
ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f9e8,alan= 2
----------------------------------------------------------------------
-------------------------Back from DBCTL------------------------------
Function = DLI request
ImdSrv=5439070, ImdUsr=5456848
retc=0,segl=50
----------------------------------------------------------------------
** After IMS call **
PCB: DI21PART01 GO
feedback len is (17)
feedback area:
F0F2D1C1 D5F1D5F9 F7F6C240 40404040 *02JAN1N976B *
40 * *
io buff:
F0F2D1C1 D5F1D5F9 F7F6C240 40404040 *02JAN1N976B *
40404040 40404040 4040C4C9 D6C4C540 * DIODE *
C3D6C4C5 60C14040 40404040 40404040 *CODE-A *
4040F040 40F1F440 40404040 40F0F6C3 * 0 14 06C*
40404040 4040F0F6 C3404040 40404040 * 06C *
** Before IMS call **
There are 5 args
cmd is (GU )
PCB: DI21PART01 GO
ssa 1: PARTROOT*U
ssa 2
E2E3C1D5 C9D5C6D6 5C604040 *STANINFO*- *
-------------------------Calling DBCTL-------------------------------- Function = DLI request ImdSrv=5439070, ImdUsr=5456848 ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f710,alan= 2 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------ Function = DLI request ImdSrv=5439070, ImdUsr=5456848 retc=0,segl=85 ---------------------------------------------------------------------- ** After IMS call ** PCB: DI21PART02 GO feedback len is (19) feedback area: F0F2D1C1 D5F1D5F9 F7F6C240 40404040 *02JAN1N976B * 40F0F2 * 02 * io buff: F0F24040 40404040 40404040 40404040 *02 * 4040F7F4 F2404040 40404040 40404040 * 742 * 40404040 40404040 40404040 404040F1 * 1* F2F0F040 40F7F240 40404040 40F0F6C3 *200 72 06C* 40404040 4040F0F6 C3404040 40404040 * 06C * ** Before IMS call ** There are 5 args cmd is (GN ) PCB: DI21PART02 GO ssa 1: PARTROOT*U ssa 2 E2E3C1D5 C9D5C6D6 5C604040 *STANINFO*- *
-------------------------Calling DBCTL-------------------------------- Function = DLI request ImdSrv=5439070, ImdUsr=5456848 ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f710,alan= 2 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------ Function = DLI request ImdSrv=5439070, ImdUsr=5456848 retc=0,segl=0 ---------------------------------------------------------------------- ** After IMS call ** PCB: DI21PART01GEGO feedback len is (17) feedback area: F0F2D1C1 D5F1D5F9 F7F6C240 40404040 *02JAN1N976B * 40 * * io buff: F0F24040 40404040 40404040 40404040 *02 * 4040F7F4 F2404040 40404040 40404040 * 742 * 40404040 40404040 40404040 404040F1 * 1* F2F0F040 40F7F240 40404040 40F0F6C3 *200 72 06C* 40404040 4040F0F6 C3404040 40404040 * 06C * ** Before IMS call ** There are 4 args cmd is (GN ) PCB: DI21PART01GEGO ssa 1 D7C1D9E3 D9D6D6E3 5C604DD7 C1D9E3D2 *PARTROOT*-(PARTK* C5E8407E 40F0F2D1 C1D5F1D5 F9F7F6C2 *EY = 02JAN1N976B* 40404040 40405D40 * ) *
-------------------------Calling DBCTL-------------------------------- Function = DLI request ImdSrv=5439070, ImdUsr=5456848 ctok=1e8e8,ctk2=5457aa8,ttok=5456848,clst=1f9e8,alan= 2 ---------------------------------------------------------------------- -------------------------Back from DBCTL------------------------------ Function = DLI request ImdSrv=5439070, ImdUsr=5456848 retc=0,segl=0 ---------------------------------------------------------------------- ** After IMS call ** PCB: DI21PART00GEGO feedback len is (0) feedback area: io buff: F0F24040 40404040 40404040 40404040 *02 * 4040F7F4 F2404040 40404040 40404040 * 742 * 40404040 40404040 40404040 404040F1 * 1* F2F0F040 40F7F240 40404040 40F0F6C3 *200 72 06C* 40404040 4040F0F6 C3404040 40404040 * 06C *
-------------------------Calling DBCTL-------------------------------
13.Function = Prepare for Commit
ImdSrv=7e080c8, ImdUsr=7e18578
ctok=21840,ctk2=7ebb530,ttok=7e18578,stcd=7d52fb0
----------------------------------------------------------------------
-------------------------Back from DBCTL------------------------------
Function = Prepare for Commit
retc=0,stcd=3,
----------------------------------------------------------------------
-------------------------Calling DBCTL--------------------------------
Function = Commit - Terminate
ImdSrv=7e080c8, ImdUsr=7e18578
ctok=21840,ctk2=7ebb530,ttok=7e18578,rtok=c4d6c3e2
----------------------------------------------------------------------
-------------------------Back from DBCTL------------------------------
Function = Commit - Terminate
retc=0
----------------------------------------------------------------------
-------------------------Calling DBCTL--------------------------------
Function = Terminate thread
ImdSrv=7e080c8, ImdUsr=7e18578
ctok=21840,ctk2=7ebb530,ttok=7e18578----------------------------------
-------------------------Back from DBCTL------------------------------
Function = Terminate thread
retc=0
----------------------------------------------------------------------
NUMBER OF RECORDS IN TABLE= 2 LINES= 2
PAUSE.. PLEASE ISSUE CARRIAGE RETURN WHEN READY
The trace shows the following:
This call is a GU call. The PCB contains the database name, DI21PART, and the PROCOPT, GO.
A dump has a left side and a right side. The left side shows the hexadecimal values in the memory locations. The right side, delimited by *'s, contains the corresponding alphanumeric characters. Since not all hexadecimal values represent printable alphanumeric characters, those parts of the dump that correspond to non-printable characters display as blanks on the right side. In particular, if a comparison value in an SSA is a packed number, it displays as blank on the right-hand side of the dump.
In this case, PARTKEY is an alphanumeric field, so the comparison value, 02AN960C10, is also alphanumeric and displays in the trace. The adapter constructs a qualified SSA that includes the segment name, PARTROOT, and the logical expression, PARTKEY=02AN960C10.
When there are no selection criteria for a segment, the adapter constructs an SSA that contains only the segment name.
The second SSA is for the STANINFO segment (the FOCUS request prints the STANKEY field from this segment). Since the request contains no selection criteria on this segment, the SSA is unqualified and contains only the segment name. This call retrieves a STANINFO segment with STANKEY = 02 (see the feedback area and I/O buffer).
The following report is generated:
PAGE 1 PARTKEY STANKEY ------- ------- 02AN960C10 02 02JAN1N976B 02
When you allocate FSTRACE4 in the DBCTL environment, the trace provides statistics about the number of calls made, enqueues, waits, and buffers. The following example illustrates FSTRACE4 results in this environment:
> > DYNAM ALLOC FILE FSTRACE4 DA * > > TABLE FILE DI21PART > PRINT PARTKEY STANKEY > WHERE PARTKEY IN ('01AN960C10','02JAN1N976B') > END
The resulting trace provides the SSA buffer and the UOR statistics:
set up SSA-Q: D7C1D9E3 D9D6D6E3 5C604DD7 C1D9E3D2 *PARTROOT*-(PARTK* C5E8407E 40F0F1C1 D5F9F6F0 C3F1F040 *EY = 01AN960C10 * 40404040 40405D40 * ) * set up SSA-Q: D7C1D9E3 D9D6D6E3 5C604DD7 C1D9E3D2 *PARTROOT*-(PARTK* C5E8407E 40F0F2D1 C1D5F1D5 F9F7F6C2 *EY = 02JAN1N976B* 40404040 40405D40 * ) * set up SSA-Q: E2E3C1D5 C9D5C6D6 5C604040 *STANINFO*- * -------------------------UOR Statistics--------------------------------- GU calls=3,GN calls=2,GNP calls=0,GHU calls=0,GHN calls=0,GHNP calls=0, ISRT calls=0,DLET calls=0,REPL calls=0,Total DLI calls=5, Test ENQ=0,Waits for Test ENQ=0,Test DEQ=0,Update ENQ=0,Waits for Updt ENQ=0,U p Exclusive ENQ=0,Waits on Exclusive ENQ=0,Exclusive DEQ=0, DEDB Calls=0,DEDB Reads=0,Overflow Buffers Used=0,UOW Contentions=0, Waits for DEDB Buffers=0,Schedule Seq Number=998, Elapsed UOR CPUTIME (Timer units)=209. -----------------------------------------------------------------------
If your request seems to take a long time, you may want to allocate FSTRACE4 to see if any of the numbers are very high. Enqueues become a factor depending on the PROCOPT you use.
Information Builders |