Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Python 3.6 logging thread name regression with concurrent.future threads #73398

Closed
desbma mannequin opened this issue Jan 9, 2017 · 16 comments
Closed

Python 3.6 logging thread name regression with concurrent.future threads #73398

desbma mannequin opened this issue Jan 9, 2017 · 16 comments
Assignees
Labels
3.7 (EOL) end of life stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error

Comments

@desbma
Copy link
Mannequin

desbma mannequin commented Jan 9, 2017

BPO 29212
Nosy @gpshead, @brianquinlan, @methane, @desbma
PRs
  • bpo-29212: Fix the ugly repr() ThreadPoolExecutor thread name. #2315
  • [3.6] bpo-29212: Fix the ugly repr() ThreadPoolExecutor thread name #3276
  • Files
  • test.py: Program to reproduce issue
  • issue29212_1.patch: First patch
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = 'https://github.com/gpshead'
    closed_at = <Date 2017-09-06.20:41:33.631>
    created_at = <Date 2017-01-09.05:16:03.048>
    labels = ['3.7', 'type-bug', 'library']
    title = 'Python 3.6 logging thread name regression with concurrent.future threads'
    updated_at = <Date 2017-09-06.20:41:33.630>
    user = 'https://github.com/desbma'

    bugs.python.org fields:

    activity = <Date 2017-09-06.20:41:33.630>
    actor = 'gregory.p.smith'
    assignee = 'gregory.p.smith'
    closed = True
    closed_date = <Date 2017-09-06.20:41:33.631>
    closer = 'gregory.p.smith'
    components = ['Library (Lib)']
    creation = <Date 2017-01-09.05:16:03.048>
    creator = 'desbma'
    dependencies = []
    files = ['46222', '46224']
    hgrepos = []
    issue_num = 29212
    keywords = ['patch']
    message_count = 16.0
    messages = ['285021', '285025', '285028', '285339', '286033', '286035', '286080', '286081', '287417', '296555', '296568', '296582', '296616', '296617', '301174', '301201']
    nosy_count = 4.0
    nosy_names = ['gregory.p.smith', 'bquinlan', 'methane', 'desbma']
    pr_nums = ['2315', '3276']
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'behavior'
    url = 'https://bugs.python.org/issue29212'
    versions = ['Python 3.6', 'Python 3.7']

    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jan 9, 2017

    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

    @desbma desbma mannequin added the type-bug An unexpected behavior, bug, or error label Jan 9, 2017
    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jan 9, 2017

    The bug seem to have been introduced by https://hg.python.org/cpython/rev/1002a1bdc5b1

    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jan 9, 2017

    Here is a patch that restores the previous behavior and update test to catch bogus naming.

    @desbma desbma mannequin added stdlib Python modules in the Lib dir 3.7 (EOL) end of life labels Jan 9, 2017
    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jan 12, 2017

    Thoughts anyone?

    This is a minor bug, but for a common use case (easy to hit), and the fix is trivial.

    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jan 22, 2017

    Ping

    @methane
    Copy link
    Member

    methane commented Jan 23, 2017

    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".

    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jan 23, 2017

    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 :)

    @methane
    Copy link
    Member

    methane commented Jan 23, 2017

    OK. I'll wait for another opinions.

    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Feb 9, 2017

    Ping, so that this has a chance for the 3.6.1 release.

    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jun 21, 2017

    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.

    @gpshead
    Copy link
    Member

    gpshead commented Jun 21, 2017

    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.

    @gpshead gpshead self-assigned this Jun 21, 2017
    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Jun 21, 2017

    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)?

    @gpshead
    Copy link
    Member

    gpshead commented Jun 22, 2017

    New changeset a3d91b4 by Gregory P. Smith in branch 'master':
    bpo-29212: Fix the ugly repr() ThreadPoolExecutor thread name. (bpo-2315)
    a3d91b4

    @gpshead
    Copy link
    Member

    gpshead commented Jun 22, 2017

    Yes, I'll get this into 3.6. The default repr based name was clearly a regression from reasonable behavior.

    @desbma
    Copy link
    Mannequin Author

    desbma mannequin commented Sep 2, 2017

    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

    @gpshead
    Copy link
    Member

    gpshead commented Sep 3, 2017

    New changeset 7d8282d by Gregory P. Smith in branch '3.6':
    [3.6] bpo-29212: Fix the ugly repr() ThreadPoolExecutor thread name. (GH-2315) (bpo-3276)
    7d8282d

    @gpshead gpshead closed this as completed Sep 6, 2017
    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.7 (EOL) end of life stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Development

    No branches or pull requests

    2 participants