times() returns incorrect value?

Discussion in 'Perl Misc' started by makoto kuwata, Sep 22, 2009.

  1. Hi,
    I have a question about times() function.
    times() returns user-time, but these values seems to be incorrect.
    The following is an example code to show incorrect result:

    bench.pl:
    ----------------------------------
    use strict;
    use Time::HiRes;

    sub fib {
    my ($n) = @_;
    return $n <= 2 ? 1 : fib($n-2)+fib($n-1);
    }

    my @start_times = times();
    my $start_time = Time::HiRes::time();

    my $n = 35;
    print "fib($n) = ", fib($n), "\n";

    my @end_times = times();
    my $end_time = Time::HiRes::time();

    my $user_time = $end_times[0] - $start_times[0];
    my $sys_time = $end_times[1] - $start_times[1];
    my $real_time = $end_time - $start_time;

    my $format = "*** user %4.4f, sys %4.4f, real %4.4f\n";
    printf $format, $user_time, $sys_time, $real_time;
    --------------------------------

    output example:
    --------------------------------
    $ /usr/bin/perl -v | grep built
    This is perl, v5.10.0 built for x86_64-linux-thread-multi
    $ time /usr/bin/perl fib.pl
    fib(35) = 9227465
    *** user 4.2900, sys 0.0000, real 13.1078

    real 0m13.126s
    user 0m4.294s
    sys 0m0.001s
    --------------------------------

    The above output shows that real time is over 13 seconds,
    but user time is reported only 4.29 seconds.
    (Of course, there is no other process to consume cpu.)
    I compled and installed Perl 5.10 from source, but issue is not
    solved.

    Environment: FedoraCore 11 (x64), Macbook (Core2Duo 2.0GHz),

    $ uname -a
    Linux spica.local 2.6.29.4-167.fc11.x86_64 #1 SMP Wed May 27 17:27:08
    EDT 2009 x86_64 x86_64 x86_64 GNU/Linux

    Any suggestion?

    --
    regards,
    makoto kuwata
     
    makoto kuwata, Sep 22, 2009
    #1
    1. Advertising

  2. makoto kuwata

    Teo Guest

    Dear Makoto,

    On Sep 22, 2:50 pm, makoto kuwata <> wrote:
    > I have a question about times() function.
    > times() returns user-time, but these values seems to be incorrect.
    > The following is an example code to show incorrect result:
    >
    > bench.pl:
    > ----------------------------------
    > use strict;
    > use Time::HiRes;
    >
    > sub fib {
    >   my ($n) = @_;
    >   return $n <= 2 ? 1 : fib($n-2)+fib($n-1);
    >
    > }
    >
    > my @start_times = times();
    > my $start_time  = Time::HiRes::time();
    >
    > my $n = 35;
    > print "fib($n) = ", fib($n), "\n";
    >
    > my @end_times   = times();
    > my $end_time    = Time::HiRes::time();
    >
    > my $user_time = $end_times[0] - $start_times[0];
    > my $sys_time  = $end_times[1] - $start_times[1];
    > my $real_time = $end_time     - $start_time;
    >
    > my $format = "*** user %4.4f, sys %4.4f, real %4.4f\n";
    > printf $format, $user_time, $sys_time, $real_time;
    > --------------------------------
    >
    > output example:
    > --------------------------------
    > $ /usr/bin/perl -v | grep built
    > This is perl, v5.10.0 built for x86_64-linux-thread-multi
    > $ time /usr/bin/perl fib.pl
    > fib(35) = 9227465
    > *** user 4.2900, sys 0.0000, real 13.1078
    >
    > real    0m13.126s
    > user    0m4.294s
    > sys     0m0.001s
    > --------------------------------
    >
    > The above output shows that real time is over 13 seconds,
    > but user time is reported only 4.29 seconds.
    > (Of course, there is no other process to consume cpu.)
    > I compled and installed Perl 5.10 from source, but issue is not
    > solved.
    >
    > Environment: FedoraCore 11 (x64), Macbook (Core2Duo 2.0GHz),
    >
    > $ uname -a
    > Linux spica.local 2.6.29.4-167.fc11.x86_64 #1 SMP Wed May 27 17:27:08
    > EDT 2009 x86_64 x86_64 x86_64 GNU/Linux
    >
    > Any suggestion?


    In fact it is strange: on my Fedora machine I cannot reproduce the
    problem:

    $ time perl fib.pl
    fib(35) = 9227465
    *** user 26.2800, sys 0.0600, real 27.3968

    real 0m27.430s
    user 0m26.300s
    sys 0m0.066s

    The only difference is that you are on 64 bit platform (while I'm
    still on a 32 bit one).

    $ uname -a
    Linux matteo.ethz.ch 2.6.30.5-43.fc11.i586 #1 SMP Thu Aug 27 21:18:54
    EDT 2009 i686 i686 i386 GNU/Linux
    $ /usr/bin/perl -v | grep built
    This is perl, v5.10.0 built for i386-linux-thread-multi

    Are you sure that no other processes are running? Did you try it in
    single user mode?

    I can observe the same behavior only with a high machine load (e.g.,
    starting several instances of the process).

    Matteo
     
    Teo, Sep 22, 2009
    #2
    1. Advertising

  3. Thank you, Teo.
    I update FedoreCore11 Kernel and issue seems to be fixed.
    It is kernel problem, not Perl problem. Oh my god.

    --
    regards,
    makoto kuwata

    On 2009-09-22, 10:50pm, Teo <> wrote:
    > Dear Makoto,
    >
    > On Sep 22, 2:50 pm, makoto kuwata <> wrote:
    >
    >
    >
    >
    >
    > > I have a question about times() function.
    > > times() returns user-time, but these values seems to be incorrect.
    > > The following is an example code to show incorrect result:

    >
    > > bench.pl:
    > > ----------------------------------
    > > use strict;
    > > use Time::HiRes;

    >
    > > sub fib {
    > >   my ($n) = @_;
    > >   return $n <= 2 ? 1 : fib($n-2)+fib($n-1);

    >
    > > }

    >
    > > my @start_times = times();
    > > my $start_time  = Time::HiRes::time();

    >
    > > my $n = 35;
    > > print "fib($n) = ", fib($n), "\n";

    >
    > > my @end_times   = times();
    > > my $end_time    = Time::HiRes::time();

    >
    > > my $user_time = $end_times[0] - $start_times[0];
    > > my $sys_time  = $end_times[1] - $start_times[1];
    > > my $real_time = $end_time     - $start_time;

    >
    > > my $format = "*** user %4.4f, sys %4.4f, real %4.4f\n";
    > > printf $format, $user_time, $sys_time, $real_time;
    > > --------------------------------

    >
    > > output example:
    > > --------------------------------
    > > $ /usr/bin/perl -v | grep built
    > > This is perl, v5.10.0 built for x86_64-linux-thread-multi
    > > $ time /usr/bin/perl fib.pl
    > > fib(35) = 9227465
    > > *** user 4.2900, sys 0.0000, real 13.1078

    >
    > > real    0m13.126s
    > > user    0m4.294s
    > > sys     0m0.001s
    > > --------------------------------

    >
    > > The above output shows that real time is over 13 seconds,
    > > but user time is reported only 4.29 seconds.
    > > (Of course, there is no other process to consume cpu.)
    > > I compled and installed Perl 5.10 from source, but issue is not
    > > solved.

    >
    > > Environment: FedoraCore 11 (x64), Macbook (Core2Duo 2.0GHz),

    >
    > > $ uname -a
    > > Linux spica.local 2.6.29.4-167.fc11.x86_64 #1 SMP Wed May 27 17:27:08
    > > EDT 2009 x86_64 x86_64 x86_64 GNU/Linux

    >
    > > Any suggestion?

    >
    > In fact it is strange: on my Fedora machine I cannot reproduce the
    > problem:
    >
    > $ time perl fib.pl
    > fib(35) = 9227465
    > *** user 26.2800, sys 0.0600, real 27.3968
    >
    > real    0m27.430s
    > user    0m26.300s
    > sys     0m0.066s
    >
    > The only difference is that you are on 64 bit platform (while I'm
    > still on a 32 bit one).
    >
    > $ uname -a
    > Linux matteo.ethz.ch 2.6.30.5-43.fc11.i586 #1 SMP Thu Aug 27 21:18:54
    > EDT 2009 i686 i686 i386 GNU/Linux
    > $ /usr/bin/perl -v | grep built
    > This is perl, v5.10.0 built for i386-linux-thread-multi
    >
    > Are you sure that no other processes are running? Did you try it in
    > single user mode?
    >
    > I can observe the same behavior only with a high machine load (e.g.,
    > starting several instances of the process).
    >
    > Matteo
     
    makoto kuwata, Sep 22, 2009
    #3
    1. Advertising

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. =?Utf-8?B?bWF2cmlja18xMDE=?=

    SetAuthCookie works some times and fails some times?

    =?Utf-8?B?bWF2cmlja18xMDE=?=, Mar 23, 2006, in forum: ASP .Net
    Replies:
    0
    Views:
    517
    =?Utf-8?B?bWF2cmlja18xMDE=?=
    Mar 23, 2006
  2. Dale Reed
    Replies:
    3
    Views:
    308
    Lukas Kurka
    Oct 9, 2006
  3. hagar
    Replies:
    1
    Views:
    775
    Tom Forsmo
    Nov 2, 2006
  4. `Zidane Tribal
    Replies:
    1
    Views:
    2,521
    Joe Smith
    Jul 28, 2007
  5. `Zidane Tribal
    Replies:
    3
    Views:
    259
    Sisyphus
    Jul 27, 2007
Loading...

Share This Page