Multi-threaded Active mode failure with XP SP2 Firewall

Question

My company has a series of VoIP devices that we setup via FTP. We get the files from the boxes, modify them, and send them back. The files are not very large in size (1-2 KB). I have a VB.NET application to do this. A simplified version of my GET function is as follows:

Public Function GetAllFilesFromBox(ByVal IPAddr as string) as boolean

        Dim i As Integer
        Dim FileName As String
        Dim ftp As FTPClient

        Try
            ftp = New FTPClient
            ftp.RemoteHost = IPAddr
            ftp.Timeout = FTPTimeout
            ftp.ConnectMode = FTPConnectMode.ACTIVE
            ftp.Connect()
            ftp.Login(UserName, Passwd)
            ftp.ChDir(BoxFileDir)

            For i = 0 to 20
                  FileName = FileLocation & FileNames(i)
                  ftp.Get(FileName, FileNames(i))
            Next
            
            Return True

       Catch
            ErrorLog.WriteException(ex)
            Return False
       Finally
            if (ftp.Connected) then
                 ftp.Quit
            end if
       End Try

End Function

I call this function asynchronouslly multiple times so that I can retreive files from more than one box at a time. I typically do 20 boxes at a time as my default. Note that each call to the function creates its own instance of the FTPClient. Once I reach my limit, I will start another box as one finishes. However, on Windows XP SP2, this often fails. I typically do not get all of the files from all of my boxes. Some finish completely, but on some I will get some of the files and then the function will fail with an exception "Unable to read data from the transport connection."

I have discovered the following. This only happens on XP SP2 with the firewall turned on. If I turn it off, I get all the files from all the boxes. If I switch to passive mode, it works fine, but other issues may prevent us from using passive mode. If I do each box one at a time, it works fine, but of course this takes forever. Even just 2 at a time will cause some failures. XP SP2 has a limit on the number of outbound connection attempts as detailed here:

http://www.speedguide.net/read_articles.php?id=1497

I tried the fix, but it didn't help. Any ideas as to what is going on? I just downloaded the new 1.2.3 version of edtFTPnet yesterday and nothing in there seemed to fix the problem, but this is the version that I am currently using.

Answer 1

I just read something about the Application Layer Gateway Service and FTP with the firewall, but I don't know much about it. I've found that if I stop this service, it also works in Active mode, just like if I had disabled the firewall. If that provides any more info that's helpful.

Answer 2

In active mode the server tries to connect to your client for data transfers - and it looks like your XP firewall is preventing that from happening.

Try setting the PortRange to a set range of port numbers, e.g. 10000-10050, and configuring the XP firewall to allow incoming connections in this port range.

Answer 3

I tried setting the ActivePortRange like you suggested, even to that specific range (10000-10050), but it didn't seem to make a difference. However, I'm not sure the port range is actually being used correctly. Using a packet sniffer it looked like the normal ports were being used, often starting at 5001. I know that this has been an issue before as indicated by this thread:

http://www.enterprisedt.com/forums/viewtopic.php?p=3254&highlight=activeportrange#3254

Also the notes for the 1.2.3 version that was released yesterday indicated something like this. However, again, I am running the 1.2.3 version.

Even if this does work, however, I'm not sure how viable of a solution this will be since you can't seem to add a range of ports to the XP firewall. I had to add them 1 at a time.

Answer 4

If you enable logging you'll see what ports are being used. Can you post a section of the log? The issue you refer to with active mode has been fixed in 1.2.3.

Are you using FTPClient or FTPConnection?

What code do you use to set the port range?

Answer 5

I have tried both FTPClient and FTPConnection, both with the same results. I am mainly using FTPClient.

This is how I set the port range:

ftp = New FTPClient
ftp.ActivePortRange = New PortRange(10000, 10050)
ftp.RemoteHost = IPAddr
ftp.Timeout = FTPTimeout
ftp.ConnectMode = FTPConnectMode.ACTIVE
ftp.Connect()
ftp.Login(UserName, Passwd)

I have to admit, I'm a little confused. I created a log, but it did not match what I saw in my packet capture (using Ethereal). My log shows the correct ports but Ethereal did not. Maybe Ethereal just wasn't showing them correctly. Below is a sample log from one of my boxes that failed, followed back a small sample of the packet capture for that device.

