admin管理员组

文章数量:1131142

Have a strange issue where PHP's microtime() sometimes goes back in time when doing http requests. And it's not a "floating point error" either, it can be as much as 0.8 seconds seconds backwards!

I have this reproduce code (PS I'm the owner of the domain and the webserver):

<?php

declare(strict_types=1);
error_reporting(E_ALL);
set_error_handler(function ($errno, $errstr, $errfile, $errline) {
    throw new ErrorException($errstr, 0, $errno, $errfile, $errline);
});
function DoStuff()
{
    $ch = curl_init();
    curl_setopt_array($ch, array(
        CURLOPT_URL => '/',
        CURLOPT_RETURNTRANSFER => true,
    ));
    $data = curl_exec($ch);
    curl_close($ch);
}
$attempts_before_going_backwards = 0;
for (;;) {
    $t1 = microtime(true);
    DoStuff();
    $t2 = microtime(true);
    $t = $t2 - $t1;
    $str = number_format($t, 3, '.', '');
    if (str_contains($str, '-')) {
        var_dump([
            "WTF",
            "attempts_before_going_backwards" => $attempts_before_going_backwards,
            "t" => $t,
            "t_100" => number_format($t, 100, '.', ''),
            "str" => $str,
            "t1" => $t1,
            "t1_100" => number_format($t1, 100, '.', ''),
            "t2" => $t2,
            "t2_100" => number_format($t2, 100, '.', ''),
        ]);
        die();
    }
    ++$attempts_before_going_backwards;
}

And when it runs long enough, eventually something like this happens:

$ time php repro2.php 
array(9) {
  [0]=>
  string(3) "WTF"
  ["attempts_before_going_backwards"]=>
  int(126)
  ["t"]=>
  float(-0.7924120426177979)
  ["t_100"]=>
  string(103) "-0.7924120426177978515625000000000000000000000000000000000000000000000000000000000000000000000000000000"
  ["str"]=>
  string(6) "-0.792"
  ["t1"]=>
  float(1736293804.892522)
  ["t1_100"]=>
  string(111) "1736293804.8925220966339111328125000000000000000000000000000000000000000000000000000000000000000000000000000000"
  ["t2"]=>
  float(1736293804.10011)
  ["t2_100"]=>
  string(111) "1736293804.1001100540161132812500000000000000000000000000000000000000000000000000000000000000000000000000000000"
}

real    0m29.164s
user    0m0.025s
sys 0m0.041s

In this example, microtime() somehow went 0.792 seconds back in time after 126 attempts.

How is that possible?

Environment:

  • OS: Ubuntu24.04 on WSL2 on Windows 10 x64 22H2
  • CPU: AMD Ryzen 9 7950X
  • PHP version: 8.3.6 NTS

Btw seems someone observed similar behavior on NetBSD in 2002: .html

Have a strange issue where PHP's microtime() sometimes goes back in time when doing http requests. And it's not a "floating point error" either, it can be as much as 0.8 seconds seconds backwards!

I have this reproduce code (PS I'm the owner of the domain and the webserver):

<?php

declare(strict_types=1);
error_reporting(E_ALL);
set_error_handler(function ($errno, $errstr, $errfile, $errline) {
    throw new ErrorException($errstr, 0, $errno, $errfile, $errline);
});
function DoStuff()
{
    $ch = curl_init();
    curl_setopt_array($ch, array(
        CURLOPT_URL => 'http://x2.ratma.net/',
        CURLOPT_RETURNTRANSFER => true,
    ));
    $data = curl_exec($ch);
    curl_close($ch);
}
$attempts_before_going_backwards = 0;
for (;;) {
    $t1 = microtime(true);
    DoStuff();
    $t2 = microtime(true);
    $t = $t2 - $t1;
    $str = number_format($t, 3, '.', '');
    if (str_contains($str, '-')) {
        var_dump([
            "WTF",
            "attempts_before_going_backwards" => $attempts_before_going_backwards,
            "t" => $t,
            "t_100" => number_format($t, 100, '.', ''),
            "str" => $str,
            "t1" => $t1,
            "t1_100" => number_format($t1, 100, '.', ''),
            "t2" => $t2,
            "t2_100" => number_format($t2, 100, '.', ''),
        ]);
        die();
    }
    ++$attempts_before_going_backwards;
}

And when it runs long enough, eventually something like this happens:

$ time php repro2.php 
array(9) {
  [0]=>
  string(3) "WTF"
  ["attempts_before_going_backwards"]=>
  int(126)
  ["t"]=>
  float(-0.7924120426177979)
  ["t_100"]=>
  string(103) "-0.7924120426177978515625000000000000000000000000000000000000000000000000000000000000000000000000000000"
  ["str"]=>
  string(6) "-0.792"
  ["t1"]=>
  float(1736293804.892522)
  ["t1_100"]=>
  string(111) "1736293804.8925220966339111328125000000000000000000000000000000000000000000000000000000000000000000000000000000"
  ["t2"]=>
  float(1736293804.10011)
  ["t2_100"]=>
  string(111) "1736293804.1001100540161132812500000000000000000000000000000000000000000000000000000000000000000000000000000000"
}

real    0m29.164s
user    0m0.025s
sys 0m0.041s

In this example, microtime() somehow went 0.792 seconds back in time after 126 attempts.

How is that possible?

Environment:

  • OS: Ubuntu24.04 on WSL2 on Windows 10 x64 22H2
  • CPU: AMD Ryzen 9 7950X
  • PHP version: 8.3.6 NTS

Btw seems someone observed similar behavior on NetBSD in 2002: https://mail-index.netbsd.org/port-i386/2002/07/31/0002.html

Share Improve this question edited Jan 8 at 0:10 Marcin Orlowski 75.6k11 gold badges127 silver badges152 bronze badges asked Jan 7 at 23:58 hanshenrikhanshenrik 21.4k4 gold badges56 silver badges103 bronze badges 2
  • 1 my best guess is that the WSL2 hypervisor is to blame, but i have no idea why/how – hanshenrik Commented Jan 8 at 0:01
  • 2 root cause of your negative time deltas is clock adjustments (likely via WSL2’s synchronization with the Windows host or TSC drift) making the system clock step back in time. stackoverflow.com/questions/39151049/… – talha2k Commented Jan 8 at 0:05
Add a comment  | 

1 Answer 1

Reset to default 2

microtime reports the system time. The system time is subject to change at any time, either explicitly by an administrator or automatically for clock synchronization (with an NTP server, for instance, or for leap second adjustments). You can therefore never rely on the system clock to measure durations -- at least not at low resolution.

Instead, use a monotonic clock. In PHP, one is provided by hrtime.

$t1 = hrtime(true);
DoStuff();
$t2 = hrtime(true);

$deltaNanos = $t2 - $t1;
$deltaSeconds = $deltaNanos / 1e9;

本文标签: unix timestampWhy does PHP39s microtime() sometimes go backwardsStack Overflow