[Python-Dev] Buildbot timing out - test suite failure - test_socket issue with UDP6?

[Chris Angelico]

On Wed, Jan 27, 2016 at 8:39 PM, Victor Stinner
<victor.stinner at gmail.com> wrote:
> 2016-01-23 7:03 GMT+01:00 Chris Angelico <rosuav at gmail.com>:
>> Running just that test file:
>>
>> $ ./python Lib/test/test_socket.py
>> ... chomp lots of lines ...
>> testRecvmsgPeek (__main__.RecvmsgUDP6Test) ...
>>
>> seems to indicate that the stall is due to IPv6 and UDP. The VM should
>> have full IPv6 support, although my ISPs don't carry IPv6 traffic, so
>> it won't be able to reach the internet proper; but it should be able
>> to do all manner of local tests.
>
> Try to apply attached patch and run:
>
> $ ./python -m test -v -m testRecvmsgPeek test_socket
> (...)
> testRecvmsgPeek (test.test_socket.RecvmsgUDP6Test) ... CLI SOCK
> <socket.socket fd=5, family=AddressFamily.AF_INET6,
> type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::1', 44347, 0, 0)>
> SERV SOCK <socket.socket fd=4, family=AddressFamily.AF_INET6,
> type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::1', 40488, 0, 0)>
> CLI SOCK ('::1', 44347, 0, 0)
> SERV SOCK ('::1', 40488, 0, 0)
> ok
> testRecvmsgPeek (test.test_socket.RecvmsgIntoUDP6Test) ... CLI SOCK
> <socket.socket fd=5, family=AddressFamily.AF_INET6,
> type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::1', 52721, 0, 0)>
> SERV SOCK <socket.socket fd=4, family=AddressFamily.AF_INET6,
> type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::1', 43967, 0, 0)>
> CLI SOCK ('::1', 52721, 0, 0)
> SERV SOCK ('::1', 43967, 0, 0)
> ok
> (...)
>
> As you can see: the test uses the local loopback interface.
> Inet6TestBase.host is "::1".

Confirmed. It does two tests of IPv4 which run just fine, and then:

testRecvmsgPeek (test.test_socket.RecvmsgUDP6Test) ... CLI SOCK
<socket.socket fd=5, family=AddressFamily.AF_INET6,
type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::1', 47518, 0, 0)>
CLI SOCK ('::1', 47518, 0, 0)
SERV SOCK <socket.socket fd=4, family=AddressFamily.AF_INET6,
type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::1', 42421, 0, 0)>
SERV SOCK ('::1', 42421, 0, 0)

and hangs until I interrupt it.

> You can try to run a UDP server using netcat: "nc -l -u ::1 12345".
> Keep the command running in a terminal, and then run in a different
> terminal: "echo abc | nc -u ::1 12345". You should receive abc in the
> server.

(Oddly, the default netcat-traditional doesn't seem to support this,
but installing netcat-openbsd adds IPv6 support.)

Yep, and that works flawlessly. It's nothing weird about that
particular port, either - nc can use 42421 without a problem.

After digging through test_socket.py for over an hour (the MRO for
RecvmsgUDP6Test is enormous!!), I've boiled the issue down to this:

import socket
MSG = b'asdf qwer zxcv'
serv = socket.socket(socket.AF_INET6, socket.SOCK_DGRAM)
serv.bind(("::1", 0))
cli = socket.socket(socket.AF_INET6, socket.SOCK_DGRAM)
cli.bind(("::1", 0))
cli.sendto(MSG, serv.getsockname())
print(serv.recvmsg(len(MSG) - 3, 0, socket.MSG_PEEK))
print(serv.recvmsg(len(MSG), 0, socket.MSG_PEEK))
print(serv.recvmsg(len(MSG)))

On my main system, this produces three lines of output: the first has
truncated text, the second has full text, and the third also has full
text. This proves that MSG_PEEK is working correctly. On the buildbot,
though, the first one stalls out. Commenting that line out produces
correct results - peek the full data, then read it, and all is well.

Any idea why partial read on a datagram socket would sometimes stall?

ChrisA