1

I'm experiencing very odd behaviour from Time::HiRes on RHEL5. Since Time::HiRes is in the Perl standard installation, and is basically a wrapper around the gettimeofday system call, I'm inclined to point the finger at the OS rather than the module, or even perl.

Here's my sample code:

#!/usr/bin/perl

use Time::HiRes;
use LWP::Simple;

for (1..10) {

    my $started = [Time::HiRes::gettimeofday];

    # do something that we can expect to take time, but not too much time
    my $throwaway = get("http://localhost/");

    my $elapsed = Time::HiRes::tv_interval($started);

    print "$elapsed\n";

    sleep(1);

}

Running this on my Mac provides the entirely-sane results:

0.025934
0.000642
0.000716
0.001003
0.001026
0.000733
0.000815
0.000646
0.000629
0.000793

But running on my RHEL5 server yields the not-at-all-sane:

0.034182
0.015998
0.06415
0.015523
-0.000379
0
0
0
0
0

Note in particular the fifth result!

Just in case, here's the results of perl -V on the server:

Summary of my perl5 (revision 5 version 8 subversion 8) configuration:
  Platform:
    osname=linux, osvers=2.6.18-92.1.6.el5, archname=i686-linux
    uname='linux 188186.sexton.article7.co.uk 2.6.18-92.1.6.el5 #1 smp fri jun 20 02:36:16 edt 2008 i686 athlon i386 gnulinux '
    config_args='-des -Dprefix=/usr/local'
    hint=previous, useposix=true, d_sigaction=define
    usethreads=undef use5005threads=undef useithreads=undef usemultiplicity=undef
    useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
    use64bitint=undef use64bitall=undef uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='cc', ccflags ='-fno-strict-aliasing -pipe -Wdeclaration-after-statement -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64',
    optimize='-O2',
    cppflags='-fno-strict-aliasing -pipe -Wdeclaration-after-statement -I/usr/local/include -fno-strict-aliasing -pipe -Wdeclaration-after-statement -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64'
    ccversion='', gccversion='4.1.2 20071124 (Red Hat 4.1.2-42)', gccosandvers=''
    intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
    ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
    alignbytes=4, prototype=define
  Linker and Libraries:
    ld='cc', ldflags =' -L/usr/local/lib'
    libpth=/usr/local/lib /lib /usr/lib
    libs=-lnsl -ldl -lm -lcrypt -lutil -lc
    perllibs=-lnsl -ldl -lm -lcrypt -lutil -lc
    libc=/lib/libc-2.5.so, so=so, useshrplib=false, libperl=libperl.a
    gnulibc_version='2.5'
  Dynamic Linking:
    dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E'
    cccdlflags='-fpic', lddlflags='-shared -L/usr/local/lib'


Characteristics of this binary (from libperl): 
  Compile-time options: PERL_MALLOC_WRAP USE_LARGE_FILES USE_PERLIO
  Built under linux
  Compiled at Sep 15 2008 15:05:12
  @INC:
    /usr/local/perl/5.8.8/lib/5.8.8/i686-linux
    /usr/local/perl/5.8.8/lib/5.8.8
    /usr/local/perl/5.8.8/lib/site_perl/5.8.8/i686-linux
    /usr/local/perl/5.8.8/lib/site_perl/5.8.8
    /usr/local/perl/5.8.8/lib/site_perl
    .

Is this a known problem? Any ideas very gratefully accepted.

shedside
  • 11
  • 1

2 Answers2

0

Have a look at

https://stackoverflow.com/questions/656537/is-there-a-better-way-to-determine-elapsed-time-in-perl

The last comment implies its not just you with this problem

0

Can't you just be happy with the fact that your system is so fast it's returning results in negative time? :) All kidding aside, we had weird clock drift issues with RHEL5 in virtualized environments; might that relate to your issue?

Jeff Albert
  • 1,987
  • 9
  • 14