[Proftpd-user] Directory listing fails

[John May]

Using Proftpd 1.3.6rc2.

Trying to list a directory with about 18,000 files. It's not working -
says the connection timed out. Tried setting maxfiles in the proftpd
prefs and also set FTP client to active mode.

Any ideas on how to get this to work? Thanks!

- John

[TJ Saunders]

Post by John May
Trying to list a directory with about 18,000 files. It's not working -
says the connection timed out. Tried setting maxfiles in the proftpd
prefs and also set FTP client to active mode.

Which party appears to be timing out the connection, the client or the
server? What's the specific command you're using? Just LIST, or LIST
with a glob/pattern, or...?

Cheers,
TJ

[John May]

Post by TJ Saunders

Post by John May
Trying to list a directory with about 18,000 files. It's not working -
says the connection timed out. Tried setting maxfiles in the proftpd
prefs and also set FTP client to active mode.

Which party appears to be timing out the connection, the client or the
server? What's the specific command you're using? Just LIST, or LIST
with a glob/pattern, or...?
Cheers,
TJ

I'm not exactly sure. I'm accessing the ProFTPd server using the
Transmit FTP client on OS X.

Here's the complete session transcript:



Connection 1

Transmit 4.4.10 (x86_64) Session Transcript [Version 10.11.6 (Build
15G1217)] (3/3/17, 7:09 AM)
LibNcFTP 3.2.3 (July 23, 2009) compiled for UNIX
Remote server is running ProFTPD.
220: ProFTPD 1.3.6rc2 Server (ftp10.pointinspace.com) [216.27.95.22]
Connected to ftp10.pointinspace.com.
Cmd: USER supercargo
331: Password required for supercargo
Cmd: PASS xxxxxxxx
230: User supercargo logged in
Cmd: TYPE A
200: Type set to A
Logged in to ftp10.pointinspace.com as supercargo.
Cmd: SYST
215: UNIX Type: L8
Cmd: FEAT
211: Features:
EPRT
EPSV
HOST
MDTM
MFF modify;UNIX.group;UNIX.mode;
MFMT
MLST
modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;
REST STREAM
SIZE
TVFS
End
Cmd: PWD
257: "/" is the current directory
Cmd: PORT 192,168,0,34,228,158
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
226: Transfer complete
drwxrwx--- 8 supercargo supercargogroup 272 Sep 12 2014 .
drwxrwx--- 8 supercargo supercargogroup 272 Sep 12 2014 ..
-rwxrwxrwx 1 supercargo supercargogroup 855341 Mar 2 21:29
SuperContainer.log
-rw-rw---- 1 supercargo supercargogroup 306 Feb 16 2015
SuperContainer.log.1
-rw-rw---- 1 supercargo supercargogroup 0 Jan 26 2012
SuperContainer.log.1.lck
-rw-rw---- 1 supercargo supercargogroup 0 Dec 30 2011
SuperContainer.log.lck
drwxrwx--- 5 supercargo supercargogroup 170 Aug 2 2016
supercontainer
drwxrwx--- 9 supercargo supercargogroup 306 Oct 20 2014 thumbnails
Cmd: MDTM SuperContainer.log
213: 20170302212909
Cmd: OPTS MLST modify;
200: MLST OPTS modify;
Cmd: PORT 192,168,0,34,228,159
200: PORT command successful
Cmd: MLSD
150: Opening ASCII mode data connection for MLSD
226: Transfer complete
modify=20140912175428; .
modify=20140912175428; ..
modify=20160802050407; supercontainer
modify=20170302212909; SuperContainer.log
modify=20150216083855; SuperContainer.log.1
modify=20120126190733; SuperContainer.log.1.lck
modify=20111230165129; SuperContainer.log.lck
modify=20141020201017; thumbnails
Cmd: CWD /supercontainer
250: CWD command successful
Cmd: PORT 192,168,0,34,228,161
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
226: Transfer complete
drwxrwx--- 5 supercargo supercargogroup 170 Aug 2 2016 .
drwxrwx--- 8 supercargo supercargogroup 272 Sep 12 2014 ..
drwxrwx--- 5 supercargo supercargogroup 170 Jun 13 2014 CBE
drwxrwx--- 4 supercargo supercargogroup 136 Apr 9 2014 GDC
drwxrwx--- 6 supercargo supercargogroup 204 Aug 21 2012 ICE
Cmd: PORT 192,168,0,34,228,163
200: PORT command successful
Cmd: MLSD
150: Opening ASCII mode data connection for MLSD
226: Transfer complete
modify=20160802050407; .
modify=20140912175428; ..
modify=20140613175656; CBE
modify=20140409232546; GDC
modify=20120821123901; ICE
Cmd: CWD /supercontainer/ICE
250: CWD command successful
Cmd: PORT 192,168,0,34,228,164
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
226: Transfer complete
drwxrwx--- 6 supercargo supercargogroup 204 Aug 21 2012 .
drwxrwx--- 5 supercargo supercargogroup 170 Aug 2 2016 ..
drwxrwx--- 923 supercargo supercargogroup 31382 Jan 6 00:32 DOCS
drwxrwx--- 8 supercargo supercargogroup 272 Dec 16 2015 DONATIONS
drwxrwx--- 17629 supercargo supercargogroup 599386 Jan 6 16:45 IMAGES
drwxrwx--- 3 supercargo supercargogroup 102 Jun 25 2016 zLOGO
Cmd: PORT 192,168,0,34,228,165
200: PORT command successful
Cmd: MLSD
150: Opening ASCII mode data connection for MLSD
226: Transfer complete
modify=20120821123901; .
modify=20160802050407; ..
modify=20170106003227; DOCS
modify=20151216214942; DONATIONS
modify=20170106164522; IMAGES
modify=20160625235032; zLOGO
Cmd: CWD /supercontainer/ICE/IMAGES
250: CWD command successful
Cmd: PORT 192,168,0,34,228,167
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
Could not directory listing data -- timed out.
Remote server is running ProFTPD.
220: ProFTPD 1.3.6rc2 Server (ftp10.pointinspace.com) [216.27.95.22]
Connected to ftp10.pointinspace.com.
Cmd: USER supercargo
331: Password required for supercargo
Cmd: PASS xxxxxxxx
230: User supercargo logged in
Cmd: TYPE A
200: Type set to A
Logged in to ftp10.pointinspace.com as supercargo.
Cmd: SYST
215: UNIX Type: L8
Cmd: FEAT
211: Features:
EPRT
EPSV
HOST
MDTM
MFF modify;UNIX.group;UNIX.mode;
MFMT
MLST
modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;
REST STREAM
SIZE
TVFS
End
Cmd: PWD
257: "/" is the current directory
Cmd: CWD /supercontainer/ICE/IMAGES
250: CWD command successful
Cmd: PORT 192,168,0,34,228,178
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
Could not directory listing data -- timed out.