06/20/2006 14:55:02 ---> USER root
06/20/2006 14:55:03 331 Password required for root.
06/20/2006 14:55:03 ---> PASS ********
06/20/2006 14:55:03 230 User root logged in.
06/20/2006 14:55:03 ---> CWD /mnt
06/20/2006 14:55:03 250 CWD command successful.
06/20/2006 14:55:03 Transfer Started
06/20/2006 14:55:03 ---> PORT 192,168,18,200,39,22
06/20/2006 14:55:03 200 PORT command sucessful.
06/20/2006 14:55:03 ---> RETR factory.ini
06/20/2006 14:55:03 150 Opening ASCII mode data connection for 'factory.ini' (66 bytes).
06/20/2006 14:55:03 Bytes Transfered=60; File=factory.ini
06/20/2006 14:55:03 226 Transfer complete.
06/20/2006 14:55:03 Transfer Complete
06/20/2006 14:55:03 Transfer Started
06/20/2006 14:55:03 ---> PORT 192,168,18,200,39,23
06/20/2006 14:55:03 200 PORT command sucessful.
06/20/2006 14:55:03 ---> RETR tooldata.ini
06/20/2006 14:55:03 150 Opening ASCII mode data connection for 'tooldata.ini' (75 bytes).
06/20/2006 14:55:03 Bytes Transfered=72; File=tooldata.ini
06/20/2006 14:55:03 226 Transfer complete.
06/20/2006 14:55:03 Transfer Complete
06/20/2006 14:55:03 Transfer Started
06/20/2006 14:55:03 ---> PORT 192,168,18,200,39,24
06/20/2006 14:55:03 200 PORT command sucessful.
06/20/2006 14:55:03 ---> RETR chan1.ini
06/20/2006 14:55:03 150 Opening ASCII mode data connection for 'chan1.ini' (125 bytes).
06/20/2006 14:55:03 Bytes Transfered=114; File=chan1.ini
06/20/2006 14:55:04 226 Transfer complete.
06/20/2006 14:55:04 Transfer Complete
06/20/2006 14:55:04 Transfer Started
06/20/2006 14:55:04 ---> PORT 192,168,18,200,39,25
06/20/2006 14:55:04 200 PORT command sucessful.
06/20/2006 14:55:04 ---> RETR chan2.ini
06/20/2006 14:55:04 150 Opening ASCII mode data connection for 'chan2.ini' (125 bytes).
06/20/2006 14:55:04 Bytes Transfered=114; File=chan2.ini
06/20/2006 14:55:04 226 Transfer complete.
06/20/2006 14:55:04 Transfer Complete
06/20/2006 14:55:04 Transfer Started
06/20/2006 14:55:04 ---> PORT 192,168,18,200,39,26
06/20/2006 14:55:04 200 PORT command sucessful.
06/20/2006 14:55:04 ---> RETR chan3.ini
06/20/2006 14:55:04 150 Opening ASCII mode data connection for 'chan3.ini' (125 bytes).
06/20/2006 14:55:04 Bytes Transfered=114; File=chan3.ini
06/20/2006 14:55:04 226 Transfer complete.
06/20/2006 14:55:04 Transfer Complete
06/20/2006 14:55:04 Transfer Started
06/20/2006 14:55:04 ---> PORT 192,168,18,200,39,27
06/20/2006 14:55:04 200 PORT command sucessful.
06/20/2006 14:55:04 ---> RETR chan4.ini
06/20/2006 14:55:04 150 Opening ASCII mode data connection for 'chan4.ini' (125 bytes).
06/20/2006 14:55:04 Bytes Transfered=114; File=chan4.ini
06/20/2006 14:55:05 226 Transfer complete.
06/20/2006 14:55:05 Transfer Complete
06/20/2006 14:55:05 Transfer Started
06/20/2006 14:55:05 ---> PORT 192,168,18,200,39,28
06/20/2006 14:55:05 200 PORT command sucessful.
06/20/2006 14:55:05 ---> RETR input1.ini
06/20/2006 14:55:05 150 Opening ASCII mode data connection for 'input1.ini' (28 bytes).
06/20/2006 14:55:05 Bytes Transfered=25; File=input1.ini
06/20/2006 14:55:05 226 Transfer complete.
06/20/2006 14:55:05 Transfer Complete
06/20/2006 14:55:05 Transfer Started
06/20/2006 14:55:05 ---> PORT 192,168,18,200,39,29
06/20/2006 14:55:05 200 PORT command sucessful.
06/20/2006 14:55:05 ---> RETR input2.ini
06/20/2006 14:55:05 150 Opening ASCII mode data connection for 'input2.ini' (28 bytes).
06/20/2006 14:55:05 Bytes Transfered=25; File=input2.ini
06/20/2006 14:55:05 226 Transfer complete.
06/20/2006 14:55:05 Transfer Complete
06/20/2006 14:55:05 Transfer Started
06/20/2006 14:55:05 ---> PORT 192,168,18,200,39,30
06/20/2006 14:55:05 200 PORT command sucessful.
06/20/2006 14:55:05 ---> RETR input3.ini
06/20/2006 14:55:05 150 Opening ASCII mode data connection for 'input3.ini' (28 bytes).
06/20/2006 14:55:05 Bytes Transfered=25; File=input3.ini
06/20/2006 14:55:06 226 Transfer complete.
06/20/2006 14:55:06 Transfer Complete
06/20/2006 14:55:06 Transfer Started
06/20/2006 14:55:06 ---> PORT 192,168,18,200,39,31
06/20/2006 14:55:06 200 PORT command sucessful.
06/20/2006 14:55:06 ---> RETR input4.ini
06/20/2006 14:55:06 150 Opening ASCII mode data connection for 'input4.ini' (28 bytes).
06/20/2006 14:55:06 Bytes Transfered=25; File=input4.ini
06/20/2006 14:55:06 226 Transfer complete.
06/20/2006 14:55:06 Transfer Complete
06/20/2006 14:55:06 Transfer Started
06/20/2006 14:55:06 ---> PORT 192,168,18,200,39,32
06/20/2006 14:55:06 200 PORT command sucessful.
06/20/2006 14:55:06 ---> RETR relay1.ini
06/20/2006 14:55:06 150 Opening ASCII mode data connection for 'relay1.ini' (21 bytes).
06/20/2006 14:55:06 Bytes Transfered=19; File=relay1.ini
06/20/2006 14:55:06 226 Transfer complete.
06/20/2006 14:55:06 Transfer Complete
06/20/2006 14:55:06 Transfer Started
06/20/2006 14:55:06 ---> PORT 192,168,18,200,39,33
06/20/2006 14:55:06 200 PORT command sucessful.
06/20/2006 14:55:06 ---> RETR relay2.ini
06/20/2006 14:55:06 150 Opening ASCII mode data connection for 'relay2.ini' (21 bytes).
06/20/2006 14:55:06 Bytes Transfered=19; File=relay2.ini
06/20/2006 14:55:06 226 Transfer complete.
06/20/2006 14:55:06 Transfer Complete
06/20/2006 14:55:06 Transfer Started
06/20/2006 14:55:06 ---> PORT 192,168,18,200,39,34
06/20/2006 14:55:06 200 PORT command sucessful.
06/20/2006 14:55:06 ---> RETR relay3.ini
06/20/2006 14:55:06 150 Opening ASCII mode data connection for 'relay3.ini' (21 bytes).
06/20/2006 14:55:06 Bytes Transfered=19; File=relay3.ini
06/20/2006 14:55:07 226 Transfer complete.
06/20/2006 14:55:07 Transfer Completd
06/20/2006 14:55:07 Transfer Started
06/20/2006 14:55:07 ---> PORT 192,168,18,200,39,35
06/20/2006 14:55:07 200 PORT command sucessful.
06/20/2006 14:55:07 ---> RETR relay4.ini
06/20/2006 14:55:07 150 Opening ASCII mode data connection for 'relay4.ini' (21 bytes).
06/20/2006 14:55:07 Bytes Transfered=19; File=relay4.ini
06/20/2006 14:55:07 226 Transfer complete.
06/20/2006 14:55:07 Transfer Complete
06/20/2006 14:55:07 Transfer Started
06/20/2006 14:55:07 ---> PORT 192,168,18,200,39,36
06/20/2006 14:55:07 200 PORT command sucessful.
06/20/2006 14:55:07 ---> RETR groups.ini
06/20/2006 14:55:07 150 Opening ASCII mode data connection for 'groups.ini' (15 bytes).
06/20/2006 14:55:07 Bytes Transfered=14; File=groups.ini
06/20/2006 14:55:07 226 Transfer complete.
06/20/2006 14:55:07 Transfer Complete
06/20/2006 14:55:07 Transfer Started
06/20/2006 14:55:07 ---> PORT 192,168,18,200,39,37
06/20/2006 14:55:07 200 PORT command sucessful.
06/20/2006 14:55:07 ---> RETR cache.ini
06/20/2006 14:55:07 150 Opening ASCII mode data connection for 'cache.ini' (2038 bytes).
06/20/2006 14:55:07 Bytes Transfered=1944; File=cache.ini
06/20/2006 14:55:08 226 Transfer complete.
06/20/2006 14:55:08 Transfer Complete
06/20/2006 14:55:08 Transfer Started
06/20/2006 14:55:08 ---> PORT 192,168,18,200,39,39
06/20/2006 14:55:08 200 PORT command sucessful.
06/20/2006 14:55:08 ---> RETR network.ini
06/20/2006 14:55:08 150 Opening ASCII mode data co

