Using the FTP client API trace

The FTP client API trace is used to debug problems in the interface or record activity and data that are returned to the interface that might not otherwise be available to the application (see TERM). The interface trace cannot be used to debug errors in the trace itself or any error that prevents the interface from accessing the trace data set. The trace writes records for interface events, which include requests to the interface, the results of interface requests, and output from the client. Client output includes client messages, server replies, list data, and DEBUG and DUMP trace data that is received from the client.

The FTP client API trace is controlled by a statement that is coded in the FTP.DATA file for the FTP client. The statement is named TRACECAPI and is described in z/OS Communications Server: IP Configuration Reference.

Tip: The FTP client API trace does not include trace records for the FTP client API for REXX function package. See FTP client API for REXX function for information about trace records for the FTP client API for REXX function package.

Rule: If using the Trace Resolver facility, the trace should be activated by specifying the RESOLVER_TRACE environment variable to collect the trace information in a file or MVS™ dataset.

The following table lists the settings accepted for TRACECAPI.

If the statement is coded with a value of	Then . . .	Notes
ALL	all interface events are traced.	n/a
NONE	no events are traced.	n/a
CONDITIONAL	events are traced only when requested by the user program. This is the default.	The user program can request that events be traced by setting the FCAI_TraceIt field. FCAI_Traceit_Yes indicates that events are traced by the interface; FCAI_Traceit_No indicates that events are not traced.

The settings in the following two fields in the FCAI are applicable when the interface trace is initialized (the interface trace is initialized by the first request that requests tracing):

FCAI_TraceSClass
The interface trace is written to a spool file of the SYSOUT class supplied in FCAI_TraceSClass. Valid values are in the range A––Z and 0––9. The default value is A. The first request that is traced allocates and opens the spool file. When the trace file is opened, its ddname is placed in FCAI_TraceName. After the file is opened, it stays open until a TERM request is processed.
FCAI_TraceID
The user program can request that an ID be placed at the start of each trace record. This is done by putting a 3-byte character ID string in the field FCAI_TraceID. This value is written as the first three characters of each trace record. The trace ID is placed on each record to uniquely identify records from the same process. Trace records from different processes are written to different spool files. The ID ensures that records retain their identity when aggregated. The following example shows the trace records if FCAI_TraceID=TRC:
```
TRC INIT>-a never
TRC INIT<00000000 00000000 00000000 00000000
TRC SCMD>open 9.42.105.93 6321|W
```

At the top of the trace output and every 64 lines thereafter, the interface writes a header record to provide information about the trace records being written. The header record contains the FCAI_TraceID, the updated date and time, the decimal value of process ID (pid) of the created z/OS® client, and the decimal value of the TCB address for the user program's task. The following is a sample header record:

  ID-PAW  Date-02/26/2004  Time-21:16:31  Process ID-0000000067108873  TCB Address-000000008256584

The following example uses a sample trace for a very simple session with the FTP client API to show the format of the trace. The lines are numbered for the discussion of the trace; that is, the numbers do not appear in an actual trace. This trace shows requests, request results, and also client messages, server replies, and debug traces entries. The FCAI_TraceID value is 0, so each trace record is preceded by three blank characters (not reflected in this example). Also, the trace header records are not shown in the example.

 1  PAW INIT>-a never |_CEE_DMPTARG=/etc
 2  INIT<00000000 00000000 00000000 00000000
 3  SCMD>open 9.42.105.93 6321|W
 4  Connecting to:   9.42.105.93 port: 6321.
 5  220-FTPDJG1 IBM FTP CS V1R6 at MVS164, 14:44:15 on 2007.
 6  220 Connection will not timeout.
 7  Command(00-10-    -220):
 8  SCMD<00000000 0A000000 00000000 00000000
 9  SCMD>user user33
