php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #64633 microtime regression - resolution reduced to 64 ticks per second
Submitted: 2013-04-11 16:52 UTC Modified: 2014-01-10 08:24 UTC
Votes:15
Avg. Score:4.7 ± 0.7
Reproduced:8 of 8 (100.0%)
Same Version:6 (75.0%)
Same OS:7 (87.5%)
From: phpbugs at musiclogistics dot net Assigned: pajoye
Status: Assigned Package: Date/time related
PHP Version: 5.4.14 OS: Windows 7
Private report: No CVE-ID:
Have you experienced this issue?
Rate the importance of this bug to you:

 [2013-04-11 16:52 UTC] phpbugs at musiclogistics dot net
Description:
------------
Probably caused by recent patch for bug #64370:

Since v 5.4.14 microtime() only moves forward in 15,6 ms (1/64 sec) increments on Win7. Same for CLI and Apache 2.2 SAPI.

Build: VC9 x86 Thread Safe (2013-Apr-10 22:55:28) from windows.php.net.

Behaviour normal after downgrade to 5.4.13.

This also breaks usleep() (only sleeping for multiples of 15,6 ms now) and uniqid() (returning the same value for 15,6 ms with $more_entropy = false).

Test script:
---------------
for ($startTimeMs = currentTimeMs(), $i = 0; $i < 10000; $i++) {
	//usleep(1);
	echo (currentTimeMs() - $startTimeMs) . ' ';
}

function currentTimeMs() {
	return round(microtime(true) * 1000000);
}

Expected result:
----------------
[what PHP 5.4.13 prints on the same machine:]

13 28 35 41 48 54 61 67 74 80 86 92 99 105 112 118 124 131 137 143 149 155 162 168 174 181 187 193 200 206 212 218 224 [...and so on]


Actual result:
--------------
0 0 0 0 0 0 0 0 0 [many more zeroes] 15600 15600 15600 15600 [...] 31200 31200 31200 31200 31200 [...] 46800 46800 46800 46800 46800 [...and so on]

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2013-04-12 11:25 UTC] ab@php.net
-Status: Open +Status: Verified
 [2013-04-12 11:25 UTC] ab@php.net
This is a tradeoff one has to make, precision vs. accuracy. That's very depending on the hardware. While on one system using the performance timer it would work as expected, on another it's still more accurate time with a very variable precision. That's where you could see in your snippet currentTimeMs() - $startTimeMs < 0. That is much more weird than possibly having a worse resolution, say currentTimeMs() - $startTimeMs == 0.

Heres' an interesting reading about this http://blogs.msdn.com/b/oldnewthing/archive/2005/09/02/459952.aspx . The goal of the latest fix is to remove the random results. Also this will work in most cases as normally a script doesn't consist on just two subsequent microtime calls. Starting with win8 there is a much better API, but it of course doesn't help here. I'm not sure it should be touched, will look how to improve it without getting to the old erroneous behaviour. Maybe reimplement the performance timer part and make an ini option to let user decide if the performance timer should be used. As we really cannot foresee every hardware bugs.

Btw. usleep() isn't affected by that, it uses the waitable timer which has a better resolution.
 [2013-04-12 11:29 UTC] pajoye@php.net
-Status: Verified +Status: Assigned -Assigned To: +Assigned To: pajoye
 [2013-04-12 11:29 UTC] pajoye@php.net
We should use performance counters instead, which brings a much higher precision 
at less cost.
 [2013-04-12 14:22 UTC] phpbugs at musiclogistics dot net
@ab@php.net: You are right: While usleep() only works in 1/64 second increments on my machine (640 loops of "usleep(1)" take about 10 seconds), this is not related to PHP 5.4.14. It's the same on 5.4.13 and probably a limitation of Windows' multitasking.
 [2013-06-16 04:02 UTC] yaro at opti dot su
The same problem occurs in PHP 5.4.15 too!
Why developers ignore such an important issue?
 [2013-07-31 07:19 UTC] martin dot hason at gmail dot com
The same problem occurs in PHP 5.5.1 too! Please fix this bug.
 [2013-08-01 05:04 UTC] yaro2000 at yandex dot ru
