socket.settimeout(5.0) does not have any effect

[piotrjurkiewicz]

BPO	23351
Nosy	@pitrou, @piotrjurkiewicz
Files	test_unix_sock_timeout.py

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2015-02-05.07:37:20.618>
created_at = <Date 2015-01-30.01:28:12.176>
labels = ['type-bug', 'library', 'expert-IO']
title = 'socket.settimeout(5.0) does not have any effect'
updated_at = <Date 2015-02-05.07:37:20.616>
user = 'https://github.com/piotrjurkiewicz'

bugs.python.org fields:

activity = <Date 2015-02-05.07:37:20.616>
actor = 'neologix'
assignee = 'none'
closed = True
closed_date = <Date 2015-02-05.07:37:20.618>
closer = 'neologix'
components = ['Library (Lib)', 'IO']
creation = <Date 2015-01-30.01:28:12.176>
creator = 'piotrjurkiewicz'
dependencies = []
files = ['37919']
hgrepos = []
issue_num = 23351
keywords = []
message_count = 6.0
messages = ['235013', '235015', '235028', '235044', '235416', '235422']
nosy_count = 3.0
nosy_names = ['pitrou', 'neologix', 'piotrjurkiewicz']
pr_nums = []
priority = 'normal'
resolution = 'third party'
stage = None
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue23351'
versions = ['Python 2.7', 'Python 3.4', 'Python 3.5']

[piotrjurkiewicz]

After setting socket.settimeout(5.0), socket.send() returns immediately, instead of returning after specified timeout.

Steps to reproduce:

Open two python interpreters.

In the first one (the receiver) execute:

>> import socket
>> r = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)
>> r.bind("test.sock")

In the second one (the sender) execute:

>> import socket
>> s = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)

Then run the following command 11 times:

>> s.sendto("msg", "test.sock")

On the 12 run command will block. This happens because datagram sockets queue on Linux is 11 messages long. Interrupt the command.

So far so good.

Then set sender socket timeout:

>> s.settimeout(5.0)

Expected behavior:

s.sendto() should block for a 5 seconds and THEN raise error 11 (EAGAIN/EWOULDBLOCK).

Actual behavior:

s.sendto() raises the error IMMEDIATELY.

>>> s.sendto("msg", "test.sock")
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
socket.error: [Errno 11] Resource temporarily unavailable

So, in fact, s.settimeout(5.0) does not have any effect.

I think that problem is that settimeout() sets the socket to the non-blocking mode (docs say: "Timeout mode internally sets the socket in non-blocking mode.").

As described here setting timeout on non-blocking sockets is impossible.

In fact, when I set timeout manually with setsockopt(), everything works as expected:

>> s.setblocking(1) #go back to blocking mode
>> tv = struct.pack("ll", 5, 0)
>> s.setsockopt(socket.SOL_SOCKET, socket.SO_SNDTIMEO, tv)

Now s.sendto() raises the error after 5 seconds, as expected.

[pitrou]

The way socket timeouts are implemented is by using select() to determine whether the socket is ready for read/write. In this case, select() probably marks the socket ready even though the queue is full, which later raises EAGAIN.

About SO_SNDTIMEO and SO_RCVTIMEO, POSIX says "it is implementation-defined whether the SO_SNDTIMEO option can be set". Also, they would not necessarily apply to other operations such as accept().

[neologix]

The way socket timeouts are implemented is by using select() to determine whether the socket is ready for read/write. In this case, select() probably marks the socket ready even though the queue is full, which later raises EAGAIN.

Indeed, and this looks like a kernel bug.

Working as expected on a RHEL6:

$ python /tmp/test_unix_sock_timeout.py
('sending ', 0)
took 0.000s
('sending ', 1)
took 0.000s
('sending ', 2)
took 0.000s
('sending ', 3)
took 0.000s
('sending ', 4)
took 0.000s
('sending ', 5)
took 0.000s
('sending ', 6)
took 0.000s
('sending ', 7)
took 0.000s
('sending ', 8)
took 0.000s
('sending ', 9)
took 0.000s
('sending ', 10)
took 0.000s
('sending ', 11)
took 1.000s
Traceback (most recent call last):
  File "/tmp/test_unix_sock_timeout.py", line 17, in <module>
    s.sendto("hello", SOCKNAME)
socket.timeout: timed out

About SO_SNDTIMEO and SO_RCVTIMEO, POSIX says "it is implementation-defined whether the SO_SNDTIMEO option can be set". Also, they would not necessarily apply to other operations such as accept().

Exactly, the current way timeouts are implemented ar The Right Way, IMO.

[pitrou]

The test script works on Ubuntu 14.10 as well.

[piotrjurkiewicz]

Does not work on Debian 7 Wheezy, kernel 3.2.65.

$ python test.py
('sending ', 0)
took 0.000s
('sending ', 1)
took 0.000s
('sending ', 2)
took 0.000s
('sending ', 3)
took 0.000s
('sending ', 4)
took 0.000s
('sending ', 5)
took 0.000s
('sending ', 6)
took 0.000s
('sending ', 7)
took 0.000s
('sending ', 8)
took 0.000s
('sending ', 9)
took 0.000s
('sending ', 10)
took 0.000s
('sending ', 11)
took 0.000s
Traceback (most recent call last):
  File "test.py", line 17, in <module>
    s.sendto("hello", SOCKNAME)
socket.error: [Errno 11] Resource temporarily unavailable

$ uname -a
Linux 3.2.0-4-amd64 #1 SMP Debian 3.2.65-1+deb7u1 x86_64 GNU/Linux

[neologix]

It's a kernel bug closing (working fine on my Debian wheezy with a more recent kernel BTW).