Answer 6

From the log the port range is being used correctly.

It seems that the server doesn't respond to RETR, i.e. it has failed in its attempt to make the connection to the listening socket on the client. Thus it doesn't respond on the command channel which times out trying to read the response.

Most likely the firewall isn't letting the server connect on that port (is there any log that will tell you what it has blocked?). Have you enabled all the ports in the range? You can of course make the range much smaller, as long as used sockets have time to be recycled.

Answer 7

I do have a log from the firewall. It actually matches what I got from my packet capture. As a small sample, here is what I got from the component logging:

06/21/2006 08:46:00 ---> PORT 192,168,18,200,39,81

Then here is the related packet capture:

No.     Time                       Source                Destination           Protocol Info
   5504 2006-06-21 08:46:00.157258 192.168.18.200        192.168.18.24         FTP      Request: PORT 192,168,18,200,20,186
   5512 2006-06-21 08:46:00.180692 192.168.18.24         192.168.18.200        FTP      Response: 200 PORT command sucessful.
   5513 2006-06-21 08:46:00.185707 192.168.18.200        192.168.18.24         FTP      Request: RETR cache.ini
   5518 2006-06-21 08:46:00.226092 192.168.18.24         192.168.18.200        TCP      3322 > 5306 [SYN] Seq=0 Ack=0 Win=5840 Len=0 MSS=1460 TSV=159259777 TSER=0 WS=0

