classification
Title: test_socket altered the execution environment: threading_cleanup() failed to cleanup 0 threads (count: 0, dangling: 5)
Type: Stage: resolved
Components: Tests Versions: Python 3.10
process
Status: closed Resolution: out of date
Dependencies: Superseder:
Assigned To: Nosy List: corona10, shihai1991, vstinner
Priority: normal Keywords:

Created on 2020-06-11 14:27 by vstinner, last changed 2020-12-16 09:39 by vstinner. This issue is now closed.

Messages (8)
msg371287 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-06-11 14:27
aarch64 RHEL8 Refleaks 3.x:
https://buildbot.python.org/all/#/builders/563/builds/127

The system load was quite high (9.95) for "CPU count: 8".

0:22:19 load avg: 9.95 [406/426/2] test_socket failed (env changed) (2 min 41 sec) -- running: test_pydoc (20 min 35 sec), test_asyncio (11 min 56 sec), test_faulthandler (39.2 sec), test_concurrent_futures (20 min 7 sec), test_venv (1 min 17 sec), test_peg_generator (15 min 51 sec), test_multiprocessing_spawn (54.4 sec), test_signal (9 min 26 sec)
beginning 6 repetitions
123456
....Warning -- threading_cleanup() failed to cleanup 0 threads (count: 0, dangling: 5)
Warning -- Dangling thread: <Thread(Thread-30, stopped 281473491857888)>
Warning -- Dangling thread: <Thread(Thread-29, stopped 281473491857888)>
Warning -- Dangling thread: <Thread(Thread-32, stopped 281473491857888)>
Warning -- Dangling thread: <Thread(Thread-31, stopped 281473491857888)>
Warning -- Dangling thread: <_MainThread(MainThread, started 281473770473840)>
..

It may be related to bpo-36750: "test_socket leaks file descriptors on macOS".
msg375227 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-08-12 11:52
PPC64LE RHEL7 Refleaks 3.9:
https://buildbot.python.org/all/#/builders/704/builds/87

0:12:25 load avg: 8.94 [242/425/1] test_socket failed (env changed) (2 min 43 sec) -- running: test_decimal (2 min 26 sec), test_peg_generator (12 min 23 sec), test_signal (6 min 20 sec), test_weakref (2 min 41 sec), test_multiprocessing_fork (2 min 36 sec), test_venv (2 min 33 sec)
beginning 6 repetitions
123456
.....Warning -- threading_cleanup() failed to cleanup 0 threads (count: 0, dangling: 5)
Warning -- Dangling thread: <Thread(Thread-37, stopped 70367133561264)>
Warning -- Dangling thread: <Thread(Thread-38, stopped 70367133561264)>
Warning -- Dangling thread: <Thread(Thread-36, stopped 70367133561264)>
Warning -- Dangling thread: <_MainThread(MainThread, started 70367377380144)>
Warning -- Dangling thread: <Thread(Thread-39, stopped 70367133561264)>
.
msg375237 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-08-12 13:24
While running "./python -m test.bisect_cmd test_socket --fail-env-changed -v -o bisect" 6x in parallel (with a different filename for the -o option), I got this error:

testSourceAddress (test.test_socket.NetworkConnectionAttributesTest) ... Warning -- Unraisable exception
Exception ignored in thread started by: <bound method ThreadableTest.clientRun of <test.test_socket.NetworkConnectionAttributesTest testMethod=testSourceAddress>>
Traceback (most recent call last):
  File "/home/vstinner/cpython/Lib/test/test_socket.py", line 396, in clientRun
    self.clientTearDown()
  File "/home/vstinner/cpython/Lib/test/test_socket.py", line 5164, in clientTearDown
    self.cli.close()
AttributeError: 'NetworkConnectionAttributesTest' object has no attribute 'cli'


By the way, I was also running "./python -m test -j20 -r -F" in parallel and it failed with the following error which isn't very helpful :-(

test test_socket failed -- multiple errors occurred; run in verbose mode for details
msg375241 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-08-12 13:35
More logs before testSourceAddress failure:

