FTPFile.close() may result in FTPIOException

Testcase

Hello Mikhail

Which ftputil version do you use?

Your test code doesn't throw an exception here, just as I tried it.

RFC 959, which describes the file transfer protocol, discusses the status code 426 like this:

""" ABORT (ABOR)

This command tells the server to abort the previous FTP service command and any associated transfer of data. The abort command may require "special action", as discussed in the Section on FTP Commands, to force recognition by the server. No action is to be taken if the previous command has been completed (including data transfer). The control connection is not to be closed by the server, but the data connection must be closed.

There are two cases for the server upon receipt of this command: (1) the FTP service command was already completed, or (2) the FTP service command is still in progress.

In the first case, the server closes the data connection (if it is open) and responds with a 226 reply, indicating that the abort command was successfully processed.

In the second case, the server aborts the FTP service in progress and closes the data connection, returning a 426 reply to indicate that the service request terminated abnormally. The server then sends a 226 reply, indicating that the abort command was successfully processed.

"""

Your's is the second case because the connection is aborted and the status code sent by the server.

Which other FTP commands were running or had previously run when the exception occured? It may be a mistake on your side, a server bug, - or in fact a bug in ftputil (e. g. not correctly cleaning up children sessions under certain circumstances, so you run in trouble the _next_ time you use this child). Therefore, I would like to get more information on the context in which the bug appears. Many thanks in advance. :-)

Which ftputil version do you use?

2.1. I didn't found this version in available versions in combobox, only 2.1b и b2 :)

Your test code doesn't throw an exception here, just as I tried it.

Probably this is timing issue. Please try with larger file. Testcase should trigger the condition (2) from the citation above:

In the second case, the server aborts the FTP service in progress
and closes the data connection, returning a 426 reply to indicate
that the service request terminated abnormally.

_FtpFlie.close() calls self._session.voidresp() while it should expect 426. Server actually responds with 426 and exception is thrown. Here is the log of interaction with server:

*cmd* 'PWD'
*resp* '257 "/"'
*cmd* 'CWD /mirrors/ftp.fi.debian.org/debian/doc'
*resp* '250 Directory successfully changed.'
*cmd* 'TYPE A'
*resp* '200 Switching to ASCII mode.'
*cmd* 'PASV'
*resp* '227 Entering Passive Mode (212,192,164,11,145,140)'
*cmd* 'RETR mailing-lists.txt'
*resp* '150 Opening BINARY mode data connection for mailing-lists.txt (56142 bytes).'
*resp* '426 Failure writing network stream.'
Traceback (most recent call last):
  File "testftputil.py", line 5, in ?
    f.close()
  File "/home/mag/plesk/ftputil-2.1/ftp_file.py", line 228, in close
    ftp_error._try_with_ioerror(self._session.voidresp)
  File "/home/mag/plesk/ftputil-2.1/ftp_error.py", line 101, in _try_with_ioerror
    raise FTPIOError(ftp_error)
ftp_error.FTPIOError: 426 Failure writing network stream.
Debugging info: ftputil 2.1, Python 2.3.5 (linux2)

Which other FTP commands were running or had previously run when the exception occured?

Just provided testcase fails for me.

Mikhail, thanks for the detailed description.

Regarding larger files: Ok, I could reproduce the bug when trying to open the file debian-keyring.tar.gz in the same directory. This is the traceback:

>>> import ftputil
>>> host = ftputil.FTPHost('debian.nsu.ru', 'anonymous', '')
>>> f = host.file('mirrors/ftp.fi.debian.org/debian/doc/debian-keyring.tar.gz')
>>> f.close()
Traceback (most recent call last):
  File "<stdin>", line 1, in ?
  File "/home/schwa/sd/python/ftputil/ftp_file.py", line 228, in close
    ftp_error._try_with_ioerror(self._session.voidresp)
  File "/home/schwa/sd/python/ftputil/ftp_error.py", line 101, in _try_with_ioerror
    raise FTPIOError(ftp_error)
ftp_error.FTPIOError: 426 Failure writing network stream.
Debugging info: ftputil 2.1, Python 2.4.3 (linux2)

I can start to download the file with a command line FTP client. However, the download stalled at about 2.5 of 37 MB and I stopped it.

Surprisingly, when I tried to open the "same" file on another Debian mirror, it failed with the same type of exception, - but with a different status code (450):

>>> import ftputil
>>> host = ftputil.FTPHost('ftp.de.debian.org', 'anonymous', '')
>>> f = host.file('debian/doc/debian-keyring.tar.gz')
>>> f.close()
Traceback (most recent call last):
  File "<stdin>", line 1, in ?
  File "/home/schwa/sd/python/ftputil/ftp_file.py", line 228, in close
    ftp_error._try_with_ioerror(self._session.voidresp)
  File "/home/schwa/sd/python/ftputil/ftp_error.py", line 101, in _try_with_ioerror
    raise FTPIOError(ftp_error)
ftp_error.FTPIOError: 450 Transfer aborted. Link to file server lost.
Debugging info: ftputil 2.1, Python 2.4.3 (linux2)

A complete download of the file with a command line client works.

Both of the above Python sessions were "fresh", without any other statements preceeding them. So the problem won't be related to the reuse of child sessions.

I'll check other FTP servers with "large" files later and see if I can reproduce the bug there.

I did some more tests. The file I used here is debian-keyring.tar.gz from 2006-07-26, i. e. the one read in the previous tests.

-rw-r--r-- 1 ftptest ftptest 13705975 Aug 17 10:48 debian-keyring.tar.gz

I found that I get exceptions with status code 450 even if server and client run on the same host, so it doesn't seem that it's a problem with the speed of the network connection.

As in your testcase, I get the exception even if I just open the file and close it. Also, if I read only some bytes. If I read exactly 13631488 bytes with the file open for binary reading, I don't get the exception, but when reading one byte less (13631487), I do get the exception. 13631488 Bytes are exactly 13 MB (13*1024*1024 Bytes) which is also "almost" the length of the file, so I think that the problem has to do with a buffer on the server side which still contains some data and "wants" to be emptied before closing the connection.

The "clean" solution might be to read all the remaining bytes if the file is closed. However, this is presumably impractical because the assumed purpose of reading only a part of the file is to avoid reading it in total. ;-) Therefore, I've added a workaround to ftp_file.py, please get the file from http://ftputil.sschwarzer.net/trac/browser/trunk/ftp_file.py?rev=549&format=txt and tell me if it works for you.

I already applied the similar fix in the software we develop, and it seems to work properly.

Your fix handles the situation described in RFC: "(2) the FTP service command is still in progress." and, hence, this is not a workaround but the correct code.

Alexander Holyapin pointed out that per RFC 959 the status code 451 should be ignored, too. This has been committed (see changeset [679]).