[TJ Saunders]

Post by John May
Remote server is running ProFTPD.
220: ProFTPD 1.3.6rc2 Server (ftp10.pointinspace.com) [216.27.95.22]

Here we see the IP address used for the control connection: 216.27.95.22

Post by John May
Cmd: PORT 192,168,0,34,228,158
200: PORT command successful

Here we see the FTP client requesting an active data transfer, to
192.168.0.34. Curious, as that is an RFC 1918, non-publicly routable
address, but...

Post by John May
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
226: Transfer complete

Here we see that the requested data transfer succeeds. This suggests
that there's a client-side router/NAT/firewall which can properly handle
active data transfers from the FTP server. This is good; it rules out
the possibility of such network middleboxes causing FTP data transfer
issues (as they often do).

Post by John May
Cmd: PORT 192,168,0,34,228,159
200: PORT command successful
Cmd: MLSD
150: Opening ASCII mode data connection for MLSD
226: Transfer complete

Another successful active data transfer. And several more.

Post by John May
Cmd: PORT 192,168,0,34,228,164
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
226: Transfer complete

Here we see an active data transfer using "LIST -a", which succeeds.
Also a good sign. Then...

Post by John May
Cmd: PORT 192,168,0,34,228,167
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
Could not directory listing data -- timed out.

Here we see the timeout. I'm assuming the directory listed is the one
with *many* entries.

Post by John May
From this transcript, it looks like it's the FTP _client_ which is

timing out, waiting for the requested transfer of LIST data. Is there a
way to change that client-side data transfer timeout?