(...)
testSmallReadNonBlocking (test.test_socket.UnbufferedFileObjectClassTestCase) ... ok
testUnbufferedRead (test.test_socket.UnbufferedFileObjectClassTestCase) ... ok
testWriteNonBlocking (test.test_socket.UnbufferedFileObjectClassTestCase) ... ok
testAttributes (test.test_socket.LineBufferedFileObjectClassTestCase) ... ok
testMakefileAfterMakefileClose (test.test_socket.LineBufferedFileObjectClassTestCase) ... ok
testReadAfterTimeout (test.test_socket.LineBufferedFileObjectClassTestCase) ... ok
testCloseAfterMakefile (test.test_socket.SmallBufferedFileObjectClassTestCase) ... ok
testMakefileAfterMakefileClose (test.test_socket.SmallBufferedFileObjectClassTestCase) ... ok
testUnbufferedRead (test.test_socket.SmallBufferedFileObjectClassTestCase) ... ok
testAttributes (test.test_socket.UnicodeReadFileObjectClassTestCase) ... ok
testClosedAttr (test.test_socket.UnicodeReadFileObjectClassTestCase) ... ok
testMakefileAfterMakefileClose (test.test_socket.UnicodeReadFileObjectClassTestCase) ... ok
testReadAfterTimeout (test.test_socket.UnicodeReadFileObjectClassTestCase) ... ok
testReadline (test.test_socket.UnicodeReadFileObjectClassTestCase) ... ok
testCloseAfterMakefile (test.test_socket.UnicodeWriteFileObjectClassTestCase) ... ok
testClosedAttr (test.test_socket.UnicodeWriteFileObjectClassTestCase) ... ok
testFullRead (test.test_socket.UnicodeWriteFileObjectClassTestCase) ... ok
testMakefileAfterMakefileClose (test.test_socket.UnicodeWriteFileObjectClassTestCase) ... ok
testReadAfterTimeout (test.test_socket.UnicodeWriteFileObjectClassTestCase) ... ok
testRealClose (test.test_socket.UnicodeWriteFileObjectClassTestCase) ... ok
testFullRead (test.test_socket.UnicodeReadWriteFileObjectClassTestCase) ... ok
testMakefileAfterMakefileClose (test.test_socket.UnicodeReadWriteFileObjectClassTestCase) ... ok
testReadAfterTimeout (test.test_socket.UnicodeReadWriteFileObjectClassTestCase) ... ok
testReadline (test.test_socket.UnicodeReadWriteFileObjectClassTestCase) ... ok
testSmallRead (test.test_socket.UnicodeReadWriteFileObjectClassTestCase) ... ok
testUnbufferedRead (test.test_socket.UnicodeReadWriteFileObjectClassTestCase) ... ok
test_create_connection (test.test_socket.NetworkConnectionNoServer) ... ok
test_create_connection_timeout (test.test_socket.NetworkConnectionNoServer) ... ok
testSourceAddress (test.test_socket.NetworkConnectionAttributesTest) ... Warning -- Unraisable exception
Exception ignored in thread started by: <bound method ThreadableTest.clientRun of <test.test_socket.NetworkConnectionAttributesTest testMethod=testSourceAddress>>
Traceback (most recent call last):
  File "/home/vstinner/cpython/Lib/test/test_socket.py", line 396, in clientRun
    self.clientTearDown()
  File "/home/vstinner/cpython/Lib/test/test_socket.py", line 5164, in clientTearDown
    self.cli.close()
AttributeError: 'NetworkConnectionAttributesTest' object has no attribute 'cli'
msg375242 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-08-12 13:36
Another error while running "./python -m test test_socket --fail-env-changed -j20 -r -F -w":

NetworkConnectionNoServer.test_create_connection() fails with "AssertionError: OSError not raised".

0:01:13 load avg: 69.29 [ 12/1] test_socket failed (1 min 9 sec) -- running: test_socket (...)

/home/vstinner/cpython/Lib/test/test_socket.py:5120: ResourceWarning: unclosed <socket.socket fd=3, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6,
 laddr=('127.0.0.1', 44304), raddr=('127.0.0.1', 44304)>
  socket.create_connection((HOST, port))
ResourceWarning: Enable tracemalloc to get the object allocation traceback

test test_socket failed -- Traceback (most recent call last):
  File "/home/vstinner/cpython/Lib/test/test_socket.py", line 5120, in test_create_connection
    socket.create_connection((HOST, port))
AssertionError: OSError not raised
msg375243 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-08-12 13:45
Oh, by design, NetworkConnectionNoServer.test_create_connection() has a race condition:

        port = socket_helper.find_unused_port()
        with self.assertRaises(OSError) as cm:
            socket.create_connection((HOST, port))

If another process starts to listen to the "unused" port between find_unused_port() call and the create_connection() call, create_connection() succeed and the test fails.

Maybe I should just add a comment mentioning the race condition. Or we should find a more reliable way to get an error.
msg375244 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-08-12 13:50
I tried various commands to reproduce the "test_socket (env changed)" but I failed to find a reliable way to trigger this bug. I ran test.bisect_cmd for 3h, with other commands run in parallel to stress the machine (system load between 8 and 30).
msg383128 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-12-16 09:39
I didn't see the failure recently, I close the issue.
History
Date User Action Args
2020-12-16 09:39:48vstinnersetstatus: open -> closed
resolution: out of date
messages: + msg383128

stage: resolved
2020-08-12 16:26:59shihai1991setnosy: + shihai1991
2020-08-12 13:50:11vstinnersetmessages: + msg375244
2020-08-12 13:45:14vstinnersetmessages: + msg375243
2020-08-12 13:36:38vstinnersetmessages: + msg375242
2020-08-12 13:35:36vstinnersetmessages: + msg375241
2020-08-12 13:24:07vstinnersetmessages: + msg375237
2020-08-12 11:52:23vstinnersetmessages: + msg375227
title: test_socket: threading_cleanup() failed to cleanup 0 threads (count: 0, dangling: 5) -> test_socket altered the execution environment: threading_cleanup() failed to cleanup 0 threads (count: 0, dangling: 5)
2020-06-11 14:28:20corona10setnosy: + corona10
2020-06-11 14:27:23vstinnercreate