timeout=False puts the socket in non-blocking mode, causing weird errors.

I'm receiving a strange connection error using Requests 2.7.0
connecting to an HTTP service as part of an integration test. Below is
the call stack when I call into `session.request` in the API (for
reasons of NDA I can't provide the rest of the callstack).

The error is below in full detail, but in short, send() in requests is emitting `ConnectionError: ('Connection aborted.', error(115, 'Operation now in progress'))`

Python=2.7
Requests=2.7.0

The parameters being passed in to this are:

verb=POST
url=(an HTTP url for an internal service)
data=(a dict)
verify=False
cert=None
headers={'Content-Encoding': 'amz-1.0', 'Connection': 'keep-alive', 'Accept': 'application/json, text/javascript, _/_', 'User-Agent': 'A thing', 'Host': 'hostname', 'Pragma': 'no-cache', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json'}   # plus some service headers used by our service
timeout=False
proxies=Noneﬁ

> package-cache/packages/Requests/lib/python2.7/site-packages/requests/api.py:50: in request
>     response = session.request(method=method, url=url, *_kwargs)
> package-cache/packages/Requests/lib/python2.7/site-packages/requests/sessions.py:465: in request
>     resp = self.send(prep, *_send_kwargs)
> package-cache/packages/Requests/lib/python2.7/site-packages/requests/sessions.py:573: in send
>     r = adapter.send(request, **kwargs)
> ---
> 
> self = <requests.adapters.HTTPAdapter object at 0x7ff845dccd50>, request = <PreparedRequest [POST]>, stream = False, timeout = <requests.packages.urllib3.util.timeout.Timeout object at 0x7ff845dd0cd0>, verify = False, cert = None
> proxies = {}
> 
> ```
> def send(self, request, stream=False, timeout=None, verify=True, cert=None, proxies=None):
>     """Sends PreparedRequest object. Returns Response object.
> 
>         :param request: The :class:`PreparedRequest <PreparedRequest>` being sent.
>         :param stream: (optional) Whether to stream the request content.
>         :param timeout: (optional) How long to wait for the server to send
>             data before giving up, as a float, or a (`connect timeout, read
>             timeout <user/advanced.html#timeouts>`_) tuple.
>         :type timeout: float or tuple
>         :param verify: (optional) Whether to verify SSL certificates.
>         :param cert: (optional) Any user-provided SSL certificate to be trusted.
>         :param proxies: (optional) The proxies dictionary to apply to the request.
>         """
> 
>     conn = self.get_connection(request.url, proxies)
> 
>     self.cert_verify(conn, request.url, verify, cert)
>     url = self.request_url(request, proxies)
>     self.add_headers(request)
> 
>     chunked = not (request.body is None or 'Content-Length' in request.headers)
> 
>     if isinstance(timeout, tuple):
>         try:
>             connect, read = timeout
>             timeout = TimeoutSauce(connect=connect, read=read)
>         except ValueError as e:
>             # this may raise a string formatting error.
>             err = ("Invalid timeout {0}. Pass a (connect, read) "
>                    "timeout tuple, or a single float to set "
>                    "both timeouts to the same value".format(timeout))
>             raise ValueError(err)
>     else:
>         timeout = TimeoutSauce(connect=timeout, read=timeout)
> 
>     try:
>         if not chunked:
>             resp = conn.urlopen(
>                 method=request.method,
>                 url=url,
>                 body=request.body,
>                 headers=request.headers,
>                 redirect=False,
>                 assert_same_host=False,
>                 preload_content=False,
>                 decode_content=False,
>                 retries=self.max_retries,
>                 timeout=timeout
>             )
>         # Send the request.
>         else:
>             if hasattr(conn, 'proxy_pool'):
>                 conn = conn.proxy_pool
> 
>             low_conn = conn._get_conn(timeout=timeout)
> 
>             try:
>                 low_conn.putrequest(request.method,
>                                     url,
>                                     skip_accept_encoding=True)
> 
>                 for header, value in request.headers.items():
>                     low_conn.putheader(header, value)
> 
>                 low_conn.endheaders()
> 
>                 for i in request.body:
>                     low_conn.send(hex(len(i))[2:].encode('utf-8'))
>                     low_conn.send(b'\r\n')
>                     low_conn.send(i)
>                     low_conn.send(b'\r\n')
>                 low_conn.send(b'0\r\n\r\n')
> 
>                 r = low_conn.getresponse()
>                 resp = HTTPResponse.from_httplib(
>                     r,
>                     pool=conn,
>                     connection=low_conn,
>                     preload_content=False,
>                     decode_content=False
>                 )
>             except:
>                 # If we hit any problems here, clean up the connection.
>                 # Then, reraise so that we can handle the actual exception.
>                 low_conn.close()
>                 raise
>             else:
>                 # All is well, return the connection to the pool.
>                 conn._put_conn(low_conn)
> 
>     except (ProtocolError, socket.error) as err:
> ```
> 
> > ```
> >       raise ConnectionError(err, request=request)
> > ```
> > 
> > E           ConnectionError: ('Connection aborted.', error(115, 'Operation now in progress'))
> 
> cert       = None
> chunked    = False
> conn       = <requests.packages.urllib3.connectionpool.HTTPConnectionPool object at 0x7ff844c68c10>
> err        = ProtocolError('Connection aborted.', error(115, 'Operation now in progress'))
> proxies    = {}
> request    = <PreparedRequest [POST]>
> self       = <requests.adapters.HTTPAdapter object at 0x7ff845dccd50>
> stream     = False
> timeout    = <requests.packages.urllib3.util.timeout.Timeout object at 0x7ff845dd0cd0>
> url        = '/'
> verify     = False
> 
> package-cache/packages/Requests/lib/python2.7/site-packages/requests/adapters.py:415: ConnectionError


(Hi Chris!)

Well this is weird. Are you passing any socket options?


None explicitly, no, and I checked in pdb; the options are the `default_socket_options`


Basically, I've bottomed out on my socket-related knowhow. This code works for other services, so it's certainly possible that it's something related to this particular service endpoint, but I don't know what it would be.


Ok.

So, my basic understanding of this error is as follows. First, the error in question is EINPROGRESS (errno 115). I've seen this happen with a socket in non-blocking mode on a `connect()` call: it's very common in that case. However, if you're not passing explicit socket options then we aren't putting the socket in non-blocking mode, and it's hard to see why you'd do that (lots of stuff would go wrong if you did).

Can we clarify some stuff? Are you running in a deployment with PyOpenSSL, or just with the standard ssl library?


I believe without PyOpenSSL, but... checking now...

As far as I know the only instance of PyOpenSSL on my sys.path is in requests/contrib, which I assume is not what you're talking about.


> As far as I know the only instance of PyOpenSSL on my sys.path is in requests/contrib, which I assume is not what you're talking about.

Correct. =) What I want to know is whether PyOpenSSL the package is accessible: that is, that running `python -c 'import OpenSSL'` fails in some way.

So, in that case I recommend running `strace` on your process. If the bug is readily reproducible then this will be particularly useful, because we can see the failing syscall, but I also want to see all syscalls relating to the socket in question. Let's see if it's actually being set to non-blocking mode or not.


(To be clear, setting a socket nonblocking will involve a `fnctl` call that can be seen in strace.)


Okay, gimme a few; it's a 200Mb strace file all-in; narrowing this down will take me a bit.


No rush. =)


```
socket(PF_NETLINK, SOCK_RAW, 0)         = 10
bind(10, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(10, {sa_family=AF_NETLINK, pid=13834, groups=00000000}, [12]) = 0
sendto(10, "\24\0\0\0\26\0\1\3s\217\272U\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(10, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"D\0\0\0\24\0\2\0s\217\272U\n6\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 220
recvmsg(10, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"@\0\0\0\24\0\2\0s\217\272U\n6\0\0\n\200\200\376\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 192
recvmsg(10, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0s\217\272U\n6\0\0\0\0\0\0\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(10)                               = 0
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 10
connect(10, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = 0
sendto(10, "\2\0\0\0\r\0\0\0\6\0\0\0hosts\0", 18, MSG_NOSIGNAL, NULL, 0) = 18
poll([{fd=10, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=10, revents=POLLIN|POLLHUP}])
recvmsg(10, {msg_name(0)=NULL, msg_iov(2)=[{"hosts\0", 6}, {"H\344\17\0\0\0\0\0", 8}], msg_controllen=24, {cmsg_len=20, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, {11}}, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 14
mmap(NULL, 1041480, PROT_READ, MAP_SHARED, 11, 0) = 0x7f866d0b6000
close(11)                               = 0
close(10)                               = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 10
setsockopt(10, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(10, F_GETFL)                      = 0x2 (flags O_RDWR)
fcntl(10, F_SETFL, O_RDWR|O_NONBLOCK)   = 0
connect(10, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("10.12.164.47")}, 16) = -1 EINPROGRESS (Operation now in progress)
close(10)                               = 0
```

So, it looks like something _is_ setting it.


Fun!

So, the `setsockopt` call is us setting the "default socket options". I don't believe we call `setblocking` in our code. Out of interest, does any of yours make that call?

One way or another, it's happening somewhere between the point where we create the socket and call connect. In a vanilla requests/urllib3 that's really only a very small number of lines of code: requests.packages.urllib3.util.connection:68 to requests.packages.urllib3.util.connection:78.

One thing that might be worth doing is running in pdb and setting a breakpoint there, and also open strace in another window for that program, then step through and see if you can see where the fcntl call is coming from.


I'll do that & report back. For what it's worth, this is the code calling requests:

```
    reply = requests.request(verb.lower(), uri.geturl(), data=http_data,
                             verify=verify_cert, cert=cert, headers=headers,
                             auth=http_auth, timeout=self._timeout,
                             proxies=self._proxies)
```

Doesn't seem to be anything there about sockets :/


No, I doubt there is, but I worry about monkeypatching and other kinds of fun. =D No rush, take your time on this.


Based on the strace, it looks like socket.settimeout is doing it:

```
write(1, "-> sock.settimeout(timeout)\n", 28) = 28
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
ioctl(0, TIOCGWINSZ, {ws_row=0, ws_col=0, ws_xpixel=0, ws_ypixel=0}) = 0
ioctl(0, TIOCSWINSZ, {ws_row=0, ws_col=0, ws_xpixel=0, ws_ypixel=0}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig -icanon -echo ...}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGWINCH, {0x7fafa61156a0, [], SA_RESTORER|SA_RESTART, 0x7fafb36daae0}, {SIG_DFL, [], SA_RESTORER, 0x7fafb36daae0}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
write(1, "(Pdb) ", 6)                   = 6
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
select(1, [0], NULL, NULL, NULL)        = 1 (in [0])
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(0, "\n", 1)                        = 1
write(1, "\n", 1)                       = 1
```


That strace doesn't appear to have any fcntl calls in it at all...


Shit. I missed them on paste. One sec.


```
write(1, "-> sock.settimeout(timeout)\n", 28) = 28
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
ioctl(0, TIOCGWINSZ, {ws_row=0, ws_col=0, ws_xpixel=0, ws_ypixel=0}) = 0
ioctl(0, TIOCSWINSZ, {ws_row=0, ws_col=0, ws_xpixel=0, ws_ypixel=0}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig -icanon -echo ...}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGWINCH, {0x7fafa61156a0, [], SA_RESTORER|SA_RESTART, 0x7fafb36daae0}, {SIG_DFL, [], SA_RESTORER, 0x7fafb36daae0}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
write(1, "(Pdb) ", 6)                   = 6
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
select(1, [0], NULL, NULL, NULL)        = 1 (in [0])
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(0, "\n", 1)                        = 1
write(1, "\n", 1)                       = 1
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig icanon echo ...}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGWINCH, {SIG_DFL, [], SA_RESTORER, 0x7fafb36daae0}, {0x7fafa61156a0, [], SA_RESTORER|SA_RESTART, 0x7fafb36daae0}, 8) = 0
fcntl(10, F_GETFL)                      = 0x2 (flags O_RDWR)
fcntl(10, F_SETFL, O_RDWR|O_NONBLOCK)   = 0
write(1, "> /home/chrisros/workspace/CDSer"..., 199) = 199
write(1, "-> if source_address:\n", 22) = 22
```


Note the prompt boundaries for the pdb prompt; that's how I'm triangulating


_Aha_! Check this weaselly section of the Python docs (emphasis mine):

> Set a timeout on blocking socket operations. The value argument can be a nonnegative float expressing seconds, or None. If a float is given, subsequent socket operations will raise a timeout exception if the timeout period value has elapsed before the operation has completed. Setting a timeout of None disables timeouts on socket operations. **s.settimeout(0.0) is equivalent to s.setblocking(0)**; s.settimeout(None) is equivalent to s.setblocking(1).

So, what's the value of `self._timeout` in this call?


:clap: @Lukasa 


`False`


Yeah, that's not a valid value for that argument. ;) _And_, when evaluated in a numerical context, is equivalent to `0`, which is _probably_ the source of this bug.

Want to try catching that at your level and seeing if the problem goes away? If it does, we should consider whether we can police this in the API.


Heh, yup, the `Timeout` object coerces its argument to float, and in Python:

``` python
>>> float(False)
0.0
```

Sometimes I hate this language.


> Want to try catching that at your level and seeing if the problem goes away? If it does, we should consider whether we can police this in the API.

That would be a 3.0.0 change (to raise a ValueError if it isn't `None`, `tuple`, `int`, or `float`).


@sigmavirus24 Sounds good to me.

Separately, urllib3 may want a fix for this, because it is _also_ affected. /cc @shazow


What are we fixing? in urllib3, `timeout=False` has semantic meaning iirc.


@sigmavirus24 Actually, now that I think about it that's overly aggressive. Generally, things that are `float`-y or `int`-y should be totally acceptable. I think we just explicitly want to forbid `True`/`False`, because they happen to be `int`-y but really shouldn't be.


@shazow Not according to the docstring for the `Timeout` class, which is where this happens:

```
    Timeouts can be defined as a default for a pool::
        timeout = Timeout(connect=2.0, read=7.0)
        http = PoolManager(timeout=timeout)
        response = http.request('GET', 'http://example.com/')
    Or per-request (which overrides the default for the pool)::
        response = http.request('GET', 'http://example.com/', timeout=Timeout(10))
    Timeouts can be disabled by setting all the parameters to ``None``::
        no_timeout = Timeout(connect=None, read=None)
        response = http.request('GET', 'http://example.com/, timeout=no_timeout)
    :param total:
        This combines the connect and read timeouts into one; the read timeout
        will be set to the time leftover from the connect attempt. In the
        event that both a connect timeout and a total are specified, or a read
        timeout and a total are specified, the shorter timeout will be applied.
        Defaults to None.
    :type total: integer, float, or None
    :param connect:
        The maximum amount of time to wait for a connection attempt to a server
        to succeed. Omitting the parameter will default the connect timeout to
        the system default, probably `the global default timeout in socket.py
        <http://hg.python.org/cpython/file/603b4d593758/Lib/socket.py#l535>`_.
        None will set an infinite timeout for connection attempts.
    :type connect: integer, float, or None
    :param read:
        The maximum amount of time to wait between consecutive
        read operations for a response from the server. Omitting
        the parameter will default the read timeout to the system
        default, probably `the global default timeout in socket.py
        <http://hg.python.org/cpython/file/603b4d593758/Lib/socket.py#l535>`_.
        None will set an infinite timeout.
    :type read: integer, float, or None
```

Now, admittedly, the docstring does not allow `True`/`False`, but those can be integer or float if evaluated in that context, so you may want to police them. I can kinda see that `timeout=False` putting the socket in non-blocking mode might make sense in some kind of weird world, but I cannot see how `timeout=True` should put the socket into one-second-timeout mode.


`timeout=None` works for the 'set nonblocking' concept better than `timeout=False` imo


Erm I'm thinking of retries=False.