7

I have N independent tasks that are executed in a multiprocessing.Pool of size os.cpu_count() (8 in my case), with maxtasksperchild=1 (i.e. a fresh worker process is created for each new task).

The main script can be simplified to:

import subprocess as sp
import multiprocessing as mp

def do_work(task: dict) -> dict:
    res = {}
    
    # ... work ...
   
    for i in range(5):
        out = sp.run(cmd, stdout=sp.PIPE, stderr=sp.PIPE, check=False, timeout=60)
        res[i] = out.stdout.decode('utf-8')

    # ... some more work ...

    return res


if __name__ == '__main__':
    tasks = load_tasks_from_file(...) # list of dicts

    logger = mp.get_logger()
    results = []

    with mp.Pool(processes=os.cpu_count(), maxtasksperchild=1) as pool:
        for i, res in enumerate(pool.imap_unordered(do_work, tasks), start=1):
            results.append(res)
            logger.info('PROGRESS: %3d/%3d', i, len(tasks))

    dump_results_to_file(results)

The pool sometimes gets stuck. The traceback when I do a KeyboardInterrupt is here. It indicates that the pool won't fetch new tasks and/or worker processes are stuck in a queue / pipe recv() call. I was unable to reproduce this deterministically, varying different configs of my experiments. There's a chance that if I run the same code again, it'll finish gracefully.

Further observations:

  • Python 3.7.9 on x64 Linux
  • start method for multiprocessing is fork (using spawn does not solve the issue)
  • strace reveals that the processes are stuck in a futex wait; gdb's backtrace also shows: do_futex_wait.constprop
  • disabling logging / explicit flushing does not help
  • there's no bug in how a task is defined (i.e. they are all loadable).

Update: It seems that deadlock occurs even with a pool of size = 1.

strace reports that the process is blocked on trying to acquire some lock located at 0x564c5dbcd000:

futex(0x564c5dbcd000, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY

and gdb confirms:

(gdb) bt
#0  0x00007fcb16f5d014 in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0x00007fcb16f5d118 in __new_sem_wait_slow.constprop.0 () from /usr/lib/libpthread.so.0
#2  0x0000564c5cec4ad9 in PyThread_acquire_lock_timed (lock=0x564c5dbcd000, microseconds=-1, intr_flag=0)
    at /tmp/build/80754af9/python_1598874792229/work/Python/thread_pthread.h:372
#3  0x0000564c5ce4d9e2 in _enter_buffered_busy (self=self@entry=0x7fcafe1e7e90)
    at /tmp/build/80754af9/python_1598874792229/work/Modules/_io/bufferedio.c:282
#4  0x0000564c5cf50a7e in _io_BufferedWriter_write_impl.isra.2 (self=0x7fcafe1e7e90)
    at /tmp/build/80754af9/python_1598874792229/work/Modules/_io/bufferedio.c:1929
#5  _io_BufferedWriter_write (self=0x7fcafe1e7e90, arg=<optimized out>)
    at /tmp/build/80754af9/python_1598874792229/work/Modules/_io/clinic/bufferedio.c.h:396
Alexandru Dinu
  • 1,159
  • 13
  • 24
  • 1
    Are you _sure_ the `subprocess.run` call completes? That will block until the subprocess finishes, so if it doesn't.... – bnaecker Dec 02 '20 at 19:51
  • Yes, `subprocess.run` finishes. No other subprocesses of workers are reported (e.g. in `htop`) when the deadlock happens - all in interruptible sleep. – Alexandru Dinu Dec 02 '20 at 19:57
  • 1
    What OS and version of Python are you using? The default start methods differ among the various options (among obvious suspects, before 3.8, macOS used `fork`, but [it caused problems](https://bugs.python.org/issue33725), so [3.8 and higher switched to `spawn` by default](https://docs.python.org/3/whatsnew/3.8.html#multiprocessing)), and could potentially be related to your problem. Even on a forking system, you might want to change the start method; `fork` can be a problem if the parent is large and the children perform garbage collection (causing copy-on-write, making memory usage spike). – ShadowRanger Dec 02 '20 at 20:10
  • I am using Python 3.7.9 on x64 Linux (Manjaro) (edited the question). I recall using `spawn` as well, but it did not solve the problem, I will try again now. – Alexandru Dinu Dec 02 '20 at 20:14
  • 1
    Can you try limiting processes to 1 and see if it still deadlocks with a large tasklist? – Dschoni Dec 04 '20 at 08:49
  • It seems that the deadlock occurs with 1 process as well.. – Alexandru Dinu Dec 04 '20 at 18:20
  • 1
    In case _not_ using `maxtasksperchild` solves your issue, you might try with upgrading to Python 3.8, there were changes concerning worker-management. – Darkonaut Dec 04 '20 at 18:38
  • Hi, "strace reveals that the processes are stuck in a futex wait" -> do you mind sharing the full strace command that helped you conclude this? – Params Raman Aug 25 '22 at 23:40
  • One can use `strace -p ` to attach to a running process. See `man strace`. – Alexandru Dinu Sep 05 '22 at 17:44

1 Answers1

7

The deadlock occurred due to high memory usage in workers, thus triggering the OOM killer which abruptly terminated the worker subprocesses, leaving the pool in a messy state.

This script reproduces my original problem.

For the time being I am considering switching to a ProcessPoolExecutor which will throw a BrokenProcessPool exception when an abrupt worker termination occurs.

References:

Alexandru Dinu
  • 1,159
  • 13
  • 24
  • any better solution to avoid that? – Alberto Sinigaglia Dec 23 '22 at 18:46
  • It depends on what you mean by "better". If you're handling large data, you can look into potential optimizations on that level (i.e. fixing the cause, not the effect). In my case, the main problem was that the error was "silent", thus switching to a ProcessPoolExecutor helped discover the OOM behaviour. – Alexandru Dinu Feb 03 '23 at 15:25