classification
Title: Python 3.6 logging thread name regression with concurrent.future threads
Type: behavior Stage: resolved
Components: Library (Lib) Versions: Python 3.7, Python 3.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: gregory.p.smith Nosy List: bquinlan, desbma, gregory.p.smith, inada.naoki
Priority: normal Keywords: patch

Created on 2017-01-09 05:16 by desbma, last changed 2017-09-06 20:41 by gregory.p.smith. This issue is now closed.

Files
File name Uploaded Description Edit
test.py desbma, 2017-01-09 05:16 Program to reproduce issue
issue29212_1.patch desbma, 2017-01-09 08:25 First patch review
Pull Requests
URL Status Linked Edit
PR 2315 merged gregory.p.smith, 2017-06-21 18:29
PR 3276 merged gregory.p.smith, 2017-09-03 21:34
Messages (16)
msg285021 - (view) Author: desbma (desbma) * Date: 2017-01-09 05:16
Logging statement using 'threadName' from concurrent.futures threads produce the wrong output with Python 3.6.

The attached program with Python 3.5.X outputs:
MainThread From main thread
Thread-1 From worker thread

But with 3.6, it outputs:
MainThread From main thread
<concurrent.futures.thread.ThreadPoolExecutor object at 0x7f96711ac278>_0 From worker thread
msg285025 - (view) Author: desbma (desbma) * Date: 2017-01-09 08:05
The bug seem to have been introduced by https://hg.python.org/cpython/rev/1002a1bdc5b1
msg285028 - (view) Author: desbma (desbma) * Date: 2017-01-09 08:25
Here is a patch that restores the previous behavior and update test to catch bogus naming.
msg285339 - (view) Author: desbma (desbma) * Date: 2017-01-12 18:16
Thoughts anyone?

This is a minor bug, but for a common use case (easy to hit), and the fix is trivial.
msg286033 - (view) Author: desbma (desbma) * Date: 2017-01-22 23:21
Ping
msg286035 - (view) Author: Inada Naoki (inada.naoki) * (Python committer) Date: 2017-01-23 01:27
I don't think this is a regression, bug, bogos naming.

I agree that "<concurrent.futures.thread.ThreadPoolExecutor object at 0x7f96711ac278>_0" is ugly.
But the name describes what is the thread, than "Thread-1".

How about giving default thread_name_prefix less ugly?
e.g. "ThreadPoolExecutor-worker".
msg286080 - (view) Author: desbma (desbma) * Date: 2017-01-23 12:20
I don't think using repr(self) as a fallback was intentional, that is why I wrote regression, but I may be wrong.

I agree that the previous default 'Thread-x' gives little information, but only the user can give a relevant name to describe what a thread is doing.
Using a new default like "ThreadPoolExecutor-worker_x" would give more information but at the same time it leaks internal information about how the thread was created in the code (which is not relevant when using the logging module), not about what it's doing.

Anyway as long as that repr string is replaced, I am happy :)
msg286081 - (view) Author: Inada Naoki (inada.naoki) * (Python committer) Date: 2017-01-23 12:52
OK. I'll wait for another opinions.
msg287417 - (view) Author: desbma (desbma) * Date: 2017-02-09 13:49
Ping, so that this has a chance for the 3.6.1 release.
msg296555 - (view) Author: desbma (desbma) * Date: 2017-06-21 13:46
Ping.

I think any change, included Inada Naoki's idea above is better that the current behavior that pollutes the logging module output.

Unfortunately I cannot rely on the 3.6 new thread_name_prefix argument for portability reasons, and have to manually patch my Python 3.6.x installs just to fix this.
msg296568 - (view) Author: Gregory P. Smith (gregory.p.smith) * (Python committer) Date: 2017-06-21 16:57
agreed the repr(self) name being surfaced is a regression even if technically "correct".

your patch makes sense, but i think a nicer variant of it will be to name the thread ("Executor_" + str(num_threads)) when no thread_name_prefix is supplied.
msg296582 - (view) Author: desbma (desbma) * Date: 2017-06-21 20:32
Thank you Gregory for the insight and new patch.

Can this be merged in the 3.6 branch as well (targeting the 3.6.3 release)?
msg296616 - (view) Author: Gregory P. Smith (gregory.p.smith) * (Python committer) Date: 2017-06-22 06:41
New changeset a3d91b43c2851312fb942f31afa12f5961706db6 by Gregory P. Smith in branch 'master':
bpo-29212: Fix the ugly repr() ThreadPoolExecutor thread name. (#2315)
https://github.com/python/cpython/commit/a3d91b43c2851312fb942f31afa12f5961706db6
msg296617 - (view) Author: Gregory P. Smith (gregory.p.smith) * (Python committer) Date: 2017-06-22 06:43
Yes, I'll get this into 3.6.  The default repr based name was clearly a regression from reasonable behavior.
msg301174 - (view) Author: desbma (desbma) * Date: 2017-09-02 20:22
Gregory, please don't forget to backport the fix in the 3.6 branch, so that it is released with Python 3.6.3.

Thank you
msg301201 - (view) Author: Gregory P. Smith (gregory.p.smith) * (Python committer) Date: 2017-09-03 21:52
New changeset 7d8282d25d4900dd3367daf28bb393be7f276729 by Gregory P. Smith in branch '3.6':
[3.6] bpo-29212: Fix the ugly repr() ThreadPoolExecutor thread name. (GH-2315) (#3276)
https://github.com/python/cpython/commit/7d8282d25d4900dd3367daf28bb393be7f276729
History
Date User Action Args
2017-09-06 20:41:33gregory.p.smithsetstatus: open -> closed
resolution: fixed
stage: resolved
2017-09-03 21:52:22gregory.p.smithsetmessages: + msg301201
2017-09-03 21:34:28gregory.p.smithsetpull_requests: + pull_request3319
2017-09-02 20:22:27desbmasetmessages: + msg301174
2017-06-22 06:43:48gregory.p.smithsetmessages: + msg296617
2017-06-22 06:41:15gregory.p.smithsetmessages: + msg296616
2017-06-21 20:32:21desbmasetmessages: + msg296582
2017-06-21 18:29:38gregory.p.smithsetpull_requests: + pull_request2365
2017-06-21 16:58:00gregory.p.smithsetassignee: gregory.p.smith
messages: + msg296568
2017-06-21 13:46:46desbmasetmessages: + msg296555
2017-02-09 13:49:23desbmasetmessages: + msg287417
2017-01-23 12:52:07inada.naokisetmessages: + msg286081
2017-01-23 12:20:05desbmasetmessages: + msg286080
2017-01-23 02:56:04xiang.zhangsetnosy: + gregory.p.smith
2017-01-23 01:27:04inada.naokisetnosy: + inada.naoki
messages: + msg286035
2017-01-22 23:24:23ned.deilysetnosy: + bquinlan
2017-01-22 23:21:56desbmasetmessages: + msg286033
2017-01-12 18:16:52desbmasetmessages: + msg285339
2017-01-09 08:31:39desbmasetcomponents: + Library (Lib)
versions: + Python 3.7
2017-01-09 08:25:52desbmasetfiles: + issue29212_1.patch
keywords: + patch
messages: + msg285028
2017-01-09 08:05:10desbmasetmessages: + msg285025
2017-01-09 05:16:03desbmacreate