Sunday, April 27, 2014

PHP Date vs. gettimeofday

I just had a lot of trouble with a unit test failing. Unfortunately lots of things had changed: new computer, new linux distro, new version of PHP (from 5.3 to 5.5), new version of PHPUnit (from 3.4 all the way to 4.0 then back to 3.7), etc.

I eventually tracked it down; and made this minimal example:

        $t = time();
        $s = date("Y-m-d H:i:s");
        $tod = gettimeofday();
        echo "$t,$s,{$tod['sec']},{$tod['usec']},".
          date("Y-m-d H:i:s")."\n";
    usleep(10000);  //0.01s

It is getting the time 100 times a second, and comparing with time(), date() and gettimeofday(). I’ll just show the interesting bit:

1398601641,2014-04-27 21:27:21,1398601641,972424,2014-04-27 21:27:21
1398601641,2014-04-27 21:27:21,1398601641,982545,2014-04-27 21:27:21
1398601641,2014-04-27 21:27:21,1398601641,992669,2014-04-27 21:27:21
1398601641,2014-04-27 21:27:21,**1398601642**,2793,2014-04-27 21:27:21
1398601642,2014-04-27 21:27:22,1398601642,12919,2014-04-27 21:27:22
1398601642,2014-04-27 21:27:22,1398601642,23041,2014-04-27 21:27:22

I’ve highlighted the problem point. It appears gettimeofday() is slightly ahead of time() (and date() is always consistent with time()). More precisely, for the first 10000 microseconds of each second, time() is still in the previous second.

My unit test was watching gettimeofday() to wait for a new second to roll by. But the code being tested was using date to get a timestamp. (That timestamp was then used as a unique ID for a database insert, and the unit test asserted it was always an insert, not an update!)

Fascinating stuff, eh? I’ve no idea if this is a behaviour change in PHP, or if this new machine is simply a bit quicker, and the problem never cropped up before. However I doubt the latter as the unit test now fails 100% of the time, but never failed this way before.

Oh, the fix? Simply changed the calls to gettimeofday() to time(). To be honest I’ve no idea why I used the more complicated function in the first place.

No comments: