ftplib version: 3.2
Python version: 2.7.10
FTP server: Synology FTP server ready (this is a NAS appliance)
Client OS version: CentOS linux 6.4 - Linux serverXXX 2.6.32-358.el6.x86_64 #1 SMP Fri Feb 22 00:31:26 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux
I have implemented a python script using ftplib to transfer several images at night, usually it transfers about 1500 to 2000 images (between 500 Mb to 700 Mb) daily... the thing is that sometimes the script fails and throws the traceback:
Traceback (most recent call last):
File "/etc/scripts/proyecto_escaneo/envia.py", line 227, in <module>
main()
File "/etc/scripts/proyecto_escaneo/envia.py", line 178, in main
resp_stf = send_to_ftp(local_path,remote_path,row[2])
File "/etc/scripts/proyecto_escaneo/envia.py", line 100, in send_to_ftp
transfer = ftp.upload_if_newer(source_file_path, dest_file_path)
File "/root/.pyenv/versions/2.7.10/lib/python2.7/site-packages/ftputil/host.py", line 471, in upload_if_newer
callback=callback)
File "/root/.pyenv/versions/2.7.10/lib/python2.7/site-packages/ftputil/file_transfer.py", line 184, in copy_file
target_fobj = target_file.fobj()
File "/root/.pyenv/versions/2.7.10/lib/python2.7/site-packages/ftputil/file_transfer.py", line 94, in fobj
return self._host.open(self.name, self.mode)
File "/root/.pyenv/versions/2.7.10/lib/python2.7/site-packages/ftputil/host.py", line 180, in open
host = self._available_child()
File "/root/.pyenv/versions/2.7.10/lib/python2.7/site-packages/ftputil/host.py", line 158, in _available_child
host._session.pwd()
File "/root/.pyenv/versions/2.7.10/lib/python2.7/ftplib.py", line 587, in pwd
return parse257(resp)
File "/root/.pyenv/versions/2.7.10/lib/python2.7/ftplib.py", line 872, in parse257
raise error_reply, resp
ftplib.error_reply: 226 Transfer complete.
The script runs from cron at a specific time... this is the code I am using to transfer the files:
def send_to_ftp(source_path, dest_path, codigo_reg):
resp = 0
files = []
counter = 0
error_trans = 0
if os.path.isdir(source_path):
for item in os.listdir(source_path):
files.append(item)
try:
ftp = ftputil.FTPHost(HOST_FTP, USER_FTP, PASSWD_FTP)
if not ftp.path.isdir(dest_path):
logging.info("Se creara directorio remoto: %s" % (dest_path))
ftp.makedirs(dest_path)
for file in files:
counter += 1
source_file_path = source_path + file
dest_file_path = dest_path + file
transfer = ftp.upload_if_newer(source_file_path, dest_file_path)
if transfer == True:
logging.info("%d Archivo %s tranferido con exito a %s" % (counter, source_file_path, dest_file_path))
else:
logging.warning("%d Archivo %s NO se transfirio con exito (o ya existia en destino) a %s" % (counter, source_file_path, dest_file_path))
error_trans += 1
except ftputil.error.FTPError, e:
logging.critical("Error send_to_ftp() %s" % (e.args[0]))
resp = -1
return [resp, counter, error_trans, e]
finally:
if hasattr(ftputil, "ftp"):
ftp.close()
else:
resp = -2
return [resp, counter, error_trans]
This only happens a sometimes and I can't figure it out!!!
Any help would be very helpful.
Thanks for the report!
First of all, I don't see anything in your code that I'd expect to cause the traceback.
Replying to ftputiluser:
and I can't figure it out!!!
Don't panic! :-)
When a data transfer finishes, the server sends a 226 code like the one you're seeing in the traceback. There's the code in
ftputil/file.py
to get any "pending" messages from the server before marking the file closed:def close(self): """Close the `FTPFile`.""" ... try: ... try: with ftputil.error.ftplib_error_to_ftp_io_error: self._session.voidresp() except ftputil.error.FTPIOError as exc: # Ignore some errors, see tickets <a href="/~sschwarzer/ftputil/51" title="~sschwarzer/ftputil#51: _FTPFile.close() blocks after reading only a part of a file">#51</a> and <a href="/~sschwarzer/ftputil/17" title="~sschwarzer/ftputil#17: FTPFile.close() may result in FTPIOException">#17</a> at # https://todo.sr.ht/~sschwarzer/ftputil/51 and # https://todo.sr.ht/~sschwarzer/ftputil/17, # respectively. exc = str(exc) error_code = exc[:3] if exc.splitlines()[0] != "timed out" and \ error_code not in ("150", "426", "450", "451"): raise finally: ... # If something went wrong before, the file is probably # defunct and subsequent calls to `close` won't help # either, so we consider the file closed for practical # purposes. self.closed = True
I have the suspicion that in your case the server sometimes sends the 226 response twice (or some other 2xx response and then 226). This would explain why the problem only occurs sporadically.
The code
host._session.pwd()
inFTPHost._available_child
then accidentally "picks up" the "remaining" 226 status and fails because thepwd
call expects a reply with a 257 status.I'm still thinking about a proper way to fix or work around this problem.
Ideas:
Call
voidresp
infile.close
more than once. I don't think that's a good idea because this is kind of a shot in the dark. We don't know what responses subsequentvoidresp
calls would "pick up". Also, if the server doesn't send anything, we have to wait until a timeout happens.Catch the
error_reply
exception fromhost._session.pwd
and continue with the next child session candidate. This is an "obvious" way to handle the problem. If thepwd
call fails, the child session isn't usable, similar to the session timeout case, which catcheserror_temp
.Still, I'm not comfortable with implementing the second idea right now because I'd like to find out what actually happens. That is, what is the response for the session which was picked up by the
voidresp
call inclose
? Possibly more is going on than I assume and the findings may give some insight, so that we should handle the problem differently.I'm going to attach some instrumented files.
I've attached two files to this ticket. Please put them in the
ftputil
library directory to replace the original files. Of course you should make backup copies of the files to restore them later.Please redirect the resulting
tar
orzip
and attach it to this ticket. If you want, you can replace the
If your code has other
grep
to include only the lines starting with "=== ":grep "^=== " debug_output.txt > debug_output_filtered.txt
Thanks for the quick reply!!!... I'll do the required changes and send you the results... only think is I am not going to be able to do this until next monday - company closed for holidays.
I'll let you know as soon as I have the results!
Regards and happy holidays.
Hi,
I replaced the files, but I've got an error message when I run the program:
Traceback (most recent call last): File "./envia.py", line 8, in <module> import ftputil File "/root/.pyenv/versions/2.7.10/lib/python2.7/site-packages/ftputil/__init__.py", line 50, in <module> from ftputil.host import FTPHost File "/root/.pyenv/versions/2.7.10/lib/python2.7/site-packages/ftputil/host.py", line 23, in <module> import ftputil.session_adapter ImportError: No module named session_adapter
Please advice...
Oops, sorry. You need
session_adapter.py
, which I implemented to fix ticket #100. Please get the file from ftputil/session_adapter.py?format=txt and put it into theftputil
directory. Then the import should work.
Alternatively, you can download and unpack ftputil 3.3 and replace
host.py
andfile.py
with the files attached to this ticket.
Just wanted you to know that the error has not presented itself again!!!...
That's no problem from my side. I suggest you let me know as soon as the error happens again.
If nothing happens within half a year or so, I may close the ticket as "worksforme". I do such things to avoid that open tickets accumulate if I can't reproduce a problem myself and don't have debugging data from the reporter.
Therefore, as soon as you have debugging data availabe, please reopen the ticket (if it's already closed) and attach the debugging data.
Hello Schwa... the error has presented itself again!, this time I upgraded ftputil to latest version 3.3 and replaced files: host.py and file.py with the ones you attached to this ticket, then ran the script again and this time the error was thrown again... this is the output I got:
=== FTPFile, response: <ftputil.file.FTPFile object at 0x7fea1b6ca590> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea1b6ca590> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea1b6ca590> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1290> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1290> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1290> 226 Transfer complete. (u'=== FTPFile, exception:', <ftputil.host.FTPHost object at 0x7fea169d1110>, '226 Transfer complete.') === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1590> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea1b6ca590> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea1b6ca590> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea1b6ca590> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169ae390> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1290> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1290> 226 Transfer complete. === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1290> 226 Transfer complete. (u'=== FTPFile, exception:', <ftputil.host.FTPHost object at 0x7fea169d1110>, '226 Transfer complete.') === FTPFile, response: <ftputil.file.FTPFile object at 0x7fea169d1590> 226 Transfer complete.
Hope this is meaningful to you and can help resolve the problem...
The script has been working without problems for 1 1/2 month (aprox.) until this last weekend.
Please advice...
Best regards.
Thanks a lot for your feedback. Yes, this is meaningful, - but I don't know yet what to do with it. :-)
The server is supposed to send the 226 code after a successful transfer, or after an
ABORT
command, which doesn't apply here. If the 226 is seen after aPWD
command, either the server sent more than one 226 (quite unlikely), or the 226 hadn't been read/seen before when the remote file was closed inFTPFile.close
(much more likely).I'm not yet sure how to deal with this. I think I'll have
_available_child
catch theerror_reply
exception, but I have the feeling that this is somewhat hackish and that there's a better solution. That said, I'd rather go for the first approach if I can't come up with a better one.For the record, here are two interesting pages I found on the subject.
Hi Schwa... unfortunately I am forced to change the protocol used to do this job/transfers (probably using pysftp) to avoid this failure... this process is important for the company...
I will do so in the following days progressively, so in the meantime if you come up with an idea for me to try just let me know... I'll try to help you as long as I can...
Regards Schwa!
I'm now handling the delayed 226 reply by catching
error_reply
in_available_child
, see abab579857a96813322c7282fbb4f72cd9954320.
I just released ftputil 3.3.1 with the fix. I hope that makes your move to another tool or library unnecessary. :-)
By the way, would pysftp handle the problem of this ticket?