classification
Title: urllib2.open FTP open times out at 20 secs despite timeout parameter
Type: Stage: resolved
Components: Library (Lib) Versions: Python 3.3, Python 2.7
process
Status: closed Resolution: wont fix
Dependencies: Superseder:
Assigned To: Nosy List: nagle, neologix
Priority: normal Keywords:

Created on 2013-09-02 18:18 by nagle, last changed 2013-11-09 08:59 by neologix. This issue is now closed.

Files
File name Uploaded Description Edit
edgartimeouttest.py nagle, 2013-09-02 18:18 Test case program
edgartimeouttest3.py nagle, 2013-09-02 18:26 Test case program for Python 3
Messages (5)
msg196800 - (view) Author: John Nagle (nagle) Date: 2013-09-02 18:18
urllib2.open for an FTP url does not obey the timeout parameter.

Attached test program times out on FTP open after 21 seconds, even though the specified timeout is 60 seconds.  Timing is consistent; times have ranged from 21.03 to 21.05 seconds. Python documentation (http://docs.python.org/2/library/urllib2.html) says "The optional timeout parameter specifies a timeout in seconds for blocking operations like the connection attempt (if not specified, the global default timeout setting will be used). This actually only works for HTTP, HTTPS and FTP connections."  The documentation for Python 3 reads the same.

Open of ftp://ftp.sec.gov/edgar/daily-index failed after 21.05 seconds: <urlopen error ftp error: [Errno 10060] A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond>

This was on Windows 7, but the same result is observed on Linux.  

(The FTP server at the U.S. Securities and Exchange Commission is now imposing a 20-second connection delay during busy periods.  This is causing our Python code that retrieves new SEC filings to fail.  It may be necessary to run the program at different times of the day to reproduce the problem.)
msg196801 - (view) Author: John Nagle (nagle) Date: 2013-09-02 18:26
Reproduced problem in Python 3.3 (Win32). Error message there is:

Open of ftp://ftp.sec.gov/edgar/daily-index failed after 21.08 seconds: <urlopen error ftp error: TimeoutError(10060, 'A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond', None, 10060)>

So this is broken in both Python 2.7 and Python 3.3.
msg196809 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2013-09-02 21:30
Actually, I think urllib (actually ftplib) handles the timeout correctly.

Here's the result on my Linux box (replacing the server with localhost, with a firewall rule to drop packets to ftp port):

$ ./python ~/edgartimeouttest3.py 
Open of ftp://localhost/daily-index failed after 60.09 seconds: <urlopen error ftp error: timeout('timed out',)>

And indeed, here's what strace shows:

$ strace -ttT ./python ~/edgartimeouttest3.py 
23:15:46.953116 connect(3, {sa_family=AF_INET, sin_port=htons(21), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000066>
23:15:46.953257 poll([{fd=3, events=POLLOUT}], 1, 60000) = 0 (Timeout) <60.011497>

See, we - correctly - pass 60s to poll()/select().

Now, I think I know what's going on in your case.
It's likely that your TCP/IP stack settings have shorter timeouts than mine, so the kernel reports a timeout on the socket *before the timeout expires*:

If I reduce the SYN retries limit (on Linux):
# sysctl net.ipv4.tcp_syn_retries=1
net.ipv4.tcp_syn_retries = 1

I now get:
$ ./python ~/edgartimeouttest3.py 
Open of ftp://localhost/daily-index failed after 3.03 seconds: <urlopen error ftp error: TimeoutError(110, 'Connection timed out')>

3s timeout, and yet, we still pass 60 seconds to poll():

23:19:43.756823 connect(3, {sa_family=AF_INET, sin_port=htons(21), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000099>
23:19:43.757034 poll([{fd=3, events=POLLOUT}], 1, 60000) = 1 ([{fd=3, revents=POLLOUT|POLLERR|POLLHUP}]) <3.003306>

In short, the kernel reports a timeout on the socket because it reached the maximum number of retries for SYN packets.

And actually, you can check that the timeouts are correctly processed by passing a smaller value: if it's smaller than the TCP/IP retries limit, you'll get exactly the expected timeout.

So I think it's not a Python bug, but rather an issue with your TCP/IP stack settings.

On Linux, can you try to increase the following sysctls:
# sysctl net.ipv4.tcp_syn_retries=7
# net.ipv4.tcp_retries1=7

And see if this solves your problem?

(BTW, are you "the" John Nagle?)
msg197719 - (view) Author: John Nagle (nagle) Date: 2013-09-14 17:15
The server operator at the US Securities and Exchange Commission writes to me: "There was a DNS issue that affected the availability of FTP at night. We believe it is resolved. Please let us know if you encounter any further problems.  Thanks, SEC Webmaster".

So this may have been a DNS related issue, perhaps a load balancer referring the connection to a dead machine.  Yet, for some reason, the Windows command line FTP client can recover from this problem after 20 seconds? What are they doing right? Completely retrying the open?
msg198154 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2013-09-20 17:39
> So this may have been a DNS related issue, perhaps a load balancer referring the connection to a dead machine.  Yet, for some reason, the Windows command line FTP client can recover from this problem after 20 seconds? What are they doing right? Completely retrying the open?

Do you mean you're able to pass a timeout greater than 20 seconds to
the Windows command line FTP client?

In any case, there's nothing much we can do: if the TCP stack returns
the connection broken (timed out), we can't do much.
On Linux, you can increase the sysctls I mentioned in my previous
message, but that's it.
History
Date User Action Args
2013-11-09 08:59:09neologixsetstatus: open -> closed
resolution: wont fix
stage: resolved
2013-09-20 17:39:56neologixsetmessages: + msg198154
2013-09-14 17:15:19naglesetstatus: pending -> open

messages: + msg197719
2013-09-14 07:14:26neologixsetstatus: open -> pending
2013-09-02 21:30:21neologixsetnosy: + neologix
messages: + msg196809
2013-09-02 18:26:41naglesetfiles: + edgartimeouttest3.py

messages: + msg196801
versions: + Python 3.3
2013-09-02 18:18:51naglecreate