Tests: p2p_invalid_messages test can fail in runner due to stderr text when socket write buffer flushed #15400
Description
Running p2p_invalid_messages.py on its own shows a passing test, but it can fail when its run by test_runner.py. This is because test_runner checks for an empty stderr and we have some exceptions from the asyncio event loop that aren't caught in our code.
The test does a send after we know the socket would have been closed so that any kind of RST will be realized and the connection is closed officially on our end; however, if the the extra send we do is done after the kernel has already acknowledged started the close, the send error is only caught during asyncio's asynchronous write buffer flushing task and the exception is printed to stderr.
1/1 - p2p_invalid_messages.py failed, Duration: 6 s
stdout:
2019-02-13T20:21:33.270000Z TestFramework (INFO): Initializing test directory /var/folders/y0/l8_5z4393lg2qlwdjc11n9380000gn/T/test_runner_₿_🏃_20190213_142133/p2p_invalid_messages_0
2019-02-13T20:21:34.068000Z TestFramework (INFO): Sending a bunch of large, junk messages to test memory exhaustion. May take a bit...
2019-02-13T20:21:37.903000Z TestFramework (INFO): Waiting for node to drop junk messages.
2019-02-13T20:21:38.011000Z TestFramework.mininode (WARNING): Connection lost to 127.0.0.1:11000 due to [Errno 41] Protocol wrong type for socket
2019-02-13T20:21:38.116000Z TestFramework (INFO): Sending a message with incorrect size of 2
2019-02-13T20:21:38.277000Z TestFramework (INFO): Sending a message with incorrect size of 77
2019-02-13T20:21:38.433000Z TestFramework (INFO): Sending a message with incorrect size of 78
2019-02-13T20:21:38.596000Z TestFramework (INFO): Sending a message with incorrect size of 79
2019-02-13T20:21:38.972000Z TestFramework (INFO): Stopping nodes
2019-02-13T20:21:39.232000Z TestFramework (INFO): Cleaning up /var/folders/y0/l8_5z4393lg2qlwdjc11n9380000gn/T/test_runner_₿_🏃_20190213_142133/p2p_invalid_messages_0 on exit
2019-02-13T20:21:39.232000Z TestFramework (INFO): Tests successful
stderr:
Fatal write error on socket transport
protocol: <test_framework.mininode.P2PDataStore object at 0x102fc8940>
transport: <_SelectorSocketTransport fd=10 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/selector_events.py", line 857, in write
n = self._sock.send(data)
OSError: [Errno 41] Protocol wrong type for socket
We can probably check for close prior to the extra send and I think there's a way to register an exception handler to the event loop for errors that happen outside of what your code is awaiting.