I'm having a problem with Time::HiRes, specifically the gettimeofday function. Below I've given a code sample and instruction on how to duplicate the problem. It will only take a few seconds to confirm/refute the problem, if you have the time. Please and thank you in advance.

Context: The purpose of this code is simply to prepend a timestamp (with ~microsecond accuracy) to any lines, entries, stdout, whatever you'd care to feed the script.

#!/usr/bin/perl
#timestamp.pl
###
use Time::HiRes qw(gettimeofday);
$|=1;

while (<>) {
        $timestamp = sprintf("%d.%06d", gettimeofday());
        print "$timestamp $_";
        }
exit;


---
touch testfile
tail -f testfile | timestamp.pl

_in another window_
echo 'test' >> testfile
(wait a while)
echo 'test' >> testfile
(wait a few seconds)
echo 'test' >> testfile
(wait a little while)
echo 'test' >> testfile

[download]
Observe the microsecond value on the output (it will be something like this, not exactly): 
1265405350.420517 test
1265405354.420852 test
1265405356.421037 test
1265405362.421530 test

[download]

The microsecond value from 'gettimeofday()' increments by a small amount each time a new line is added, and entirely inaccurately. As you add more output to the file, you'll see that the microsecond value increments for every entry, but entirely not what it should be.

Now contrast this output with the behavior when you simply press enter a few times if you run the script by itself:

:~/bin/timestamp.pl

1265405711.519744

1265405711.784186

1265405711.939817

1265405712.144596

1265405712.355313

1265405712.648788

[download]

Which is working as expected. The values increment, but not predictably, and certainly not by very small values as observed above.


Tested & verified this behavior on:
perl, v5.10.0 built for i486-linux-gnu-thread-multi
perl, v5.8.8 built for i486-linux-gnu-thread-multi
perl, v5.8.4 built for sun4-solaris-64int

Any thoughts would be greatly appreciated. What is causing this strange behavior when piping the output from a tail -f into the script?


thanks
/gr

In reply to Time::HiRes strange behavior by golden.radish

Title:
Use:  <p> text here (a paragraph) </p>
and:  <code> code here </code>
to format your post, it's "PerlMonks-approved HTML":


  • Posts are HTML formatted. Put <p> </p> tags around your paragraphs. Put <code> </code> tags around your code and data!
  • Titles consisting of a single word are discouraged, and in most cases are disallowed outright.
  • Read Where should I post X? if you're not absolutely sure you're posting in the right place.
  • Please read these before you post! —
  • Posts may use any of the Perl Monks Approved HTML tags:
    a, abbr, b, big, blockquote, br, caption, center, col, colgroup, dd, del, details, div, dl, dt, em, font, h1, h2, h3, h4, h5, h6, hr, i, ins, li, ol, p, pre, readmore, small, span, spoiler, strike, strong, sub, summary, sup, table, tbody, td, tfoot, th, thead, tr, tt, u, ul, wbr
  • You may need to use entities for some characters, as follows. (Exception: Within code tags, you can put the characters literally.)
            For:     Use:
    & &amp;
    < &lt;
    > &gt;
    [ &#91;
    ] &#93;
  • Link using PerlMonks shortcuts! What shortcuts can I use for linking?
  • See Writeup Formatting Tips and other pages linked from there for more info.