Why are these timestamps out of order with Perl Time::HiRes?

Question

I'm seeing some strange behaviour with the timestamp reported by Perl's Time::HiRes module.

I have a script that gets three timestamps:

1. Get timestamp with Time::HiRes::time
2. Create a new file, and get its modification time with Time::HiRes::stat
3. Get timestamp with Time::HiRes::time

I'd expect the timestamps to be ordered1 < 2 < 3, however this isn't always the case; often (but not always), the time reported by stat in 2. is before the timestamp from 1..

I'm on an Ext4 filesystem. Here's an experiment:

use Time::HiRes qw/ time stat /;

while( 1 ){
    # t0
    my $t0 = time;

    # Create a file
    my $f = '/tmp/dummy.test';
    open(my $fh, '>', $f) || die;
    print $fh "hi\n";
    close($fh) || die;

    # FS: file modification time, according to the filestystem
    my $fs = (stat($f))[9];

    # t1
    my $t1 = time;

    ## Report how the timestamps relate to each other
    # A. All good
    if( $t0 < $fs && $fs < $t1 ){
       print "$t1,0\n";
    }
    # B. FS before t0
    elsif( $t0 > $fs && $fs < $t1 ){
       print "$t1,1\n";
    }
    # C. FS after t1
    elsif( $t0 < $fs && $fs > $t1 ){
       print "$t1,2\n";
    }
    # D. this should never happen (t0 and t1 probably can't flip)
    elsif( $t0 > $fs && $fs > $t1 ){
       print "$t1,3\n";
    }
}

Here are the results of letting the above loop run for a few seconds. where the blue points on the bottom are incidents of the "correct" behaviour. More often than not, I get condition B, where the modification time from stat is before the first timestamp.

What could explain this behaviour?

Update: Here's a plot of the timestamp lags for the fist 2000 iterations:

Answer 1

This might be because of a difference in the precision of both timestamps as mentioned in the doc here:

As stat or lstat but with the access/modify/change file timestamps in subsecond resolution, if the operating system and the filesystem both support such timestamps. To override the standard stat():

use Time::HiRes qw(stat);

Test for the value of &Time::HiRes::d_hires_stat to find out whether the operating system supports subsecond file timestamps: a value larger than zero means yes. There are unfortunately no easy ways to find out whether the filesystem supports such timestamps. UNIX filesystems often do; NTFS does; FAT doesn't (FAT timestamp granularity is two seconds).

A zero return value of &Time::HiRes::d_hires_stat means that Time::HiRes::stat is a no-op passthrough for CORE::stat() (and likewise for lstat), and therefore the timestamps will stay integers. The same thing will happen if the filesystem does not do subsecond timestamps, even if the &Time::HiRes::d_hires_stat is non-zero.

In any case do not expect nanosecond resolution, or even a microsecond resolution. Also note that the modify/access timestamps might have different resolutions, and that they need not be synchronized, e.g. if the operations are

write
stat # t1
read
stat # t2

the access time stamp from t2 need not be greater-than the modify time stamp from t1: it may be equal or less.