z/OS Communications Server
Diagnosing FTP Server Problems


Now that you have decided to start the investigation with the FTP Server, the next step is to determine at what point in the Daemon/Server process the error occurs (click here to skip the tutorial information). A typical FTP Daemon/Server iteration can be broken into four phases:

The following output shows a typical FTP session, broken into these four categories. Note that this output reflects tracing taken at the FLO trace point (clicking on the hypertext portions of the trace output will produces a brief explanation of that particular message's importance).

DAEMON INITIALIZATION
   ftpd[50331663]: EZYFT18I Using catalog '/usr/lib/nls/msg/C/ftpdmsg.cat' for FTP messages.
   ftpd[50331663]: EZY2697I IBM FTP CS V1R7 11:04:08 on 09/01/05
   ftpd[50331663]: EZY2640I Using dd:SYSFTPD=SYS1.TCPPARMS(FTPDATA) for local site configuration parameters.
   ftpd[50331663]: EP0615 processStatement: entered
   ftpd[50331663]: EP1846 get_bool_val: entered
   ftpd[50331663]: EP0615 processStatement: entered
   ftpd[50331663]: EP1846 get_bool_val: entered
   ftpd[50331663]: GU1355 get_recfm_values: entered
   ftpd[50331663]: EP2426 check_anonymous_keyword_consistency: entered
   ftpd[50331663]: EP2505 check_utf8_keyword_consistency: entered
   ftpd[50331663]: EZYFT21I Using catalog '/usr/lib/nls/msg/C/ftpdrply.cat' for FTP replies.
   ftpd[50331663]: DM1909 check_anonymous_configuration: entered
   ftpd[50331663]: NX0215 setup_translate_tables: entered
   ftpd[50331663]: NX0943 read_xlate_files: entered
   ftpd[50331663]: EZY2693I Unable to open //'FTPD.SRVRFTP.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: EZY2693I Unable to open //'TCPCS.SRVRFTP.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: EZY2693I Unable to open //'FTPD.STANDARD.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: EZY2693I Unable to open //'TCPCS.STANDARD.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: NY0384 build_ctrl_tables: entered
   ftpd[50331663]: EZYFT26I Using 7-bit conversion derived from 'ISO8859-1' and 'IBM-1047' for the control connection.
   ftpd[50331663]: NX0943 read_xlate_files: entered
   ftpd[50331663]: EZY2693I Unable to open //'FTPD.SRVRFTP.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: EZY2693I Unable to open //'TCPCS.SRVRFTP.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: EZY2693I Unable to open //'FTPD.STANDARD.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: EZY2693I Unable to open //'TCPCS.STANDARD.TCPXLBIN : DSSTAT rcode = -1
   ftpd[50331663]: EZYFT32I Using the same translate tables for the control and data connections.
   ftpd[50331663]: EP2165 set_dbcs_langs: entered
   ftpd[83886094]: DM0872 main: Using /usr/lib/nls/msg/%L/%N for nlspath.
   ftpd[83886094]: DM0898 main: Using C for lang value.
   ftpd[83886094]: DM0910 (00) main: a2e table for control connection
         (EDITOR'S NOTE: ASCII to EBCDIC Translation Table Dump removed for brevity)
   ftpd[83886094]: DM0912 (00) main: e2a table for control connection
         (EDITOR'S NOTE: EBCDIC to ASCII Translation Table Dump removed for brevity)
   ftpd[83886094]: DM0915 (00) main: n2f table for data connection
         (EDITOR'S NOTE: ASCII to EBCDIC Translation Table Dump removed for brevity)
   ftpd[83886094]: DM0917 (00) main: f2n table for data connection
         (EDITOR'S NOTE: EBCDIC to ASCII Translation Table Dump removed for brevity)
   ftpd[83886094]: EZYFT09I system information for MVS057: z/OS version 1 release 7 (2064)
   ftpd[83886094]: DM1393 main: environment variable: _EDC_ADD_ERRNO2=1
   ftpd[83886094]: EZY2700I Using port FTP control (21)
   ftpd[83886094]: EZY2701I Inactivity time is 300
   ftpd[83886094]: SD0297 accept_client: entered
   ftpd[83886094]: SD1406 setup_daemon_socket: entered
   ftpd[83886094]: SD1424 setup_daemon_socket: socket() failed - EDC8114I Address family not supported. (errno2=0x112B0000)
   ftpd[83886094]: SD1309 resolveHostName: entered
   ftpd[83886094]: SD1982 daemon_op_message: entered
   ftpd[83886094]: GU2344 sendopm: entered
   ftpd[83886094]: EZY2702I Server-FTP: Initialization completed at 11:04:19 on 09/01/05.
   ftpd[83886094]: EZYFT41I Server-FTP: process id 83886094, server job name FTPD1
   ftpd[83886094]: GU1011 chkVerRel: entered

CLIENT CONNECT AND FORKING OF SERVER PROCESS
   ftpd[83886094]: SD1735 handle_client_socket: entered for socket 7
   ftpd[83886094]: SD1099 spawn_ftps: entered
   ftpd[67108879]: SD0503 reply: entered
   ftpd[67108879]: SD0503 reply: entered
   ftpd[67108879]: SD0750 setup_new_pgm: entered
   ftpd[67108879]: SD0629 applyTraceFilters: entered
   ftpd[67108879]: SD0629 applyTraceFilters: entered
   ftps[67108879]: SR3566 stat_session: entered
   ftps[67108879]: GU1011 chkVerRel: entered
   ftps[67108879]: PR0291 parse_cmd: entered
   ftps[67108879]: SR0319 clear_reply_sent: entered
   ftps[67108879]: SR1031 get_command: entered

CLIENT LOGON
   ftps[67108879]: FR0503 authCmdCheck: entered with cmd 19
   ftps[67108879]: PR1455 parse_ebcdic: entered
   ftps[67108879]: PR0825 onearg_cmd: entered
   ftps[67108879]: RA1523 user: entered with username 'user119'.
   ftps[67108879]: SR2907 reply: entered
   ftps[67108879]: SR3719 usingUTF8: entered
   ftps[67108879]: SR0319 clear_reply_sent: entered
   ftps[67108879]: SR1031 get_command: entered
   ftps[67108879]: FR0503 authCmdCheck: entered with cmd 26
   ftps[67108879]: PR1455 parse_ebcdic: entered
   ftps[67108879]: PR0825 onearg_cmd: entered
   ftps[67108879]: RA0500 pass: entered
   ftps[67108879]: RA0607 RACF_MIXED_CASE_PASSWORDS_ENABLED 0
   ftps[67108879]: SR3566 stat_session: entered
   ftps[67108879]: RA0795 pass: use __passwd() to verify the user
   ftps[67108879]: RA0274 ftpinitgps: entered
   ftps[67108879]: RX1205 copyCntlBlks: entered
   ftps[67108879]: NY1000 setupUtf8: entered
   ftps[67108879]: RA2002 loginReply: entered
   ftps[67108879]: RA2517 user_options: entered
   ftps[67108879]: RA2527 user_options: gettsop() failed - safrc: 4, racfrc: 8, racfre: 8.
   ftps[67108879]: SR2907 reply: entered
   ftps[67108879]: SR3719 usingUTF8: entered
   ftps[67108879]: SR3566 stat_session: entered
   ftps[67108879]: GU1011 chkVerRel: entered
   ftps[67108879]: PR0291 parse_cmd: entered
   ftps[67108879]: SR0319 clear_reply_sent: entered
   ftps[67108879]: SR1031 get_command: entered

POST-LOGON SERVER PROCESS
   ftps[67108879]: FR0503 authCmdCheck: entered with cmd 108
   ftps[67108879]: PR1455 parse_ebcdic: entered
   ftps[67108879]: PR0825 onearg_cmd: entered
   ftps[67108879]: SR2212 port: entered with hostaddr 91b281b port 4861
   ftps[67108879]: SR2907 reply: entered
   ftps[67108879]: SR3719 usingUTF8: entered
   ftps[67108879]: SR0319 clear_reply_sent: entered
   ftps[67108879]: SR1031 get_command: entered
   ftps[67108879]: FR0503 authCmdCheck: entered with cmd 106
   ftps[67108879]: PR1455 parse_ebcdic: entered
   ftps[67108879]: PR0825 onearg_cmd: entered
   ftps[67108879]: RD1300 list: entered with command NLST, pathname "".
   ftps[67108879]: MR0704 genList: entered
   ftps[67108879]: MR4205 psList: entered with command NLST, fulldsname "USER119.*".
   ftps[67108879]: SR0513 data_connect: entered
   ftps[67108879]: SR1380 setStackAffinity: entered
   ftps[67108879]: SR2907 reply: entered
   ftps[67108879]: SR3719 usingUTF8: entered
   ftps[67108879]: MR6282 fill_send: entered
   ftps[67108879]: SR3123 send_data: entered
   ftps[67108879]: SR0343 data_close: entered (ps=-1, ds=9)
   ftps[67108879]: SR2907 reply: entered
   ftps[67108879]: SR3719 usingUTF8: entered
   ftps[67108879]: SR0319 clear_reply_sent: entered
   ftps[67108879]: SR1031 get_command: entered
   ftps[67108879]: FR0503 authCmdCheck: entered with cmd 29
   ftps[67108879]: PR1455 parse_ebcdic: entered
   ftps[67108879]: PR0661 noarg_cmd: entered
   ftps[67108879]: RM1856 quit: entered
   ftps[67108879]: SR2907 reply: entered
   ftps[67108879]: SR3719 usingUTF8: entered
   ftps[67108879]: SR0947 end_session: entered (sn=1656FFF8)
   ftps[67108879]: FR1890 resetSecurity: entered

Review the Server's SYSLOGD output, and use this to determine in which phase the error occured.


In which of the following phases does the error occur?