In general, listing tens to hundreds of thousands of files (all in the
same directory) will be an issue for any FTP client. (It's also an
issue on the filesystem.) Such "wide" directories should be minimized,
as much as possible, if performance is a goal. Strategies such as using
a "directory hash/sharding" layout, e.g.:

/dir/f/fi/filename

can help to reduce the number of files in any given directory, at the
cost of having to navigate a couple of levels deeper into the
filesystem.

Cheers,
TJ

[John May]

Hmm, I tried upping the timeout in Transmit, and now the file listing
dies after about 60 seconds with:

Remote host has closed the connection.

in the transcript.

While I understand a large number of files like this can be problematic,
I've been able to list directories of similar sizes with Transmit using
PureFTPd.

Other ideas?

- John

Post by TJ Saunders

Post by John May
Remote server is running ProFTPD.
220: ProFTPD 1.3.6rc2 Server (ftp10.pointinspace.com) [216.27.95.22]

Here we see the IP address used for the control connection: 216.27.95.22

Post by John May
Cmd: PORT 192,168,0,34,228,158
200: PORT command successful

Here we see the FTP client requesting an active data transfer, to
192.168.0.34. Curious, as that is an RFC 1918, non-publicly routable
address, but...

Post by John May
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
226: Transfer complete

Here we see that the requested data transfer succeeds. This suggests
that there's a client-side router/NAT/firewall which can properly handle
active data transfers from the FTP server. This is good; it rules out
the possibility of such network middleboxes causing FTP data transfer
issues (as they often do).

Post by John May
Cmd: PORT 192,168,0,34,228,159
200: PORT command successful
Cmd: MLSD
150: Opening ASCII mode data connection for MLSD
226: Transfer complete

Another successful active data transfer. And several more.

Post by John May
Cmd: PORT 192,168,0,34,228,164
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
226: Transfer complete

Here we see an active data transfer using "LIST -a", which succeeds.
Also a good sign. Then...

Post by John May
Cmd: PORT 192,168,0,34,228,167
200: PORT command successful
Cmd: LIST -a
150: Opening ASCII mode data connection for file list
Could not directory listing data -- timed out.

Here we see the timeout. I'm assuming the directory listed is the one
with *many* entries.

Post by John May
From this transcript, it looks like it's the FTP _client_ which is

timing out, waiting for the requested transfer of LIST data. Is there a
way to change that client-side data transfer timeout?
In general, listing tens to hundreds of thousands of files (all in the
same directory) will be an issue for any FTP client. (It's also an
issue on the filesystem.) Such "wide" directories should be minimized,
as much as possible, if performance is a goal. Strategies such as using
/dir/f/fi/filename
can help to reduce the number of files in any given directory, at the
cost of having to navigate a couple of levels deeper into the
filesystem.
Cheers,
TJ

[TJ Saunders]

Post by John May
Hmm, I tried upping the timeout in Transmit, and now the file listing
Remote host has closed the connection.
in the transcript.

Ah, OK. Now that is a ProFTPD side timeout, I'm sure. I think I'll
need to tweak the directory listing code, so that it resets the
appropriate timers, to avoid the above behavior -- it's a bug.

In the mean time, you might look at the timeouts you have explicitly
configured in your proftpd.conf (and also post those here), to see which
one is set for 60 seconds.

I'll file a bug report to track this, and have a fix, hopefully later
today.

Cheers,
TJ

[John May]

Post by TJ Saunders

Post by John May
Hmm, I tried upping the timeout in Transmit, and now the file listing
Remote host has closed the connection.
in the transcript.

Ah, OK. Now that is a ProFTPD side timeout, I'm sure. I think I'll
need to tweak the directory listing code, so that it resets the
appropriate timers, to avoid the above behavior -- it's a bug.
In the mean time, you might look at the timeouts you have explicitly
configured in your proftpd.conf (and also post those here), to see which
one is set for 60 seconds.
I'll file a bug report to track this, and have a fix, hopefully later
today.
Cheers,
TJ

Sounds good - thanks for the quick response!

No timeouts specified in the proftpd.conf file, FYI.

- John

[TJ Saunders]

Post by John May
While I understand a large number of files like this can be problematic,
I've been able to list directories of similar sizes with Transmit using
PureFTPd.
Other ideas?

Would you be able to provide a transcript of listing such a large
directory using PureFTPd, for comparison?

