http://buildbot.python.org/all/builders/AMD64%20FreeBSD%2010.x%20Shared%203.x/builds/557/steps/test/logs/stdio test_handle_called_with_mp_queue (test.test_logging.QueueListenerTest) ... Warning -- threading_cleanup() failed to cleanup -1 threads after 3 sec (count: 0, dangling: 1) ok

The load average was 3.15: 0:04:33 load avg: 3.15 [176/406] test_logging failed (env changed) -- Another fail on AMD64 FreeBSD CURRENT Non-Debug 3.x: http://buildbot.python.org/all/builders/AMD64%20FreeBSD%20CURRENT%20Non-Debug%203.x/builds/568/steps/test/logs/stdio 0:01:56 load avg: 3.45 [ 44/406] test_logging failed (env changed) ... test_output (test.test_logging.UnixSocketHandlerTest) ... ok test_output (test.test_logging.UnixDatagramHandlerTest) ... ok test_output (test.test_logging.UnixSysLogHandlerTest) ... ok test__all__ (test.test_logging.MiscTestCase) ... ok test_handle_called_with_mp_queue (test.test_logging.QueueListenerTest) ... Warning -- threading_cleanup() failed to cleanup -1 threads after 4 sec (count: 0, dangling: 1) ok test_handle_called_with_queue_queue (test.test_logging.QueueListenerTest) ... ok test_no_messages_in_queue_after_stop (test.test_logging.QueueListenerTest) ... ok

Previous issue which fixed QueueListenerTest of test_logging is bpo-30131: commit 8ca2f2faefa8dba323a2e4c4b86efb633d7a53cf Author: Victor Stinner <victor.stinner@gmail.com> Date: Wed Apr 26 15:56:25 2017 +0200 bpo-30131: test_logging now joins queue threads (#1298) QueueListenerTest of test_logging now closes the multiprocessing Queue and joins its thread to prevent leaking dangling threads to following tests. Add also @support.reap_threads to detect earlier if a test leaks threads (and try to "cleanup" these threads).

While trying to reproduce the bug, I got: test_handle_called_with_mp_queue (test.test_logging.QueueListenerTest) ... /usr/home/haypo/cpython/Lib/test/support/__init__.py:1515: ResourceWarning: unclosed <socket.socket fd=6, family=AddressFamily.AF_INET, type=536870913, proto=0, laddr=('127.0.0.1', 8166), raddr=('127.0.0.1', 8167)> gc.collect() ok

The problem is that multiprocessing.Queue.join_thread() does nothing since the thread wasn't started by a subprocess. See also bpo-30171: Emit ResourceWarning in multiprocessing Queue destructor.

The warning is a race condition which can be reproduced easily on Linux using attached test_handle_called_with_mp_queue-bug.patch, run: haypo@selma$ ./python -m test --fail-env-changed -m test_handle_called_with_mp_queue test_logging Run tests sequentially 0:00:00 load avg: 0.22 [1/1] test_logging Warning -- threading_cleanup() failed to cleanup 20 threads after 0 sec (count: 20, dangling: 21) Warning -- threading._dangling was modified by test_logging Before: <_weakrefset.WeakSet object at 0x7fe1df5302c8> After: <_weakrefset.WeakSet object at 0x7fe1df5338e0> test_logging failed (env changed) 1 test altered the execution environment: test_logging Total duration: 718 ms Tests result: ENV CHANGED

https://github.com/python/cpython/pull/2642 fixes the warning. I tested the change with test_handle_called_with_mp_queue-bug.patch: no more warning. Sorry, I don't know multiprocessing to understand the purpose of the removed test. I would like to really make sure that a Queue object doesn't "leak" a thread when I close .close() + .join_thread(). It's surprising that .join_thread() doesn't join anything and leave a thread running in the background. Even if in the common case, when the system load is low, the thread quits quickly thanks to .close().

Hum, interesting, created_by_this_process was already removed from Python 2.7 in bpo-4106: commit 77657e40fa5f43fe6f7ffb6e32da4613dba657e1 Author: Antoine Pitrou <solipsis@pitrou.net> Date: Wed Aug 24 22:41:05 2011 +0200 Issue #4106: Fix occasional exceptions printed out by multiprocessing on interpreter shutdown. This bug doesn't seem to exist on 3.2, where daemon threads are killed before Py_Finalize() is entered.

> I would like to really make sure that a Queue object doesn't "leak" a thread when I close .close() + .join_thread(). I don't understand how this happens. The Finalize object only acts as an atexit handler. When called as a regular finalize, `self._thread` is dead and therefore `_finalize_join()` doesn't do anything.

Oh, that's because you're calling join_thread() explicitly. I see. I agree that the fix looks desirable then.

> I don't understand how this happens. If you run "./python -m test --fail-env-changed -m test_handle_called_with_mp_queue test_logging" with attached test_handle_called_with_mp_queue-bug.patch, no finalizer is registered: .join_thread() does nothing, because created_by_this_process is true.

> Oh, that's because you're calling join_thread() explicitly. I see. I agree that the fix looks desirable then. FYI I added join_thread() in my first attempt to fix "Warning -- threading._dangling was modified by test_logging": bpo-30131, commit 8ca2f2faefa8dba323a2e4c4b86efb633d7a53cf. I expected that join_thread() would... join the thread :-)

I suggest to backport the fix up to Python 3.5.

 New changeset 3b69d911c57ef591ac0c0f47a66dbcad8337f33a by Victor Stinner in branch 'master': bpo-30886: Fix multiprocessing.Queue.join_thread() (#2642) https://github.com/python/cpython/commit/3b69d911c57ef591ac0c0f47a66dbcad8337f33a 

 New changeset 69e41807f0851ff1107f949dcdc94dbb0af32acd by Victor Stinner in branch '3.5': bpo-30886: Fix multiprocessing.Queue.join_thread() (#2642) (#2644) https://github.com/python/cpython/commit/69e41807f0851ff1107f949dcdc94dbb0af32acd 

 New changeset 7f3d65d6e4f8bebaaf996efb1c1adb67eb1724cb by Victor Stinner in branch '3.6': bpo-30886: Fix multiprocessing.Queue.join_thread() (#2642) (#2643) https://github.com/python/cpython/commit/7f3d65d6e4f8bebaaf996efb1c1adb67eb1724cb 

Ok, I applied my fix to 3.5, 3.6 and master branches. Thanks for the review Antoine.

I'm not sure that the bug is fully fixed, I still saw a warning on: http://buildbot.python.org/all/builders/AMD64%20FreeBSD%2010.x%20Shared%203.x/builds/561/ This build tested the commit aa8d0a24694bea05061f1920ec3f944a9e6799d5 which is more recent than commit 3b69d911c57ef591ac0c0f47a66dbcad8337f33a. test_handle_called_with_mp_queue (test.test_logging.QueueListenerTest) ... Warning -- threading_cleanup() failed to cleanup -1 threads after 5 sec (count: 0, dangling: 1) ok