multiprocess pool.apply_async execution sequence

Question

I am learning multiprocessing and running code I found somewhere on the website (I add print("check...")) to observe the sequence of code running with apply_async. Below is the code:

import multiprocessing
import time
def func(msg):
  for i in range(3):
    print(msg)
    time.sleep(1)
if __name__ == "__main__":
  pool = multiprocessing.Pool(processes=8)
  for i in range(10):
    msg = "hello %d" %(i)
    pool.apply_async(func, (msg, ))
    print('check whether block' + str(i))
  print('check')
  pool.close()
  pool.join()
  print("Sub-process(es) done.")

When I run it, I get the following output:

hello 0
hello 2
hello 4
hello 1
hello 3
hello 5
hello 6
hello 7
check whether block0
check whether block1
check whether block2
check whether block3
check whether block4
check whether block5
check whether block6
check whether block7
check whether block8
check whether block9
check
hello 0
hello 4
hello 1
hello 5
hello 2
hello 3
hello 6
hello 7
hello 4
hello 0
hello 6
hello 3
hello 5
hello 2
hello 7
hello 1
hello 8
hello 9
hello 9
hello 8
hello 9
hello 8
Sub-process(es) done.

But what I am hoping to see is the following:

hello 0
check whether block0
hello 2
check whether block2
hello 4
check whether block4
hello 1
check whether block1
hello 3
check whether block3
hello 5
check whether block5
hello 6
check whether block6
hello 7
check whether block7
hello 0
hello 4
hello 1
hello 5
hello 2
hello 3
hello 6
hello 7
hello 4
hello 0
hello 6
hello 3
hello 5
hello 2
hello 7
hello 1
hello 8
check whether block8
hello 9
check whether block9
hello 9
hello 8
hello 9
hello 8
check
Sub-process(es) done.

Basically I thought first 8 print('check whether...') should be executed following each pool.apply_async. And after 2 processes are freed up, 8 and 9 will be printed. And check is printed at the end. What I see seems to prove me wrong, but I don't know how exactly the sequence of codes is executed.

Answer 1

First, don't use time.sleep to do tests like that because python is intelligent and might do something sneaky. Do something like sum(range(10_000_000)), to be sure python (and your os) isn't using the cpu for something else.

Second, each time you run .apply_async(), you add a task to the queue without blocking the program, so it is perfectly normal to see all the check ... because what you're actually checking is whether or not they are added to the queue.

Third, it takes time to start a process, but adding a task to the queue is instantaneous, that is why you see all check ... before the rest.

I edited your program so it is more obvious.

def func(msg):
    for i in range(3):
        print(msg)
        sum(range(10_000_000))


if __name__ == "__main__":
    pool = multiprocessing.Pool(processes=8)
    for i in range(10):
        msg = f"hello {i: >{i+1}}"
        pool.apply_async(func, (msg, ))
        print('check whether block' + str(i))
    print('check')
    pool.close()
    pool.join()
    print("Sub-process(es) done.")

check whether block0             # <- adding task 0 to the queue
check whether block1             # <- adding task 1 to the queue
check whether block2             # <- adding task 2 to the queue
check whether block3             # <- adding task 3 to the queue
check whether block4             # <- adding task 4 to the queue
check whether block5             # <- adding task 5 to the queue
check whether block6             # <- adding task 6 to the queue
check whether block7             # <- adding task 7 to the queue
check whether block8             # <- adding task 8 to the queue
check whether block9             # <- adding task 9 to the queue
check                            #  ALL TASKS ADDED TO THE QUEUE
hello 0                          # -> Process 0 has been created to do task 0
hello  1                         # -> Process 1 has been created to do task 1
hello   2                        # -> Process 2 has been created to do task 2
hello    3                       # -> Process 3 has been created to do task 3
hello     4                      # -> Process 4 has been created to do task 4
hello      5                     # -> Process 5 has been created to do task 5
hello       6                    # -> Process 6 has been created to do task 6
hello        7                   # -> Process 7 has been created to do task 7
hello 0                          # -> Task is partly done
hello        7                   # -> Task is partly done
hello      5                     # -> Task is partly done
hello     4                      # -> Task is partly done
hello    3                       # -> Task is partly done
hello       6                    # -> Task is partly done
hello   2                        # -> Task is partly done
hello  1                         # -> Task is partly done
hello        7                   # -> Task is done
hello 0                          # -> Task is done
hello      5                     # -> Task is done
hello       6                    # -> Task is done
hello   2                        # -> Task is done
hello     4                      # -> Task is done
hello  1                         # -> Task is done
hello    3                       # -> Task is done
hello         8                  # -> Process 0 has been given task 8
hello          9                 # -> Process 7 has been given task 9
hello         8                  # -> Task is partly done
hello          9                 # -> Task is partly done
hello         8                  # -> Task is done
hello          9                 # -> Task is done
Sub-process(es) done.            # EVERYTHING DONE

Having Check whether block{X} after the first hello {X+1} is probably due to your console's speed of output for different processes and flush.