Cheers,
TJ

[John May]

Post by TJ Saunders

Post by John May
While I understand a large number of files like this can be problematic,
I've been able to list directories of similar sizes with Transmit using
PureFTPd.
Other ideas?

Would you be able to provide a transcript of listing such a large
directory using PureFTPd, for comparison?
Cheers,
TJ

Unfortunately not, as I don't have a specific example off the top of my
head. I do know we've had clients request PureFTPd's preferences be set
to display a larger number of files in the past.

- John

[TJ Saunders]

Post by John May
Unfortunately not, as I don't have a specific example off the top of my
head. I do know we've had clients request PureFTPd's preferences be set
to display a larger number of files in the past.

OK. The reason I ask is that you mentioned that you had not explicitly
set any ProFTPD's timeout directives (TimeoutIdle, TimeoutStalled,
TimeoutNoTransfer, etc). And you mentioned that now, you are seeing
"Remote host has closed the connection." after 60 seconds.

None of ProFTPD's timeouts have a default setting of 60 seconds. Which
makes it curious what could be causing this. The ProFTPD debug logging
would show if the above 60 second loss of connectivity was, in fact,
caused by some timeout. If not, then it would suggest that something in
between the client and the server is closing the connection.

I've seen this sort of thing happen before, with FTP-unaware
firewalls/NAT, which would close the FTP control connection for being
idle (whilst the client was waiting for traffic on the separate data
connection); such network middleboxes don't know to associate FTP's
separate control and data TCP connections together.

Now if _this_ is the case, making it work with ProFTPD becomes a little
harder -- and more likely to cause other problems with FTP clients. For
it would mean that ProFTPD would need to "trickle" data on the control
connection -- an on-going multiline response for the LIST command, in
order to keep that control connection alive. And I'm not sure how well
FTP clients would react to that sort of thing, in that situation.

So right now, it looks like it's either a) a ProFTPD timeout that you're
unaware of, somewhere in your config, which is causing the connection to
close, or b) it's something in the network. And we'll need more data
(e.g. the proftpd debug logging) to be sure. If you'd had this working
with a different FTP server, we could compare the transcripts and see
what that server might be doing differently (was it trickling responses
on the control connection, for example? Was the client in question
using FTP keepalives[1]? etc).

Cheers,
TJ

1. http://www.proftpd.org/docs/howto/KeepAlives.html

[John May]

This issue is happing on multiple networks with multiple different FTP
clients trying to access the same account/directory, so we can rule out
network/client issues.

Nowhere in my proftpd.conf file is there any mention of timeout settings.

Other ideas?

- John

Post by TJ Saunders

Post by John May
Unfortunately not, as I don't have a specific example off the top of my
head. I do know we've had clients request PureFTPd's preferences be set
to display a larger number of files in the past.

OK. The reason I ask is that you mentioned that you had not explicitly
set any ProFTPD's timeout directives (TimeoutIdle, TimeoutStalled,
TimeoutNoTransfer, etc). And you mentioned that now, you are seeing
"Remote host has closed the connection." after 60 seconds.
None of ProFTPD's timeouts have a default setting of 60 seconds. Which
makes it curious what could be causing this. The ProFTPD debug logging
would show if the above 60 second loss of connectivity was, in fact,
caused by some timeout. If not, then it would suggest that something in
between the client and the server is closing the connection.
I've seen this sort of thing happen before, with FTP-unaware
firewalls/NAT, which would close the FTP control connection for being
idle (whilst the client was waiting for traffic on the separate data
connection); such network middleboxes don't know to associate FTP's
separate control and data TCP connections together.
Now if _this_ is the case, making it work with ProFTPD becomes a little
harder -- and more likely to cause other problems with FTP clients. For
it would mean that ProFTPD would need to "trickle" data on the control
connection -- an on-going multiline response for the LIST command, in
order to keep that control connection alive. And I'm not sure how well
FTP clients would react to that sort of thing, in that situation.
So right now, it looks like it's either a) a ProFTPD timeout that you're
unaware of, somewhere in your config, which is causing the connection to
close, or b) it's something in the network. And we'll need more data
(e.g. the proftpd debug logging) to be sure. If you'd had this working
with a different FTP server, we could compare the transcripts and see
what that server might be doing differently (was it trickling responses
on the control connection, for example? Was the client in question
using FTP keepalives[1]? etc).
Cheers,
TJ
1. http://www.proftpd.org/docs/howto/KeepAlives.html

