understanding execution order and timing of multiple processes in python

Question

# from
#https://pymotw.com/2/multiprocessing/basics.htmlimport multiprocessing
import multiprocessing
import time
import logging
import sys

def worker(num):
    """thread worker function"""
    starttime = time.time()
    print '------***---WORKER ALERT: ', num, ' started', starttime
    print '------***---Doing some work'
    sys.stdout.flush()
    for i in range(100000):
        for j in range(10000):
            pass
    endtime = time.time()
    print '------***----***------WORKER TIME ',num,'  : Time Taken = ', endtime - starttime
    sys.stdout.flush()
    return

start_time = time.time()
if __name__ == '__main__':
    multiprocessing.log_to_stderr(logging.DEBUG)
    jobs = []
    for i in range(1,7):
        p = multiprocessing.Process(target=worker, args=(i,))
        jobs.append(p)
        p.start()
        print '-------MAIN ALERT: process\t',p,' started', time.time()
        sys.stdout.flush()
    for j in jobs:
        print '------------------going to run JOIN\t',j
        sys.stdout.flush()
        j.join()
        print '------------------JOINED %s.exitcode = %s' % (j.name, j.exitcode)
        print '------------------JOINED Time : {}'.format(time.time() - start_time)
        sys.stdout.flush()

    p.join()
    print '====================JOINED\t',p

The output in my terminal is here With 6 workers, it takes about thirty seconds.

On my laptop (macbook pro quad core i7), the starting order of events are:

1) MAIN ALERT

2) DEBUG info

3) WORKER ALERT

Towards the end of that I see a join starting? (Just BEFORE the last process starts) If a join did indeed get called, why do workers keep getting spawned? I made sure to use

sys.stdout.flush()

so there is no buffering delay between what is in terminal buffer and the screen. So that means the join did start but the processes kept being born anyway?

The program ends with groups of

1) Worker time calculation

2) more DEBUG info

Join commands and their time of execution bring up the end in no particular order. And these joins continue to be interspersed with groups of the Worker time calculations and debug info.

If join blocks execution, then why do i not see an orderly output of groups of 1) Join time calculation

2) DEBUG shutdown info

3) Worker time calculation

Also, if i execute with 2 workers it takes ~22 secs, 6 workers ~33 secs, 10 workers ~44 sec, 12 workers ~65 sec. Why does it take so much longer with from 2 to 6 workers if I have a hyper threaded quad core cpu (8 cores?) and not exceeded my core count? I think I understand why 10 workers take 40 sec - Workers 8 and 9 have to wait for the first two cores to become free - that is about 20 sec. But then why do I need 65 sec for 12 workers? Should the first batch of cores all become free after about 22 sec so the second batch should be done by 44 sec?

The timing of different processes depends on the operating system scheduler. This isn't under Python's control. — Roland Smith, Apr 24 '16 at 17:50

score 0 · Answer 1 · edited May 23 '17 at 12:16

Its because you're using print and flush, which are I/O operation, so they are relatively slow. So while your worker processes finishing printing action, your main process already waiting in join
The same reason. More processes not always means faster performance. It depends parameters as:
- Number of cores on your machine
- Task type - I/O bounded or CPU bounded ( check here: What do the terms "CPU bound" and "I/O bound" mean?)

understanding execution order and timing of multiple processes in python

1 Answers1