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 8ca2f2f
Author: Victor Stinner <victor.stinner@gmail.com>
Date: Wed Apr 26 15:56:25 2017 +0200

bpo-30131: test_logging now joins queue threads (bpo-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

#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 77657e4
Author: Antoine Pitrou <solipsis@pitrou.net>
Date: Wed Aug 24 22:41:05 2011 +0200

Issue bpo-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 8ca2f2f. I expected that join_thread() would... join the thread :-)

I suggest to backport the fix up to Python 3.5.

New changeset 3b69d91 by Victor Stinner in branch 'master':
bpo-30886: Fix multiprocessing.Queue.join_thread() (bpo-2642)
3b69d91

New changeset 69e4180 by Victor Stinner in branch '3.5':
bpo-30886: Fix multiprocessing.Queue.join_thread() (bpo-2642) (bpo-2644)
69e4180

New changeset 7f3d65d by Victor Stinner in branch '3.6':
bpo-30886: Fix multiprocessing.Queue.join_thread() (bpo-2642) (bpo-2643)
7f3d65d

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 aa8d0a2 which is more recent than commit 3b69d91.

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