Re: Bad News Folders
Can you post a log file showing opening of the bad directory?
Are you able to open the bad directory with any other FTP client? If you are, please post it's log file.
The problem appears to be more on the server side, where a directory listing is requested but the server cannot send the list because it is restricted, and hence it sends nothing. The clients then either wait indefinitely or assume a server disconnection, so attempt a re-connect which unfortunately then also fails.
Perhaps the current behaviour in WinSCP is OK in this situation.
1. Using filezilla client, the program will hang indefinitely with the last log entries as shown below. With this program it is possible to abort but the connection is lost.
2012-07-23 19:29:27 308 3 Command: PWD
2012-07-23 19:29:27 308 3 Response: 257 "/edgar" is the current directory
2012-07-23 19:29:27 308 3 Command: PASV
2012-07-23 19:29:27 308 3 Response: 227 Entering Passive Mode (162,138,185,31,148,16).
2012-07-23 19:29:27 308 3 Command: MLSD
2012-07-23 19:29:27 308 3 Response: 150 Opening ASCII mode data connection for MLSD
2012-07-23 19:29:28 308 3 Response: 226 Transfer complete
2012-07-23 19:29:28 308 3 Status: Directory listing successful
2012-07-23 19:29:33 308 3 Status: Retrieving directory listing...
2012-07-23 19:29:33 308 3 Command: CWD data
2012-07-23 19:29:36 308 3 Response: 250 CWD command successful
2012-07-23 19:29:36 308 3 Command: PWD
2012-07-23 19:29:36 308 3 Response: 257 "/edgar/data" is the current directory
2012-07-23 19:29:36 308 3 Command: PASV
2012-07-23 19:29:36 308 3 Response: 227 Entering Passive Mode (162,138,185,31,209,41).
2012-07-23 19:29:36 308 3 Command: MLSD
2012-07-23 19:29:36 308 3 Response: 150 Opening ASCII mode data connection for MLSD
2. When using wsftp client, it detects after about 60 seconds that there is no server response so assumes the connection is lost. Wsftp then waits perhaps another minute before trying to re-connect back into the same restricted directory hence this also fails. WinSCP behaves similar to this.
PWD
257 "/edgar" is the current directory
TYPE A
200 Type set to A
PASV
227 Entering Passive Mode (162,138,185,31,145,46).
connecting data channel to 162.138.185.31:145,46(37166)
data channel connected to 162.138.185.31:145,46(37166)
LIST
150 Opening ASCII mode data connection for file list
# transferred 2413 bytes in 0.031 seconds, 617.720 kbps ( 77.215 kBps), transfer succeeded.
226 Transfer complete
CWD data
250 CWD command successful
PWD
257 "/edgar/data" is the current directory
TYPE A
200 Type set to A
PASV
227 Entering Passive Mode (162,138,185,31,227,215).
connecting data channel to 162.138.185.31:227,215(58327)
data channel connected to 162.138.185.31:227,215(58327)
LIST
150 Opening ASCII mode data connection for file list
# transferred 0 bytes in 65.501 seconds, 0.000 bps ( 0.000 Bps), transfer failed.
Error reading response from server.
It appears that the connection is dead. Attempting reconnect...
3. This is the equivalent WinSCP log section to the above :-
> 2012-07-23 19:42:05.079 PWD
< 2012-07-23 19:42:05.189 257 "/edgar" is the current directory
. 2012-07-23 19:42:05.189 Got reply 1 to the command 16
. 2012-07-23 19:42:05.189 Retrieving directory listing...
> 2012-07-23 19:42:05.189 TYPE A
< 2012-07-23 19:42:05.314 200 Type set to A
> 2012-07-23 19:42:05.314 PASV
< 2012-07-23 19:42:05.423 227 Entering Passive Mode (162,138,185,31,183,26).
> 2012-07-23 19:42:05.423 LIST
< 2012-07-23 19:42:05.657 150 Opening ASCII mode data connection for file list
< 2012-07-23 19:42:06.251 226 Transfer complete
. 2012-07-23 19:42:06.251 Directory listing successful
. 2012-07-23 19:42:06.251 Reading symlink "Feed".
. 2012-07-23 19:42:06.251 Reading symlink "Oldloads".
. 2012-07-23 19:42:06.251 Reading symlink "index.htm".
. 2012-07-23 19:42:06.251 Reading symlink "xbrl.html".
. 2012-07-23 19:42:06.251 Got reply 1 to the command 2
. 2012-07-23 19:42:27.767 Changing directory to "data".
> 2012-07-23 19:42:27.767 CWD data
< 2012-07-23 19:42:28.033 250 CWD command successful
. 2012-07-23 19:42:28.033 Got reply 1 to the command 16
. 2012-07-23 19:42:28.033 Getting current directory name.
> 2012-07-23 19:42:28.033 PWD
< 2012-07-23 19:42:28.158 257 "/edgar/data" is the current directory
. 2012-07-23 19:42:28.158 Got reply 1 to the command 16
. 2012-07-23 19:42:28.158 Retrieving directory listing...
> 2012-07-23 19:42:28.158 TYPE A
< 2012-07-23 19:42:28.267 200 Type set to A
> 2012-07-23 19:42:28.267 PASV
< 2012-07-23 19:42:28.392 227 Entering Passive Mode (162,138,185,31,187,120).
> 2012-07-23 19:42:28.392 LIST
< 2012-07-23 19:42:28.627 150 Opening ASCII mode data connection for file list
. 2012-07-23 19:42:43.830 Timeout detected.
. 2012-07-23 19:42:43.830 Could not retrieve directory listing
. 2012-07-23 19:42:43.830 Got reply 1004 to the command 2
* 2012-07-23 19:42:43.830 (ESshFatal) Lost connection.
* 2012-07-23 19:42:43.830 Timeout detected.
* 2012-07-23 19:42:43.830 Could not retrieve directory listing
* 2012-07-23 19:42:43.830 Opening ASCII mode data connection for file list
* 2012-07-23 19:42:43.830 Error listing directory '/edgar/data'.
* 2012-07-23 19:42:43.830 Error changing directory to 'data'.
. 2012-07-23 19:42:48.987 Connecting to ftp.sec.gov ...