FTPMirror error message

Automise Discussion
#1

Running Automise 4.0.0.196 on Windows Server 2008 R2.

FTP Mirror was mirroring to local storage form an ftp site and eventually failed with the message

FTP Mirror failed. Unable to listen, too many pending PASV/EPSV requests.

The owner of the FTP site has confirmed that no error has been logged at his end.  Our firewall has no artificial limitations on the number of permitted connections.

The FTP site consists of a tree of around 38000 files, most of which had already been downloaded in a previous run (that took 6 hours to complete successfully) so this round should only have pulled in about 500 files.

Can you tell me what might cause this error and how to work around it?

Thanks.

#2

A subsequent run worked so it must have been some sort of transient condition. Would still like to know if this is an internal FTPMirror error, and if so under what circumstances it occurs.

#3

This is most likely a proxy or firewall limiting things. It’s not an error we throw.

#4

Does FTP Mirror try to run multiple concurrent connections? Another error that I am now getting to the same site is

Generating File List…
Evaluating Differences…
Downloading files…
FTP Mirror failed. Connection timed out - closing.
Retrying action (1 of 3)…
Not connected, attempting auto reconnect
Error reconnecting : Socket Error # 10053
Software caused connection abort.
Retrying action (2 of 3)…

etc.

My first suspicion is that the connection is timing out whilst evaluating differences, but of course there is no indication in the log about about how long each step is taking. Is it possible to trigger a keep-alive whilst this action is running?

#5

I am using an async action group to run FTP no-op followed by a delay of 60 seconds in parallel with the FTP mirror task, wrapped in a while loop that looks at the log output of FTPMirror.
This is running at the moment so I will have a result in the next day.

Another issue is performance of FTP Mirror whilst reading directories. According to Resource Monitor, Automise is running at around 200 BYTES per second. This seems to be unbelievably slow, considering it is talking over a 10Mb link to an ftp site in the same country using powerful servers at both ends. It would explain why the directory listing is taking hours to complete.

#6

Hi Mr Rimmer,

To help work this issue through, would you be able to provide us with the following information about your setup?

- Type of FTP server your using?
- Is there any difference with using Passive and Non-Passive FTP connection?
- A sample project with any in-confidence information removed (or even screen shots).

Feel free to send this information to our support email address.

#7

The FTP server that our supplier is using is called “Serv-U”.
No difference between active/passive connection speed.
The project I am using won’t show much as it is just an FTP connect followed by FTP Mirror command, and the problem is within FTP mirror. I can’t give you access to the FTP site as that is not under my control, but you can simulate it by creating a site with about 50000 files, split across directories 3 levels deep. Probably an extreme test of FTP Mirror, however as said before Filezilla managed to do the same job in minutes.
I would guess that FTP Mirror is reading the details of each file separately, so the 100ms latency is killing performance. It would be better to do a full directory listing, parse that then download relevant files.

#8

Thanks for reporting this.

I have setup a test here with an emulated delay of 100ms between the server and client and can see the slow down. We will post a fix when its available.

#9

Just an update that we are still progressing through this update for you. I have also found that this issue is also present in other FTP actions which we are fixing at the same time. Will post a fix when its ready. The current plan is to have it done in the next day or two.

#10

Hi Mr Rimmer,

I have fixed the ftp actions to be quicker. Please find the downloads here:

http://downloads.automise.com/downloads/automise/400/ATCMD400_465.exe
http://downloads.automise.com/downloads/automise/400/AT400_465.exe

It is now only 5x the ping time to the server for a single download, and 2x for each directory change required. This is because of the required calls for each ftp command and its response. This is down from the 20x it was previously.

Let me know how this goes for you.

#11

Jason,
Good news on the file scanning which is much improved. However there is still an issue with the amount of time taken to evaluate differences. I have enabled keepalives on the FTP Connect action and have FTP mirror in an async action group, with another thread running a loop with a delay of 30 seconds followed by FTP No-op. However, not only does the FTP mirror still take a very long time evaluating differences, but the connection is aborted by the time it attempts the first download. NoOp can take almost 40 minutes to complete before reporting “not connected” and also failing.
So mirror can read and evaluate the directories but is unable to commence downloading files due ot the conneciton being dropped.

#12

I’ve just killed the job as it had failed and was retrying. Here is a snippet of the log:

Evaluating Differences…
3731 Differences Found
Downloading files…
FTP Mirror failed. Connection timed out - closing.
Retrying action (1 of 3)…
Not connected, attempting auto reconnect
Connected OK.
CRC is not supported by this FTP Server.

So one of three things needs to happen:
1. Evaluate differences faster.
2. Whilst evaluating, send keepalives every minutes.
3. Fix the issue where asynchronous ftp operations appear to be blocked.

#13

Hi Mr Rimmer,

I will get stuck into this today and see where the issue lies.

#14

Hi Mr Rimmer,

Please revert to the previous version for the moment. I have found an issue with uploading folders with spaces in this version. I have a fix for that issue, however haven’t been able to reproduce what your seeing at this stage.

In my test environment I have over 40,000 files, with a maximum folder depth of 10 and width of 20. The environment also emulates a ping time of 100ms. I will keep investigating, however any other information as to the case in which this is occurring would be great.

#15

Hi Mr Rimmer,

We have found some performance improvements in the sorting and evaluating differences. We will get these changes out ASAP. There are some more tests that we want to run on this before releasing. This will be out tomorrow.

#16

Hi Mr Rimmer,

Here is a build with NOOP’s sent while processing the lists of local and remote files and folders. Also the sorting and determination of differences has been improved in speed. 

I suggest disabling your second Async group which is sending noop’s. The FTP connection object isn’t fully tested across threads, and we are uncertain as to whether this would be causing additional issues.

http://downloads.automise.com/downloads/automise/400/ATCMD400_467.exe
http://downloads.automise.com/downloads/automise/400/AT400_467.exe
#17

Thanks Jason, this seems to be working nicely now. I’ll report back if I discover anything else.

#18

The action seems to have worked nicely however the log output appears to have changed format. I was using a regex to extract a list of downloaded files:

Downloaded ‘(.)’ to '(.)’

but this doesn’t work now so I am trying

^Downloaded (.) to (.) in (\d+) ms$

However my concern is that there may be filenames or directory paths with spaces in them. Would it be possible to either describe the required format, or use a delimiter as was used previously?

Many thanks.

#19

Hi Mr Rimmer,

I have updated the download logging to have the same format as the upload logging. The file names are surrounded by a square bracket. This follows the format of other logging that we have. This is a change in behaviour, however it is more in line with that your expecting.

^Downloaded [(.)] to [(.)] in (\d+) ms$

should now make sure it captures all files downloaded. Please note I haven’t tested this regular expression, so happy to stand corrected.

#20
Posted By Jason Smith on 22 Sep 2013 06:59 PM
Hi Mr Rimmer,

I have updated the download logging to have the same format as the upload logging. The file names are surrounded by a square bracket. This follows the format of other logging that we have. This is a change in behaviour, however it is more in line with that your expecting.

^Downloaded [(.*)] to [(.*)] in (\d+) ms$

should now make sure it captures all files downloaded. Please note I haven't tested this regular expression, so happy to stand corrected.


Thanks Jason.

 

Is there a new download?