Implementing REST in twisted.protocols.ftp.FTP?

Question

Has anyone managed to implement the REST command in twisted's FTP server? My current attempt:

from twisted.protocols import ftp
from twisted.internet import defer

class MyFTP(ftp.FTP):
    def ftp_REST(self, pos):
        try:
            pos = int(pos)
        except ValueError:
            return defer.fail(CmdSyntaxError('Bad argument for REST'))

        def all_ok(result):
            return ftp.REQ_FILE_ACTN_PENDING_FURTHER_INFO # 350

        return self.shell.restart(pos).addCallback(all_ok)

class MyShell(ftp.FTPShell):
    def __init__(self, host, auth):
        self.position = 0
        ...

    def restart(self, pos):
        self.position = pos
        print "Restarting at %s"%pos
        return defer.succeed(pos)

When a client sends a REST command, it takes several seconds before I see this at the script output:

Traceback (most recent call last):
Failure: twisted.protocols.ftp.PortConnectionError: DTPFactory timeout
Restarting at <pos>

What am I doing wrong? Seems to me like a response should follow immediately from the REST command, why is the socket timing out?

Update:

After enabling logging as suggested by Jean-Paul Calderone, it looks like the REST command isn't even making it to my FTP class before the DTP connection times out from lack of connection (timestamps reduced to MM:SS for brevity):

09:53 [TrafficLoggingProtocol,1,127.0.0.1] cleanupDTP
09:53 [TrafficLoggingProtocol,1,127.0.0.1] <<class 'twisted.internet.tcp.Port'> of twisted.protocols.ftp.DTPFactory on 37298>
09:53 [TrafficLoggingProtocol,1,127.0.0.1] dtpFactory.stopFactory
09:53 [-] (Port 37298 Closed)
09:53 [-] Stopping factory <twisted.protocols.ftp.DTPFactory instance at 0x8a792ec>
09:53 [-] dtpFactory.stopFactory
10:31 [-] timed out waiting for DTP connection
10:31 [-] Unexpected FTP error
10:31 [-] Unhandled Error
        Traceback (most recent call last):
        Failure: twisted.protocols.ftp.PortConnectionError: DTPFactory timeout

10:31 [TrafficLoggingProtocol,2,127.0.0.1] Restarting at 1024

The ftp_PASV command returns DTPFactory.deferred, which is described as a "deferred [that] will fire when instance is connected". RETR commands come through fine (ftp.FTP would be pretty worthless otherwise).

This leads me to believe that there is some sort of blocking operation in here that won't let anything else happen until that DTP connection is made; then and only then can we accept further commands. Unfortunately, it looks like some (all?) clients (specifically, I'm testing with FileZilla) send the REST command before connecting when trying to resume a download.

Answer 1

After much digging into the source and fiddling with ideas, this is the solution I settled on:

class MyFTP(ftp.FTP):
  dtpTimeout = 30

  def ftp_PASV(self):
    # FTP.lineReceived calls pauseProducing(), and doesn't allow
    # resuming until the Deferred that the called function returns
    # is called or errored.  If the client sends a REST command
    # after PASV, they will not connect to our DTP connection
    # (and fire our Deferred) until they receive a response.
    # Therefore, we will turn on producing again before returning
    # our DTP's deferred response, allowing the REST to come
    # through, our response to the REST to go out, the client to
    # connect, and everyone to be happy.
    resumer = reactor.callLater(0.25, self.resumeProducing)
    def cancel_resume(_):
      if not resumer.called:
        resumer.cancel()
      return _
    return ftp.FTP.ftp_PASV(self).addBoth(cancel_resume)
  def ftp_REST(self, pos):
    # Of course, allowing a REST command to come in does us no
    # good if we can't handle it.
    try:
      pos = int(pos)
    except ValueError:
      return defer.fail(CmdSyntaxError('Bad argument for REST'))

    def all_ok(result):
      return ftp.REQ_FILE_ACTN_PENDING_FURTHER_INFO

    return self.shell.restart(pos).addCallback(all_ok)

class MyFTPShell(ftp.FTPShell):
  def __init__(self, host, auth):
    self.position = 0

  def restart(self, pos):
    self.position = pos
    return defer.succeed(pos)

The callLater approach can be flaky at times, but it works the majority of the time. Use at your own risk, obviously.

Answer 2

Verify that the client is behaving as you expect. Capturing all of the relevant traffic with tcpdump or wireshark is a good way to do this, although you can also enable logging in your Twisted-based FTP server in a number of ways (for example, by using the factory wrapper twisted.protocols.policies.TrafficLoggingFactory).

From the timeout error followed by the "Restarting ..." log message, I would guess that the client is sending a RETR ''first'' and then a REST. The RETR times out because the client doesn't try to connect to the data channel until after it receives a response to the REST, and the Twisted server doesn't even process the REST until after the client connects to the data channel (and downloads the entire file). Fixing this may require changing the way ftp.FTP processes commands from clients, so that a REST which follows a RETR can be interpreted properly (or perhaps the FTP client you are using is merely buggy, from the protocol documentation I can find, RETR is supposed to follow REST, not the other way around).

This is just a guess, though, and you should look at the traffic capture to confirm or reject it.