[Bug 1263050] [NEW] Transfers are closed after ~7900 seconds(!)

Fri Dec 20 09:45:59 UTC 2013

Public bug reported:

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 wput at localhost.com 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 wput at localhost.com 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 wput at localhost.com 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 wput at localhost.com 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 wput at localhost.com 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

** Affects: proftpd-dfsg (Ubuntu)
     Importance: Undecided
         Status: New

** Attachment added: "tcpdump  -i eth0 -n host 92.234.237.150 and not port 22 -s 0 -w out.cap"
   https://bugs.launchpad.net/bugs/1263050/+attachment/3933178/+files/ftp-fin.cap

-- 
You received this bug notification because you are a member of ProFTPD
Maintainance Team, which is subscribed to proftpd-dfsg in Ubuntu.
https://bugs.launchpad.net/bugs/1263050

Title:
  Transfers are closed after ~7900 seconds(!)

Status in “proftpd-dfsg” package in Ubuntu:
  New

Bug description:
  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 wput at localhost.com 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 wput at localhost.com 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 wput at localhost.com 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 wput at localhost.com 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 wput at localhost.com 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

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/proftpd-dfsg/+bug/1263050/+subscriptions