Well, the title says it all really:
I'm using FtpWebRequest to download multiple files as follows:
private string GetFile(Uri uri)
{
string un = Misc.ReadRegKey("ParserFtpUsername");
string pwd = Misc.ReadRegKey("ParserFtpPwd");
string file;
NetworkCredential cred = new NetworkCredential(un, pwd);
WebProxy pxy = new WebProxy();
pxy.UseDefaultCredentials = true;
FtpWebRequest wr = (FtpWebRequest)WebRequest.Create(uri);
wr.Credentials = cred;
wr.Proxy = pxy;
wr.UseBinary = false;
wr.Method = WebRequestMethods.Ftp.DownloadFile;
FtpWebResponse resp = (FtpWebResponse)wr.GetResponse();
Stream respStream = resp.GetResponseStream();
StreamReader reader = new StreamReader(respStream);
file = reader.ReadToEnd();
reader.Close();
respStream.Close();
return file;
}
..so I'm calling this chunk of code repeatedly in a loop. However, I've found that around the 10th iteration (not always exactly 10th), the FTP server returns "503 Bad Sequence of Commands".
I've now enabled System.Net.trace.log, so that I can see the actual ftp commands that are being sent. I have discovered that for no apparent reason, after the 10th file, the FtpWebRequest re-sends the USER and PASS commands again when they are not required.
Wondering whether this might be a timeout issue, I've adjusted the wr.Timeout to differing values, and yet the failure still happens at almost exactly the same place regardless.
Has anyone any ideas of why this is happening - it's driving me mad!
FtpWebRequest re-sending USER and PASS commands half way through download loop
Borvik
I was experiencing this exact same problem. I found that if I used the same NetworkCredentials object on each request, the problem went away.
Hope this helps.
Metro.
Jeffrey van Gogh_MS
I'm using Serv-U Ftp Server for testing my app and i see the multiple USER PASS calls but i do not get the 503 error. Anyways, if you trap for the error and continue, please check the ftp server's logs to see if there is a disconnect and reconnect after the error.
lushdog
John Vonesh
I've noticed that too with an upload implementation, but i don't get the 503 error. Maybe because i'm using Serv-U ftp server. I see in the server log that it is resending the USER / PASS commands.
My code basically makes an initial connection with .method = PWD and .keepAlive = true to test the connection. It then loops through the files to send with .keepAlive = true and then after all the files are sent i do a PWD with the .keepAlive = false to close the connection.
Here i'll paste the ftp server log with the extral USER / PASS commands highighted in red:
5] Sat 29Apr06 08:24:18 - (000005) Connected to xxx.xxx.xxx.xxx(Local address xxx.xxx.xxx.xxx)
Sat 29Apr06 08:24:18 - (000005) 220 Serv-U FTP Server v6.1 for WinSock ready...
Sat 29Apr06 08:24:18 - (000005) 331 User name okay, need password.
Sat 29Apr06 08:24:18 - (000005) 230 User logged in, proceed.
Sat 29Apr06 08:24:18 - (000005) 501 Invalid option.
Sat 29Apr06 08:24:18 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:18 - (000005) 250 Directory changed to /
Sat 29Apr06 08:24:18 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,218)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Alien 1.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 331 User name okay, need password.
Sat 29Apr06 08:24:18 - (000005) 230 User logged in, proceed.
Sat 29Apr06 08:24:18 - (000005) 501 Invalid option.
Sat 29Apr06 08:24:18 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:18 - (000005) 250 Directory changed to /
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,208)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Alien 2.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,209)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Balloon.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,210)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Bear.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,211)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Beaver.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 331 User name okay, need password.
Sat 29Apr06 08:24:18 - (000005) 230 User logged in, proceed.
Sat 29Apr06 08:24:18 - (000005) 501 Invalid option.
Sat 29Apr06 08:24:18 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:18 - (000005) 250 Directory changed to /
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,212)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Birthday Cake.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,213)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Chocolate Cake.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,214)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Da Vinci.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,215)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for David.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:18 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:18 - (000005) 227 Entering Passive Mode (218,147,194,153,7,216)
Sat 29Apr06 08:24:18 - (000005) 150 Opening BINARY mode data connection for Dragon.bmp.
Sat 29Apr06 08:24:18 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,217)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Earth.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,218)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Fireworks 1.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,208)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Fireworks 2.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 331 User name okay, need password.
Sat 29Apr06 08:24:19 - (000005) 230 User logged in, proceed.
Sat 29Apr06 08:24:19 - (000005) 501 Invalid option.
Sat 29Apr06 08:24:19 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:19 - (000005) 250 Directory changed to /
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,209)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Fish.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,210)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Frog 1.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,211)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Frog 2.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,212)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Hand.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,213)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Hitchcock.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,214)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Leaf.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,215)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Monkey 1.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 331 User name okay, need password.
Sat 29Apr06 08:24:19 - (000005) 230 User logged in, proceed.
Sat 29Apr06 08:24:19 - (000005) 501 Invalid option.
Sat 29Apr06 08:24:19 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:19 - (000005) 250 Directory changed to /
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,216)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Monkey 2.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,217)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Moon.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,218)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Owl.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,208)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Party Hat.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,209)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Penguin.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,210)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Rabbit.bmp.
Sat 29Apr06 08:24:19 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:19 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:19 - (000005) 227 Entering Passive Mode (218,147,194,153,7,211)
Sat 29Apr06 08:24:19 - (000005) 150 Opening BINARY mode data connection for Rose.bmp.
Sat 29Apr06 08:24:20 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:20 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:20 - (000005) 227 Entering Passive Mode (218,147,194,153,7,212)
Sat 29Apr06 08:24:20 - (000005) 150 Opening BINARY mode data connection for Shamrock.bmp.
Sat 29Apr06 08:24:20 - (000005) 331 User name okay, need password.
Sat 29Apr06 08:24:20 - (000005) 230 User logged in, proceed.
Sat 29Apr06 08:24:20 - (000005) 501 Invalid option.
Sat 29Apr06 08:24:20 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:20 - (000005) 250 Directory changed to /
Sat 29Apr06 08:24:20 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:20 - (000005) 227 Entering Passive Mode (218,147,194,153,7,213)
Sat 29Apr06 08:24:20 - (000005) 150 Opening BINARY mode data connection for Sun.bmp.
Sat 29Apr06 08:24:20 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:20 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:20 - (000005) 227 Entering Passive Mode (218,147,194,153,7,214)
Sat 29Apr06 08:24:20 - (000005) 150 Opening BINARY mode data connection for Thumbs.db.
Sat 29Apr06 08:24:20 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:20 - (000005) 200 Type set to I.
Sat 29Apr06 08:24:20 - (000005) 227 Entering Passive Mode (218,147,194,153,7,215)
Sat 29Apr06 08:24:20 - (000005) 150 Opening BINARY mode data connection for Women.bmp.
Sat 29Apr06 08:24:20 - (000005) 226 Transfer complete.
Sat 29Apr06 08:24:20 - (000005) 257 "/" is current directory.
Sat 29Apr06 08:24:20 - (000005) 221 Goodbye!
[2] Sat 29Apr06 08:24:18 - (000005) USER lushdog
[5] Sat 29Apr06 08:24:18 - (000005) IP-Name: JUKSOFT-C6610E6
[2] Sat 29Apr06 08:24:18 - (000005) PASS xxxxx
[5] Sat 29Apr06 08:24:18 - (000005) User LUSHDOG logged in
[2] Sat 29Apr06 08:24:18 - (000005) OPTS utf8 on
[2] Sat 29Apr06 08:24:18 - (000005) PWD
[2] Sat 29Apr06 08:24:18 - (000005) CWD /
[2] Sat 29Apr06 08:24:18 - (000005) PWD
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Alien 1.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\alien 1.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\alien 1.bmp successfully (243 kB/sec - 11951 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) USER lushdog
[2] Sat 29Apr06 08:24:18 - (000005) PASS xxxxx
[5] Sat 29Apr06 08:24:18 - (000005) User LUSHDOG logged in
[2] Sat 29Apr06 08:24:18 - (000005) OPTS utf8 on
[2] Sat 29Apr06 08:24:18 - (000005) PWD
[2] Sat 29Apr06 08:24:18 - (000005) CWD /
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Alien 2.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\alien 2.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\alien 2.bmp successfully (418 kB/sec - 10705 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Balloon.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\balloon.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\balloon.bmp successfully (678 kB/sec - 18064 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Bear.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\bear.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\bear.bmp successfully (625 kB/sec - 14717 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Beaver.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\beaver.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\beaver.bmp successfully (605 kB/sec - 14238 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) USER lushdog
[2] Sat 29Apr06 08:24:18 - (000005) PASS xxxxx
[5] Sat 29Apr06 08:24:18 - (000005) User LUSHDOG logged in
[2] Sat 29Apr06 08:24:18 - (000005) OPTS utf8 on
[2] Sat 29Apr06 08:24:18 - (000005) PWD
[2] Sat 29Apr06 08:24:18 - (000005) CWD /
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Birthday Cake.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\birthday cake.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\birthday cake.bmp successfully (433 kB/sec - 10638 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Chocolate Cake.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\chocolate cake.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\chocolate cake.bmp successfully (787 kB/sec - 19334 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Da Vinci.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\da vinci.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\da vinci.bmp successfully (557 kB/sec - 13108 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR David.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\david.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\david.bmp successfully (658 kB/sec - 16844 Bytes)
[2] Sat 29Apr06 08:24:18 - (000005) TYPE I
[2] Sat 29Apr06 08:24:18 - (000005) PASV
[2] Sat 29Apr06 08:24:18 - (000005) STOR Dragon.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Receiving file e:\matt's folder\dragon.bmp
[4] Sat 29Apr06 08:24:18 - (000005) Received file e:\matt's folder\dragon.bmp successfully (348 kB/sec - 8545 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Earth.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\earth.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\earth.bmp successfully (1055 kB/sec - 24838 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Fireworks 1.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\fireworks 1.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\fireworks 1.bmp successfully (493 kB/sec - 11602 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Fireworks 2.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\fireworks 2.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\fireworks 2.bmp successfully (372 kB/sec - 8769 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) USER lushdog
[2] Sat 29Apr06 08:24:19 - (000005) PASS xxxxx
[5] Sat 29Apr06 08:24:19 - (000005) User LUSHDOG logged in
[2] Sat 29Apr06 08:24:19 - (000005) OPTS utf8 on
[2] Sat 29Apr06 08:24:19 - (000005) PWD
[2] Sat 29Apr06 08:24:19 - (000005) CWD /
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Fish.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\fish.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\fish.bmp successfully (477 kB/sec - 11245 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Frog 1.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\frog 1.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\frog 1.bmp successfully (508 kB/sec - 11973 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Frog 2.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\frog 2.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\frog 2.bmp successfully (601 kB/sec - 14781 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Hand.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\hand.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\hand.bmp successfully (593 kB/sec - 13976 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Hitchcock.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\hitchcock.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\hitchcock.bmp successfully (200 kB/sec - 4504 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Leaf.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\leaf.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\leaf.bmp successfully (464 kB/sec - 10919 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Monkey 1.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\monkey 1.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\monkey 1.bmp successfully (725 kB/sec - 17068 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) USER lushdog
[2] Sat 29Apr06 08:24:19 - (000005) PASS xxxxx
[5] Sat 29Apr06 08:24:19 - (000005) User LUSHDOG logged in
[2] Sat 29Apr06 08:24:19 - (000005) OPTS utf8 on
[2] Sat 29Apr06 08:24:19 - (000005) PWD
[2] Sat 29Apr06 08:24:19 - (000005) CWD /
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Monkey 2.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\monkey 2.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\monkey 2.bmp successfully (713 kB/sec - 16798 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Moon.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\moon.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\moon.bmp successfully (479 kB/sec - 10795 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Owl.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\owl.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\owl.bmp successfully (689 kB/sec - 19051 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Party Hat.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\party hat.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\party hat.bmp successfully (376 kB/sec - 8465 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Penguin.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\penguin.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\penguin.bmp successfully (678 kB/sec - 15972 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Rabbit.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\rabbit.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Received file e:\matt's folder\rabbit.bmp successfully (569 kB/sec - 13992 Bytes)
[2] Sat 29Apr06 08:24:19 - (000005) TYPE I
[2] Sat 29Apr06 08:24:19 - (000005) PASV
[2] Sat 29Apr06 08:24:19 - (000005) STOR Rose.bmp
[4] Sat 29Apr06 08:24:19 - (000005) Receiving file e:\matt's folder\rose.bmp
[4] Sat 29Apr06 08:24:20 - (000005) Received file e:\matt's folder\rose.bmp successfully (747 kB/sec - 17590 Bytes)
[2] Sat 29Apr06 08:24:20 - (000005) TYPE I
[2] Sat 29Apr06 08:24:20 - (000005) PASV
[2] Sat 29Apr06 08:24:20 - (000005) STOR Shamrock.bmp
[4] Sat 29Apr06 08:24:20 - (000005) Receiving file e:\matt's folder\shamrock.bmp
[4] Sat 29Apr06 08:24:20 - (000005) Received file e:\matt's folder\shamrock.bmp successfully (633 kB/sec - 14900 Bytes)
[6] Sat 29Apr06 08:24:20 - (000005) 226 Transfer complete.
[2] Sat 29Apr06 08:24:20 - (000005) USER lushdog
[2] Sat 29Apr06 08:24:20 - (000005) PASS xxxxx
[5] Sat 29Apr06 08:24:20 - (000005) User LUSHDOG logged in
[2] Sat 29Apr06 08:24:20 - (000005) OPTS utf8 on
[2] Sat 29Apr06 08:24:20 - (000005) PWD
[2] Sat 29Apr06 08:24:20 - (000005) CWD /
[2] Sat 29Apr06 08:24:20 - (000005) TYPE I
[2] Sat 29Apr06 08:24:20 - (000005) PASV
[2] Sat 29Apr06 08:24:20 - (000005) STOR Sun.bmp
[4] Sat 29Apr06 08:24:20 - (000005) Receiving file e:\matt's folder\sun.bmp
[4] Sat 29Apr06 08:24:20 - (000005) Received file e:\matt's folder\sun.bmp successfully (281 kB/sec - 6041 Bytes)
[2] Sat 29Apr06 08:24:20 - (000005) TYPE I
[2] Sat 29Apr06 08:24:20 - (000005) PASV
[2] Sat 29Apr06 08:24:20 - (000005) STOR Thumbs.db
[4] Sat 29Apr06 08:24:20 - (000005) Receiving file e:\matt's folder\thumbs.db
[4] Sat 29Apr06 08:24:20 - (000005) Received file e:\matt's folder\thumbs.db successfully (5593 kB/sec - 154624 Bytes)
[2] Sat 29Apr06 08:24:20 - (000005) TYPE I
[2] Sat 29Apr06 08:24:20 - (000005) PASV
[2] Sat 29Apr06 08:24:20 - (000005) STOR Women.bmp
[4] Sat 29Apr06 08:24:20 - (000005) Receiving file e:\matt's folder\women.bmp
[4] Sat 29Apr06 08:24:20 - (000005) Received file e:\matt's folder\women.bmp successfully (365 kB/sec - 9351 Bytes)
[2] Sat 29Apr06 08:24:20 - (000005) PWD
[2] Sat 29Apr06 08:24:20 - (000005) QUIT
[5] Sat 29Apr06 08:24:20 - (000005) Closing connection for user LUSHDOG (00:00:02 connected)
lushdog
RenderWarrior
Hi folks,
Sorry - I thought this thread died a long time ago - thanks for all your replies. I never got to the bottom of the problem, although the theory of the host not supporting repeated authentication certainly sounds about right.
I had already discovered that turning off KeepAlive solved my problem, but the overhead of the FTP connection dropping and re-establishing between each file really slowed things down (unacceptably so, in this application). So - I cheated
Wrapped the loop in a try..catch, and got the WebRequest to retry up to a maximum of three times if an error response is encountered. Since then, it's NEVER failed on the 2nd attempt 
. I hate this kind of solution - we shouldn't have to do these things, but so often when time's against you, there's no choice.
shiggsy
Syndrake
I'm not sure what the 501 error is coming from but it happens with other ftp clients too so i'm not worried about it.
The multiple logon attempts are what this thread is all about, myself and the thread author are noticing these in both of our apps. I'm not sure if you are familiar with the FTPWEBREQUEST class but it is supposed to use the same connection for successive uploads, which it does, but we've noticed the multiple login attemps. That's why i've provided this trace with the multiple logins highlighted in red so as to help the devs track down the problem.
lushdog
seduto
Well, I don't know this specific app, but I do know FTP.
Couple of intersesting things in the trace. The app. is using passive mode FTP, which is telling the client that data port will not be the typical ftp data port as defined in the architecture. No problem it works great. But I never once saw a quit on any of the requests until the end.
Couple that with the fact that all 4XX and 5XX series messages are always a host generated issue. I believe that what could be happening is that you have reached the maximun number of sessions allowed by the host for a single username/password. This app. is currently logging on over and over without quiting until the end. I think that could be the issue.
Julian V
Excellent post JonCole.
Just for those wondering i DO NOT get the multiple login error with the Serv-U and FileZilla ftp servers.
lushdog
chossy
This is an interesting topic. I'm using FtpWebRequest to upload an amount of files and I got the same problem as the original poster after getting to around 10 files being sent in a loop - with exactly the same error message. (FTP 503 Error).
I found that trapping for the error - alerting the user - and then contiuning anyway seems to work - I haven't so far determined whether or not the file which was being sent when the error occurs does actually get transmitted!
The suggestion to turn OFF "Keep Alive" does resolve the problem, but it makes the entire process more slow as I assume the connection is being completely closed/reopen for each file.
If the file which is being processed when the error happens is sent anyway, then trapping for the expected error and continuing anyway might be a suitable workaround this problem
Derek Li
Per the RFC it is acceptible for client applications to send the USER command multiple times to change users while keeping the connection alive. See section 4.1.1. As mentioned previously in the thread, the FtpWebRequest class supports connection pooling so that the connection can be kept alive. The pooling does not currently keep track of state as to which user last authenticated on that connection because it can't gaurantee that all code running in the same AppDomain is trusted to use that connection.
FtpWebRequest forces the re-authentication of the user for each usage of the connection to avoid accidentally giving access to a site to someone that doesn't know the username/password. If the server you are connecting to doesn't support the issuing of multple "USER" commands on the same connection, then you can set KeepAlive = false on the request and a new connection will be established for each request.
As for not sending the "QUIT" command until the end, this is done on purpose as that command signals that the connection is going to be closed. Admittedly, the REIN command could have been used in this case but is not currently supported as far as I know. I do not know if the developer considered using REIN or not - it may or may not have been a conscious decision.
rnbguy
That's too bad shiggsy. I hope you can do me a favor, i have created another thread about this but i hope you can check to see if it acts the same for you. If i try to create a directory on a server that already exists i get an exception and the server disconnects and then reconnects for the next file transfer/directory creation. Could you possibly check this and see if it happens for you too.
Create directory1
Create directory2
Run program twice and check the server's log to see if the second time you ran the program you get disconnects/reconnects.
TIA,
lushdog
MADsimptom
Cadillac
niger
I ran into this problem too, also when downloading a number of files. During the operation, the FTP QUIT command was never being issued, so a subsequent attempt to log onto and fetch a file reused the same connection, on which the user was still logged in. The underlying error was not "503 Bad sequence of commands" but "503 You are already logged in!".
So you could modify your code to reuse the existing connection to download subsequent files, or add
.KeepAlive=False
to the web request, and it will force the FTP QUIT command to be issued when you close it.
DaiMori
Sorry my friend, I didn't study the thread closely enough, however, your trace does show some possible issues.
The 501 responses are telling us the server doesn't support that command, it could be removed.
Also, it still looks like there are multiple logon attempts and sucesses to the host. I don't believe they are needed, as there were never any quits in between successive logins.
ciao!