Transfers are closed after ~7900 seconds(!)

[Gavin Hamill]

I've just set up ProFTPd on a clean 12.04 VM with no host firewall and no upstream firewall. The machine is exposed to the Internet via 1:1 NAT on an upstream device (public 88.98.x.x -> private 192.168.0.108)

After approx 2 hours of smooth continuous, faultless transfer, the transfer seems to be halted by ProFTPd. This is completely repeatable - here's the recent xferlog:

The tests from 92.234.237.150 (my home IP address) were intentionally rate-limited to 1KB/sec to verify if the problem related to volume of network traffic. The transfer from 81.105.x.x is our customer trying to upload data and experiencing the same failure at aroung ~7900 seconds into the transfer:

Wed Dec 18 13:47:18 2013 7877 81.105.X,X 3858967400 /var/ftp/incoming/BMS/BMS-disk1.vmdk b _ i a User@ ftp 0 * i
Wed Dec 18 13:49:15 2013 0 81.105.X.X 121 /var/ftp/incoming/BMS/BMS.mf b _ i a User@ ftp 0 * c
Wed Dec 18 13:49:15 2013 0 81.105.X.X 5612 /var/ftp/incoming/BMS/BMS.ovf b _ i a User@ ftp 0 * c
Wed Dec 18 16:00:34 2013 7877 81.105.X.X 3802559924 /var/ftp/incoming/BMS/BMS-disk1.vmdk b _ i a User@ ftp 0 * i
Thu Dec 19 13:53:59 2013 148 92.234.237.150 1024 /var/ftp/incoming/gdhtest/fai.iso.filepart b _ i a <email address hidden> ftp 0 * c
Thu Dec 19 16:05:46 2013 7903 92.234.237.150 8093696 /var/ftp/incoming/gdhtest/fai.iso.filepart b _ i a <email address hidden> ftp 0 * i
Thu Dec 19 18:17:56 2013 7887 92.234.237.150 8078336 /var/ftp/incoming/gdhtest/fai.iso.filepart b _ i a <email address hidden> ftp 0 * i
Thu Dec 19 20:30:05 2013 7887 92.234.237.150 8077312 /var/ftp/incoming/gdhtest/fai.iso.filepart b _ i a <email address hidden> ftp 0 * i
Thu Dec 19 22:42:15 2013 7887 92.234.237.150 8078336 /var/ftp/incoming/gdhtest/fai.iso.filepart b _ i a <email address hidden> ftp 0 * i

Even with 'DebugLevel 2' in the proftpd.conf there is nothing of any significance in the proftpd.log:

Dec 20 06:03:32 ftp-in proftpd[10120] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): Transfer aborted after 8078336 bytes in 7888.03 seconds
Dec 20 06:03:32 ftp-in proftpd[10120] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): FTP session closed.
Dec 20 06:04:14 ftp-in proftpd[10127] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): FTP session opened.
Dec 20 06:04:14 ftp-in proftpd[10127] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): Preparing to chroot to directory '/srv/ftp'
Dec 20 06:04:14 ftp-in proftpd[10127] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): Environment successfully chroot()ed
Dec 20 06:04:14 ftp-in proftpd[10127] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): mod_cap/1.1: capabilities '= cap_net_bind_service,cap_audit_write+ep'
Dec 20 06:04:14 ftp-in proftpd[10127] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): notice: unable to resolve 'no-dns-yet-88-98-53-108.zen.net.uk': Resolver Error 0 (no err
or)
Dec 20 06:04:14 ftp-in proftpd[10127] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): ANON ftp: Login successful.
Dec 20 06:04:14 ftp-in proftpd[10127] ftp-in (cpc11-pres14-2-0-cust149.18-3.cable.virginm.net[92.234.237.150]): Entering Passive Mode (88,98,53,108,143,205).

I am confident that this behaviour is coming from ProFTPd itself since a tcpdump taken on the FTP server itself shows a TCP RST being sent to the client - there is no 'network timeout' or a device in the network enforcing a connection drop - the TCP RST is coming directly from the Ubuntu VM running ProFTPd as logged locally on that VM.

I have attached the tcpdump capture showing what happens at the end of each transfer attempt.

Can you help?

Description: Ubuntu 12.04.3 LTS
Release: 12.04

proftpd-basic:
  Installed: (none)
  Candidate: 1.3.4a-1
  Version table:
     1.3.4a-1 0
        500 http://gb.archive.ubuntu.com/ubuntu/ precise/universe amd64 Packages
        100 /var/lib/dpkg/status

[Gavin Hamill (gdh)]

Changing to the 'dumb' netkit in.ftpd has resolved the problem - definitely not a network issue - ProFTPd was the problem :(

[Kerry Wright (kerry-h)]

Hi Gavin,
Can you clarify what you did in "Changing the 'dumb' netkit"? I seem to be experiencing similar problems.

[Gavin Hamill (gdh)]

Hey Kerry,

Yes of course. I just did 'apt-get install ftpd' which removed ProFTPd, installed the /usr/sbin/in.ftpd binary, and updated /etc/inetd.conf to launch that binary when an incoming connection on port 21 was detected:

inetd.conf:
========= 8< ===========
ftp stream tcp nowait root /usr/sbin/tcpd /usr/sbin/in.ftpd -A -l -S -t 28800
========= 8< ===========

Hope that helps,
Gavin.

[Kerry Wright (kerry-h)]

Thanks Gavin,
Unfortunately we're already pretty deep into our ProFTP adoption, and make pretty extensive use of additional modules, so switching to another server isn't my preferred option.
We've really only seen issues while running mod_shaper, so I'm going to run some tests to see if I can replicate the issues we're seeing under load with WireShark and I'll post back if I find anything interesting.

Kerry

[TJ Saunders (r-tj)]

Could you provide the full proftpd.conf you're using?