10  >>> USER user33
11  331 Send password please.
12  Command(00-19-USER-331):
13  SCMD<01020000 13000000 00000000 00000000
14  SCMD>pass ******
15  >>> PASS
16  230 USER33 is logged on.  Working directory is "/u/user33".
17  Command(00-26-PASS-230):
18  SCMD<00000000 1A000000 00000000 00000000
19  SCMD>debug fsc
20  Active client traces - FSC(1)
21  Command(00-11-    -   ):
22  SCMD<00000000 0B000000 00000000 00000000
23  SCMD>get a abc111 (repl|W
24  CG0226 get: F=1 p=FSA ARTWT=00001
25  CG3531 rcvFile: entered
26  MR1278 set_filename: entered with pathname abc111
27  CG1359 hfs_rcvFile: entered
28  MF0750 seq_open_file: recfm is NONE
29  MF1068 seq_open_file: OSBN -> wb,recfm=*,NOSEEK
               for /u/user33/abc111
30  MF1216 seq_open_file: stream 166412C4 has maxreclen 0
31  >>> PORT 9,42,105,93,4,25
32  200 Port request OK.
33  >>> RETR a
34  125 Sending data set /u/user33/a
35  CU2009 write_smf_record: entered with type 16.
36  CU1474 write_smf_record_119: entered with type 16.
37  TI1120 write_stream: O=0 HGPES=10000 BCTE=0000 RLB=0/0/0
38  MF0632 seq_close_file: file closed
39  250 Transfer completed successfully.
40  200 bytes transferred in 0.010 seconds.  Transfer rate
              20.00 Kbytes/sec
41  CU2009 write_smf_record: entered with type 16.
42  CU1474 write_smf_record_119: entered with type 16.
43  CU2279 write_smf_record: length of smfrecord: 240
44  Command(00-16-RETR-250):
45  SCMD<00000000 10000000 00000000 00000000
46  SCMD>QUIT|W  (Generated by TERM)
47  >>> QUIT
48  221 Quit command received. Goodbye.
49  SCMD<00000000 13000000 00000000 00000000
50  TERM>
51  TERM<00000000 00000000 00000000 00000000

Line  1: This is the INIT request to the interface.  The character >
         shows the direction of the flow.  The character | is used to
         separate the start options "-a never" from the environment
         variable "_CEE_DMPTARG=/etc" that was passed on the spawn. Each
         parameter passed to the FTP client in the start options is
         separated from what follows in the trace by a null. Nulls should
         not be inserted into the start options by the application program
         (an ending null is permissible). The nulls in the trace are a
         result of the parsing mechanism that the interface uses to build
         the argument list for the spawn of the client.
Line  2: This is the result of the request from the interface. The
         character < shows the direction of flow.  The four words of
         output are the "Request Completion Values" from the FCAI.
         The values are in hexadecimal and do not display as shown 
         here. The 00 in byte 0 indicates successful initialization
         of the interface.  
Line  3: This is the first subcommand.  The subcommand string is displayed.
         If a mode parameter is entered, it is displayed following the
         character |.  The character | is used to separate parameters in
         all of the request records.  In this example, the user program
         entered a W for wait mode.
Line  4: This is a client message. 
Line  5: This is the first line of the 220 server reply.
Line  6: This is the last line of the 220 server reply.
Line  7: This is the client message that indicates the end of the
         subcommand.  The result is 00 (no errors) for the open (subcommand
         code decimal 10).  The client subcommand caused a connect to the
         server but no server command actually flowed -- so the command
         field has four blanks. However, the last reply from the server
         was the 220 reply.
Line  8: These are the completion results for the open subcommand.  The
         results in byte 0 are 00 (OK).  The x'0A' in the second word
         is the open subcommand code in hexadecimal.
Line  9: Another subcommand. This time the user program did not pass a mode 
         parameter (default mode is wait).
Line 10: This line shows the client message indicating a command to the
         server.
Line 11: This line shows the server reply which requests a password.
Line 12: This line shows as result of 00 (no errors) for the user
         subcommand (code 19).  The last server command was USER and
         the last reply was 331.
Line 13: This line contains the completion results for the user subcommand.
         The x'01' in byte 0 indicates that there is additional status.
         The x'02' in byte 1 indicates that the user program is prompted
         for a pass subcommand.
Line 14: This is the pass subcommand.  ****** is displayed to keep the
         actual password out of the trace.
Line 15: This line shows the client message indicating a command to the
         server.
Line 16: This line shows the server reply.
Line 17: This line shows a result of 00 (OK) for the pass subcommand
         (code 26).  The last server command was PASS and the last reply
         was 230 -- the user program is logged in.
Line 18: This line shows the completion results for the pass subcommand.
Line 19: This line shows a subcommand to activate one of the client traces.
Line 24: This line is a client trace entry.
Line 45: This line shows a result of 00 (no errors) for the get subcommand
         (code 16).  The last server command was RETR and the last reply
         was 250 -- the file transfer completed successfully.
Line 46: This line shows a quit subcommand that was generated by a request to
         terminate the interface. The user program failed to issue a QUIT to stop
         the client so TERM automatically generated a QUIT on behalf of the
         application.
Line 50: This line shows a request to end the interface to the Client
         API.
Line 51: The interface has ended.

The following example shows a portion of a trace after logging in and before the interface ends; this example shows some of the errors that can be reported by the trace.

 1  OOPS>
 2  OOPS<02000200 00000000 00000000 00000000 
 3  SCMD>
 4  SCMD<02000300 00000000 00000000 00000000
 5  GETL>D
 6  GETL<02004000 00000000 00000000 00000000
 7  GETL>FIND|J
 8  GETL<02004100 00000000 00000000 00000000
 9  POLL>
10  POLL<02003000 00000000 00000000 00000000
11  SCMD>get ! abc111 (rep|
12  >>> PORT 9,42,105,93,4,17
13  200 Port request OK.
14  >>> RETR !
15  501 Invalid data set name "!".  Use MVS Dsname conventions.
16  Command(02-16-RETR-501):
17  SCMD<03000002 10000000 00000000 00000000
18  SCMD>get a 'user33.aaaaaaaaaaaaaaaaa'|
19  Invalid local file identifier
20  Command(18-16-    -   ):
21  SCMD<03000012 10000000 00000000 00000000

Line  1: This is a request type that is unknown to the interface.
Line  2: The results in byte 0 are 02 (interface error) with an explanation
         in byte 2 of 02 (unknown request).
Line  3: The SCMD request has no parameters.
Line  4: The results in byte 0 are 02 (interface error) with an explanation
         in byte 2 of 03 (parameter missing).
Line  5: The GETL request has an unknown operation value.
Line  6: The results in byte 0 are 02 (interface error) with an explanation
         in byte 2 of 40 (decimal 64) (unknown operation)
Line  7: The GETL request has an unknown type value for the Find operation.
Line  8: The results in byte 0 are 02 (interface error) with an explanation
         in byte 2 of 41 (decimal 65) (unknown type)
Line  9: This is a POLL request when a prior subcommand is not in
         progress.
Line 10: The results in byte 0 are 02 (interface error) with an explanation
         in byte 2 of 30 (decimal 48) (request not in progress)
Line 11: This SCMD request has a get with a bad remote file identifier.
         Commands are sent to the server (see lines 12 to 15).
Line 16: This line shows a result of 02 (server error) for the get 
         subcommand (code 16).  The last server command was RETR and the
         last reply was 501 -- an error reply.  
Line 17: This line contains the completion results for the get subcommand.
         The result in byte 0 is 03 (FTP error).  The client error code in 
         byte 3indicates that the FTP server detected the error.
Line 18: This SCMD request has a get with a bad local file identifier. No
         command is sent to the server.
Line 20: This line shows a result of 18 (file access error) for the get 
         subcommand (code 16).  Since no command was sent to the server,
         the last server command and last reply are blanks.
Line 21: This line contains the completion results for the get subcommand.  
         The result in byte 0 is 03 (the FTP client returned an error).
         The client error code in byte 3 indicates that the FTP client 
         could not access a local file.