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

Hang on interpreter shutdown if daemon thread prints to stdout #67498

Closed
marienz mannequin opened this issue Jan 24, 2015 · 10 comments
Closed

Hang on interpreter shutdown if daemon thread prints to stdout #67498

marienz mannequin opened this issue Jan 24, 2015 · 10 comments
Labels
interpreter-core (Objects, Python, Grammar, and Parser dirs) type-bug An unexpected behavior, bug, or error

Comments

@marienz
Copy link
Mannequin

marienz mannequin commented Jan 24, 2015

BPO 23309
Nosy @tim-one, @marienz, @pitrou
Files
  • dio.py
  • bufio_lock_finalizing.patch
  • bufio_lock_finalizing_fatal_error.patch
  • bufio_lock_finalizing_fatal_error2.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 = None
    closed_at = <Date 2015-04-13.17:53:25.496>
    created_at = <Date 2015-01-24.13:52:40.361>
    labels = ['interpreter-core', 'type-bug']
    title = 'Hang on interpreter shutdown if daemon thread prints to stdout'
    updated_at = <Date 2015-04-13.17:53:25.494>
    user = 'https://github.com/marienz'

    bugs.python.org fields:

    activity = <Date 2015-04-13.17:53:25.494>
    actor = 'pitrou'
    assignee = 'none'
    closed = True
    closed_date = <Date 2015-04-13.17:53:25.496>
    closer = 'pitrou'
    components = ['Interpreter Core']
    creation = <Date 2015-01-24.13:52:40.361>
    creator = 'marienz'
    dependencies = []
    files = ['37835', '38391', '38392', '38549']
    hgrepos = []
    issue_num = 23309
    keywords = ['patch']
    message_count = 10.0
    messages = ['234615', '237551', '237552', '237553', '237554', '237605', '237615', '238477', '240681', '240684']
    nosy_count = 5.0
    nosy_names = ['tim.peters', 'marienz', 'pitrou', 'neologix', 'python-dev']
    pr_nums = []
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'behavior'
    url = 'https://bugs.python.org/issue23309'
    versions = ['Python 3.4', 'Python 3.5']

    @marienz
    Copy link
    Mannequin Author

    marienz mannequin commented Jan 24, 2015

    A script spawning a single daemon thread calling print() in a loop (like the attached) will usually hang on shutdown in Python 3.4.2 and hg rev 8d802fb6ae32. Attaching gdb at that point shows the following:

    (gdb) thread apply all bt

    Thread 1 (Thread 0x7fd927d58700 (LWP 30274)):
    #0 sem_wait () at ../sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85
    #1 0x00000000005282fe in PyThread_acquire_lock_timed (lock=0x1c5ea30, microseconds=microseconds@entry=-1,
    intr_flag=intr_flag@entry=0) at Python/thread_pthread.h:352
    #2 0x0000000000528414 in PyThread_acquire_lock (lock=<optimized out>, waitflag=waitflag@entry=1)
    at Python/thread_pthread.h:556
    #3 0x0000000000567e4c in _enter_buffered_busy (self=0x7fd927bc2b48) at ./Modules/_io/bufferedio.c:327
    #4 buffered_flush (self=0x7fd927bc2b48, args=<optimized out>) at ./Modules/_io/bufferedio.c:874
    #5 0x000000000042822a in PyObject_Call (func=0x7fd9277b69d8, arg=<optimized out>, kw=<optimized out>)
    at Objects/abstract.c:2086
    #6 0x00000000004290e4 in call_function_tail (args=0x7fd927b8d048, callable=0x7fd9277b69d8) at Objects/abstract.c:2124
    #7 callmethod (is_size_t=1, va=0x7fff5c6cf6b0, format=0x0, func=0x7fd9277b69d8) at Objects/abstract.c:2193
    #8 _PyObject_CallMethodId_SizeT (o=<optimized out>, name=<optimized out>, format=0x0) at Objects/abstract.c:2279
    #9 0x000000000042822a in PyObject_Call (func=0x7fd9277b6990, arg=<optimized out>, kw=<optimized out>)
    at Objects/abstract.c:2086
    #10 0x0000000000428cc4 in call_function_tail (args=0x7fd927b8d048, callable=0x7fd9277b6990) at Objects/abstract.c:2124
    #11 callmethod (is_size_t=0, va=0x7fff5c6cf7e0, format=0x5b9924 "", func=0x7fd9277b6990) at Objects/abstract.c:2193
    #12 _PyObject_CallMethodId (o=o@entry=0x7fd927b5d3a8, name=name@entry=0x862b00 <PyId_flush>,
    format=format@entry=0x5b9924 "") at Objects/abstract.c:2238
    #13 0x000000000050a521 in flush_std_files () at Python/pylifecycle.c:488
    #14 0x000000000050a5aa in Py_Finalize () at Python/pylifecycle.c:550
    #15 0x000000000041fc92 in Py_Main (argc=-1, argv=0x1) at Modules/main.c:787
    #16 0x000000000041be3c in main (argc=2, argv=<optimized out>) at ./Programs/python.c:69

    The daemon thread has exited, and the main thread hangs trying to flush stdout.

    I haven't fully tracked down what happens here, but I think it's this:

    • daemon thread calls ENTER_BUFFERED on stdout
    • daemon thread drops the GIL before writing to stdout
    • main thread grabs the GIL and starts exiting
    • main thread sets _Py_Finalizing, signaling daemon threads to exit
    • main thread calls flush_std_files and drops the GIL
    • daemon thread grabs the GIL and immediately exits, without reaching LEAVE_BUFFERED
    • main thread deadlocks trying to ENTER_BUFFERED the same file

    If that is what happens, I don't really see how to fix it (it's an example of daemon threads not releasing their resources, which the documentation warns about). But it's obviously unfortunate if merely writing to stdout/err is such a resource.

    @marienz marienz mannequin added interpreter-core (Objects, Python, Grammar, and Parser dirs) type-bug An unexpected behavior, bug, or error labels Jan 24, 2015
    @pitrou
    Copy link
    Member

    pitrou commented Mar 8, 2015

    Your analysis sounds right to me.

    @pitrou
    Copy link
    Member

    pitrou commented Mar 8, 2015

    A possible solution is to tweak the IO lock acquire on shutdown: only wait for a grace period instead of waiting indefinitely. Attached patch demonstrates the solution (and solves the deadlock issue in your script).

    @pitrou
    Copy link
    Member

    pitrou commented Mar 8, 2015

    (note that trying to print a warning or raise an error only makes things worse if the stream subject to deadlock is stderr)

    @pitrou
    Copy link
    Member

    pitrou commented Mar 8, 2015

    Attached patch is stricter and dumps a fatal error after the grace period.

    @marienz
    Copy link
    Mannequin Author

    marienz mannequin commented Mar 9, 2015

    I'm afraid I don't have real-world code I can confirm is fixed, since I reported this on behalf of someone on irc in #python.

    I think I'd prefer the Py_FatalError version of the patch. It's definitely possible to see writes to stdout/stderr at this time. If I read the first version right, it'll succeed the ENTER_BUFFERED without actually grabbing the lock, which seems problematic. But failing ENTER_BUFFERED is probably also more problematic, as it will probably lead to another exception that Python'll try to write to stderr, which fails the same way... If stdout/stderr are in a broken state during shutdown, Python is probably better off calling Py_FatalError rather than intermittently discarding messages.

    @pitrou
    Copy link
    Member

    pitrou commented Mar 9, 2015

    Thank you for the feedback. Yes, I now also think the fatal error is the preferrable way. I'll see if I can add a reliable test.

    @pitrou
    Copy link
    Member

    pitrou commented Mar 18, 2015

    Here is a patch with tests.

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Apr 13, 2015

    New changeset 2c53a5302058 by Antoine Pitrou in branch '3.4':
    Issue bpo-23309: Avoid a deadlock at shutdown if a daemon thread is aborted
    https://hg.python.org/cpython/rev/2c53a5302058

    New changeset 8a3da91737cf by Antoine Pitrou in branch 'default':
    Issue bpo-23309: Avoid a deadlock at shutdown if a daemon thread is aborted
    https://hg.python.org/cpython/rev/8a3da91737cf

    @pitrou
    Copy link
    Member

    pitrou commented Apr 13, 2015

    Fix pushed! closing.

    @pitrou pitrou closed this as completed Apr 13, 2015
    @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
    interpreter-core (Objects, Python, Grammar, and Parser dirs) type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Development

    No branches or pull requests

    1 participant