There here is from the XP firewall log:

#Version: 1.5
#Software: Microsoft Windows Firewall
#Time Format: Local
#Fields: date time action protocol src-ip dst-ip src-port dst-port size tcpflags tcpsyn tcpack tcpwin icmptype icmpcode info path

2006-06-21 08:46:00 DROP TCP 192.168.18.24 192.168.18.200 3322 5306 60 S 3813926407 0 5840 - - - RECEIVE

That makes it look like the connection is trying to come back on port 5306. Could the client possibly be binding to one port (10065) but telling the server to connect to another (5306)?

Just for testing, I added some more ports so I had a bigger pool to choose from, 100 in all. Then I did only 2 threads at a time. Each thread tries to get at most 21 files from its respective device. I have 24 total devices hooked up that I am getting files from. I thought that would provide a better chance for ports to be recycled in a timely manner. But even with just 2 threads, there were some failures. With a single thread, however, they all succeed. I guess I don't undersand why the firewall would be blocking when multiple threads are going, but allowing everything to come through with single threads.

Answer 8

I suspect that with multiple FTP connections, the firewall is getting confused. Of course you should also set individual (non-overlapping) port ranges for each instance of FTPClient.

With a single thread, however, they all succeed. I guess I don't undersand why the firewall would be blocking when multiple threads are going, but allowing everything to come through with single threads.

Answer 9

Hmmm. Non-overlapping ranges would make sense and I can see where that would help. Again like I said though, even if that does work, I don't know if this will even be a realistic solution for me or not, mainly since you can't add a range of ports to XP firewall. I can see where we might need quite a few ports and I can't see our customers going in and adding them all one at a time. Unless there's a way to add them in through some type of script.

In reality, we had a problem with passive mode where it seems like the server is occasionally returning an incorrect IP address in the port command. If the guy working on the server can get that straightened out, then I would probably just jump back to passive mode and avoid this whole headache all together. But I still wanted to try to understand what was going on in Active mode, in case that's our only approach.

Thanks.

Answer 10

Just a thought - you might consider using SFTP instead of FTP. SFTP does everything on a single connection so you won't have these problems. Of course you would have to make sure you have a server that supports SFTP.

We're about to release SFTP support in our new .NET product. This is a commercial product. I believe we are ready to send out beta versions of it so you should be able to start testing very soon. Please let us know if you would like to try it.

- Hans (EDT)