profiling python multiprocessing pool

Question

I've got some code that is using a Pool from Python's multiprocessing module. Performance isn't what I expect and wanted to profile the code to figure out what's happening. The problem I'm having is that the profiling output gets overwritten for each job and I can't accumulate a sensible amount of stats.

For example, with:

import multiprocessing as mp
import cProfile
import time
import random

def work(i):
    x = random.random()
    time.sleep(x)
    return (i,x)

def work_(args):
    out = [None]
    cProfile.runctx('out[0] = work(args)', globals(), locals(),
                    'profile-%s.out' % mp.current_process().name)
    return out[0]

pool = mp.Pool(10)

for i in pool.imap_unordered(work_, range(100)):
    print(i)

I only get stats on the "last" job, which may not be the most computationally demanding one. I presume I need to store the stats somewhere and then only write them out when the pool is being cleaned up.

Does this answer your question? [Python multiprocess profiling](https://stackoverflow.com/questions/11041683/python-multiprocess-profiling) — Chris Withers, Jan 17 '23 at 15:14
@ChrisWithers don't think any of those answers help much. these days I think I'd use something like https://github.com/plasma-umass/scalene which (AFAIK) didn't exist back in 2015. maybe I should post an answer here or there mentioning Scalene as I'm not sure how much people know about it — Sam Mason, Jan 17 '23 at 16:39
Hmm, this maybe some kind of weird automatic SO thing. I suggested this question be closed as a dupe of that one so we can concentrate "how do I profile multiprocessing pools in Python?" answers in one place. — Chris Withers, Jan 17 '23 at 16:47

score 2 · Answer 1 · edited May 23 '17 at 10:30

My solution involves holding onto a profile object for longer and only writing it out at the "end". Hooking into the Pool teardown is described better elsewhere, but involves using a Finalize object to execute dump_stats() explicitly at the appropriate time.

This also allows me to tidy up the awkward work_ trampoline needed with the runctx I was using before.

import multiprocessing as mp
import cProfile
import time
import random

def work(i):
    # enable profiling (refers to the global object below)
    prof.enable()
    x = random.random()
    time.sleep(x)
    # disable so we don't profile the Pool
    prof.disable()
    return (i,x)

# Initialise a good profile object and make sure it gets written during Pool teardown
def _poolinit():
    global prof
    prof = cProfile.Profile()
    def fin():
        prof.dump_stats('profile-%s.out' % mp.current_process().pid)

    mp.util.Finalize(None, fin, exitpriority=1)

# create our pool
pool = mp.Pool(10, _poolinit)

for i in pool.imap_unordered(work, range(100)):
    print(i)

Loading the output shows that multiple invocations were indeed recorded:

> p = pstats.Stats("profile-ForkPoolWorker-5.out")
> p.sort_stats("time").print_stats(10)
Fri Sep 11 12:11:58 2015    profile-ForkPoolWorker-5.out

         30 function calls in 4.684 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       10    4.684    0.468    4.684    0.468 {built-in method sleep}
       10    0.000    0.000    0.000    0.000 {method 'random' of '_random.Random' objects}
       10    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

scytale · Answer 2 · 2015-09-11T11:23:39.533

0

according to the docs you can use the pid attribute to get a unique name for each output file

cProfile.runctx('out[0] = work(args)', globals(), locals(),
                'profile-%s-%s.out' % (mp.current_process().pid, datetime.now().isoformat()))

edited Sep 11 '15 at 11:23

answered Sep 11 '15 at 11:09

scytale

12,346
3
32
46

the problem is that `runctx` overwrites the output on every invocation, because it's executed multiple times you only get the "last" job for each process—about to post a semi-working solution – Sam Mason Sep 11 '15 at 11:15
ah ok - it's over written per-process - why not just add a timestamp? – scytale Sep 11 '15 at 11:22
because I have *lots* of jobs being executed in real life and I don't want millions of small profile files – Sam Mason Sep 11 '15 at 11:38

profiling python multiprocessing pool

2 Answers2