Perl Parallel::ForkManager wait_all_children() takes excessively long time

Question

I have a script that uses Parallel::ForkManager. However, the wait_all_children() process takes incredibly long time even after all child-processes are completed. The way I know is by printing out some timestamps (see below). Does anyone have any idea what might be causing this (I have 16 CPU cores on my machine)?

my $pm = Parallel::ForkManager->new(16);
for my $i (1..16) {
    $pm->start($i) and next;

    ... do something within the child-process ...

    print (scalar localtime), " Process $i completed.\n";
    $pm->finish();
}
print (scalar localtime), " Waiting for some child process to finish.\n"; 
$pm->wait_all_children();
print (scalar localtime), " All processes finished.\n"; 

Clearly, I'll get the Waiting for some child process to finish message first, with a timestamp of, say, 7:08:35. Then I'll get a list of Process i completed messages, with the last one at 7:10:30. However, I do not receive the message All Processes finished until 7:16:33(!). Why is that 6-minute delay between 7:10:30 and 7:16:33? Thx!

Answer 1

I tried this:

#!/opt/perl/bin/perl

use strict; use warnings;

use Parallel::ForkManager;

my $pm = Parallel::ForkManager->new(16);

for my $i (1..16) {
    $pm->start($i) and next;
    sleep rand 20;
    printf "%s : Process %d completed\n", scalar localtime, $i;
    $pm->finish;
}

printf "%s: Waiting for some child to finish\n", scalar localtime;
$pm->wait_all_children;

printf "%s: All processes finished.\n", scalar localtime; 

I got:

[sinan@archardy Src]$ ./y.pl
Thu Mar 11 17:14:16 2010 : Process 3 completed
Thu Mar 11 17:14:16 2010: Waiting for some child to finish
Thu Mar 11 17:14:18 2010 : Process 8 completed
Thu Mar 11 17:14:18 2010 : Process 14 completed
<snip>...</snip>
Thu Mar 11 17:14:34 2010 : Process 12 completed
Thu Mar 11 17:14:34 2010: All processes finished.

I have perl 5.10.1 on Linux with Parallel::ForkManager version 0.7.5.

Therefore, I conclude that whatever issue you are having is happening as a consequence of what happens when you

# ... do something within the child-process ...

Update: The problem is, you are printing the Process finished message before the the finish call. Try the following version:

#!/opt/perl/bin/perl

use strict; use warnings;

use Parallel::ForkManager;

my $pm = Parallel::ForkManager->new(16);
$pm->run_on_finish( sub {
    printf "%s : Process completed: @_\n", scalar localtime
});

for my $i (1..16) {
    $pm->start($i) and next;
    sleep rand 20;
    $pm->finish;
}

printf "%s: Waiting for some child to finish\n", scalar localtime;
$pm->wait_all_children;

printf "%s: All processes finished.\n", scalar localtime;

See Callbacks in Parallel::ForkManager documentation for more information. If the delay disappears, then the symptom you are observing was due to the fact that you were claiming the forked process had finished before it was done.