CODEWITHSUNDEEP
perlbenchmarkingwww-mechanize
Saurabh Shrivastava
Saurabh Shrivastava

Reputation: 1484

Latency time difference when use parallel::forkmanager in Perl

I am using the Google website just to explain my problem.

I have a webpage with a form. I am using WWW::Mechanize to fetch and fill the form, noting the start time in $s1.

I am reading the title on the next page and noting end time in $s2.

Then I calculate the wait time by $s2 - $s1.

This is my code

use WWW::Mechanize;
use LWP::UserAgent;
use Time::HiRes qw/gettimeofday/;
use Time::Format qw/%time/;
use POSIX qw( strftime );
use Time::HiRes qw( gettimeofday );

$m = WWW::Mechanize->new();
$m->get( "http://www.google.com" );
$m->submit_form(
    form_number => 1,
    fields      => { q => 'abcd' },
);

$s1 = gettimeofday;
my ($secs, $microsecs) = gettimeofday();
print strftime("%H:%M:%S", localtime($secs)) . sprintf(".%04d", $microsecs/10);

print " ";
print $m->title;
print " ";

$s2 = gettimeofday;
my ($secs, $microsecs) = gettimeofday();
print strftime("%H:%M:%S", localtime($secs)) . sprintf(".%04d", $microsecs/10);

$s3 = $s2 - $s1;
$s3 = $s3 * 1000;
print "  $s3\n";

The output is:

18:02:42.71923 abcd - Google Search 18:02:42.71996  0.737905502319336

Now, i used same code in Parallel Fork Manager keeping loopcount as 1.
My code:

use Parallel::ForkManager;
use WWW::Mechanize;
use LWP::UserAgent;
use Time::HiRes qw/gettimeofday/;
use Time::Format qw/%time/;
use POSIX qw( strftime );
use Time::HiRes qw( gettimeofday );

$count = 1;

$pm = new Parallel::ForkManager($count);

for ( 1 .. $count ) {

  $pm->start and next;

  $m = WWW::Mechanize->new();
  $m->get( "http://www.google.com" );
  $m->submit_form(
      form_number => 1,
      fields      => { q => 'abcd' },
  );

  $s1 = gettimeofday;
  my ($secs, $microsecs) = gettimeofday();
  print strftime("%H:%M:%S", localtime($secs)) . sprintf(".%04d", $microsecs/10);

  print " ";
  print $m->title;
  print " ";

  $s2 = gettimeofday;
  my ($secs, $microsecs) = gettimeofday();
  print strftime("%H:%M:%S", localtime($secs)) . sprintf(".%04d", $microsecs/10);

  $s3 = $s2 - $s1;
  $s3 = $s3 * 1000;
  print "  $s3\n";

  $pm->finish
}  

$pm->wait_all_children; ## wait for the child processes

My output:

18:02:48.55297 abcd - Google Search 18:02:48.55325  0.282049179077148

I am not able to understand why there is so much difference in Latency time when use fork(reduce to 1/3). It should be same. Any idea. My main purpose is to record Latency time for 1000-2000 requests and find average. Since there is so much difference between direct code and same code under fork, i am not sure if Latency time is correct.

Upvotes: 0

Views: 149

Answers (1)

Borodin
Borodin

Reputation: 126722

You aren't measuring the internet response time, you're just timing a few print statements and function calls. If you have an internet connection that responds within half a millisecond then I'm amazed!

Try this code, which does something similar but times the internet request/response round trip

use strict;
use warnings;

use WWW::Mechanize;
use Time::HiRes 'gettimeofday';

my $mech = WWW::Mechanize->new;

$mech->get( 'http://www.google.com/' );

my $t0 = gettimeofday;

$mech->submit_form(
    form_number => 1,
    fields      => { q => 'abcd' },
);

my $t1 = gettimeofday;

printf "Title: %s\n",  $mech->title;
printf "Delay: %5.3fs\n", $t1 - $t0;

output

Title: abcd - Google Search
Delay: 1.784s

Upvotes: 3

Related Questions