[TJ Saunders]

Post by John May
This issue is happing on multiple networks with multiple different FTP
clients trying to access the same account/directory, so we can rule out
network/client issues.

Not so fast.

The fact that your FTP client can send out an RFC 1918 non-publicly
routable address (192.168.x.y) in a PORT command to a server -- and have
that active data transfer succeed -- says that something in front of
your client machine is translating/handling that FTP control connection,
and changing the IP addresses that the FTP server receives. Otherwise,
the active data transfer wouldn't work at all. (Or proftpd's handling
of "buggy" clients which do as your client is doing is in effect --
this, too, would show in the proftpd debug logging.)

So we know that there's a possibility of at least one network middlebox,
probably closer to the client side of things, which could also be
imposing a timeout...

Could you provide the proftpd debug logging, debug level 10, for one of
these failed directory listings, please?

TJ

[TJ Saunders]

Post by TJ Saunders
Could you provide the proftpd debug logging, debug level 10, for one of
these failed directory listings, please?

This issue was triaged off-list; the culprit ended up being the
following directive in the config file:

RLimitCPU session 60

The long-running directory listing would thus encounter the CPU limit of
60 seconds, and that would kill the session process, resulting in the
"Remote host closed connection". Increasing that CPU limit allowed the
directory list to succeed.

Cheers,
TJ

------------------------------------------------------------------------------
Announcing the Oxford Dictionaries API! The API offers world-renowned
dictionary content that is easy and intuitive to access. Sign up for an
account today to start using our lexical data to power your apps and
projects. Get started today and enter our developer competition.
http://sdm.link/oxford
_______________________________________________
ProFTPD Users List <proftpd-***@proftpd.org>
Unsubscribe problems?
http://www.proftpd.org/list-unsub.html

[John May]

Post by TJ Saunders

Post by TJ Saunders
Could you provide the proftpd debug logging, debug level 10, for one of
these failed directory listings, please?

This issue was triaged off-list; the culprit ended up being the
RLimitCPU session 60
The long-running directory listing would thus encounter the CPU limit of
60 seconds, and that would kill the session process, resulting in the
"Remote host closed connection". Increasing that CPU limit allowed the
directory list to succeed.
Cheers,
TJ

Sorry I didn't follow up with this on-list.

Note that I did get things working with ftp from the command line, but
still can't get Transmit to work. It's different behavior now - no
timeout, just spins - so I'm sure it has something to do with the client
and not the server.

- John
--
-------------------------------------------------------------------
John May : President http://www.pointinspace.com/
Point In Space Internet Solutions 800.664.8610 919.338.8198

------------------------------------------------------------------------------
Announcing the Oxford Dictionaries API! The API offers world-renowned
dictionary content that is easy and intuitive to access. Sign up for an
account today to start using our lexical data to power your apps and
projects. Get started today and enter our developer competition.
http://sdm.link/oxford
_______________________________________________
ProFTPD Users List <proftpd-***@proftpd.org>
Unsubscribe problems?
http://www.proftpd.org/list-unsub.html

[Matus UHLAR - fantomas]

Post by John May
Trying to list a directory with about 18,000 files. It's not working -
says the connection timed out. Tried setting maxfiles in the proftpd
prefs and also set FTP client to active mode.

do you mean port mode?
does listing of other directories work? In either mode?

how long does directory listing take on the system?

[John May]

No, I meant active vs. passive mode on the FTP client.

Other directory listings work fine. The directory in question takes
less than 2 seconds to list when SSH'd to the server.

- John

Post by Matus UHLAR - fantomas

Post by John May
Trying to list a directory with about 18,000 files. It's not working -
says the connection timed out. Tried setting maxfiles in the proftpd
prefs and also set FTP client to active mode.

do you mean port mode?
does listing of other directories work? In either mode?
how long does directory listing take on the system?

[Matus UHLAR - fantomas]

Post by John May
No, I meant active vs. passive mode on the FTP client.

there is port mode and passive mode in FTP, no active mode.
other than that, I have no idea what's the problem, sorry.

perhaps TJ...