Empty python process hangs on join [sys.stderr.flush()]

Question

Python guru I need your help. I faced quite strange behavior: empty python Process hangs on joining. Looks like it forks some locked resource.

Env:

Python version: 3.5.3
OS: Ubuntu 16.04.2 LTS
Kernel: 4.4.0-75-generic

Problem description:

1) I have a logger with thread to handle messages in background and queue for this thread. Logger source code (a little bit simplified).

2) And I have a simple script which uses my logger (just code to display my problem):

import os
from multiprocessing import Process
from my_logging import get_logger


def func():
    pass


if __name__ == '__main__':

    logger = get_logger(__name__)
    logger.start()
    for _ in range(2):
        logger.info('message')

    proc = Process(target=func)
    proc.start()
    proc.join(timeout=3)
    print('TEST PROCESS JOINED: is_alive={0}'.format(proc.is_alive()))

    logger.stop()
    print('EXIT')

Sometimes this test script hangs. Script hangs on joining process "proc" (when script completes execution). Test process "proc" stay alive.

To reproduce this problem you can run the script in loop:

$ for i in {1..100} ; do /opt/python3.5.3/bin/python3.5 test.py ; done

Investigation:

Strace shows following:

strace: Process 25273 attached
futex(0x2275550, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, ffffffff

And I figured out the place where process hangs. It hangs in multiprocessing module, file process.py, line 269 (python3.5.3), on flushing STDERR:

...
267    util.info('process exiting with exitcode %d' % exitcode)
268    sys.stdout.flush()
269    sys.stderr.flush()
...

If line 269 commented the script completes successfully always.

My thoughts:

By default logging.StreamHandler uses sys.stderr as stream.

If process has been forked when logger flushing data to STDERR, process context gets some locked resource and further hangs on flushing STDERR.

Some workarounds which solves problem:

Use python2.7. I can't reproduce it with python2.7. Maybe timings prevent me to reproduce the problem.
Use process to handle messages in logger instead of thread.

Do you have any ideas on this behavior? Where is the problem? Am I doing something wrong?

Empty python process hangs on join [sys.stderr.flush()]

2 Answers