5.4.09 - OK, 5.4.10 - OK ... 5.4.14 - BUG, 5.4.15 - BUG
Why?
 [2013-08-01 05:43 UTC] yohgaki@php.net
Just a note.
Linux does not have problem at all, it seems.

http://3v4l.org/nMBha
 [2013-08-01 06:07 UTC] yohgaki@php.net
I guess this commit is the cause.

git show  b022e54bd100a914417e216
commit b022e54bd100a914417e216d0872d3e67edecaf9
Author: Anatol Belski <ab@php.net>
Date:   Sat Mar 23 17:40:06 2013 +0100

    Fixed possible precision loss in microtime
    
    This is related to the fix for bug #64370. MSVC natively supports __int64 
type,
    so calculating with 32 bit ints is neither necessary nor reliable. Therefore
    an older piece of code is reused.

diff --git a/win32/time.c b/win32/time.c
index 77e4504..7553974 100644
--- a/win32/time.c
+++ b/win32/time.c
@@ -50,6 +50,7 @@ int getfilesystemtime(struct timeval *tv)
        FILETIME ft;
        unsigned __int64 ff = 0;
        MyGetSystemTimeAsFileTime timefunc;
+       ULARGE_INTEGER fft;
 
        timefunc = get_time_func();
        if (timefunc) {
@@ -58,14 +59,20 @@ int getfilesystemtime(struct timeval *tv)
                GetSystemTimeAsFileTime(&ft);
        }
 
-       ff |= ft.dwHighDateTime;
-       ff <<= 32;
-       ff |= ft.dwLowDateTime;
-       ff /= 10; /* convert to microseconds */
+        /*
+        * Do not cast a pointer to a FILETIME structure to either a 
+        * ULARGE_INTEGER* or __int64* value because it can cause alignment 
faults on 64-bit Windows.
+        * via  http://technet.microsoft.com/en-
us/library/ms724284(v=vs.85).aspx
+        */
+       fft.HighPart = ft.dwHighDateTime;
+       fft.LowPart = ft.dwLowDateTime;
+       ff = fft.QuadPart;
+
+       ff /= 10Ui64; /* convert to microseconds */
        ff -= 11644473600000000Ui64; /* convert to unix epoch */
 
-       tv->tv_sec = (long)(ff / 1000000UL);
-       tv->tv_usec = (long)(ff % 1000000UL);
+       tv->tv_sec = (long)(ff / 1000000Ui64);
+       tv->tv_usec = (long)(ff % 1000000Ui64);
 
        return 0;
 }
 [2013-08-01 06:53 UTC] yohgaki@php.net
Anyone could verify that this wouldn't happen with Windows 8/Windows Server 2012?
It seems different API is used for these platforms.
 [2014-01-08 14:13 UTC] louis at stovesonline dot co dot uk
Having the same issue with 5.5.7 on Windows Server 2008 R2.

Interestingly starting Google Chrome on the server increases the tick rate for a few seconds, meaning I can briefly get accurate results from my timing functions!
 [2014-01-10 08:24 UTC] ab@php.net
@louis, that's exactly what i'm talking about - with the current variant one would never get time1 > time2, i bet with the old variant using performance counters it could easy happen in your situation. Running chrome seems to be a catalyser for some instability in your case. In the current implementation time1 = time2 is the worst case, earlier it could be casual time1 > time2, or not. Now it's never time1 > time2, but with the trade off.

@yohgaki, i don't think the patch you've posted is responsible, but merely the exclusion of the performance counters. On win8 one can profit from the new API call GetSystemTimePreciseAsFileTime(), which is comparable to Linux. On earlier it's GetSystemTimeAsFileTime(). The latter has poorer accuracy, but is stable and will never deliver time1 > time2. That's the trade off, as i've said above. Earlier performance counters was used instead of GetSystemTimeAsFileTime(), which led to even more confusing bugs, as in the bug #64370 and related. Turning back the old code will turn back time1 > time2 on win8 ancestors, as it's hardware+API dependent and is more random than now.
 
PHP Copyright © 2001-2014 The PHP Group
All rights reserved.
Last updated: Fri Apr 18 05:03:21 2014 UTC