php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #54050 microtime() returns random values
Submitted: 2011-02-18 22:17 UTC Modified: 2013-03-12 07:57 UTC
Votes:2
Avg. Score:4.5 ± 0.5
Reproduced:2 of 2 (100.0%)
Same Version:1 (50.0%)
Same OS:2 (100.0%)
From: nospam at unclassified dot de Assigned:
Status: Duplicate Package: *General Issues
PHP Version: Irrelevant OS: Windows XP
Private report: No CVE-ID: None
Welcome back! If you're the original bug submitter, here's where you can edit the bug or add additional notes.
If you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: nospam at unclassified dot de
New email:
PHP Version: OS:

 

 [2011-02-18 22:17 UTC] nospam at unclassified dot de
Description:
------------
I have a very weird bug here. The microtime() function with the parameter true works fine everywhere in my entire application - except in one single place. It's measuring database query durations here. It counts everything perfectly but always at a certain database query in the deepest middle of my application it returns random values. When I call it a second time just a line of code later, it returns the correct value again. It happens every time tonight. I cannot provide a testcase yet because there's another tens of thousands of lines of code hanging at this to work at all.

I cannot upgrade PHP because there's no newer XAMPP package available. Version is 5.3.1.


Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2011-02-18 22:32 UTC] nospam at unclassified dot de
I have restarted the Apache web server and then the microtime function worked correctly in this situation a few times. Then it started to produce the same bogus data often. Now the original problem is right here again. Same place. Only the approximately 100th of like 200 times it is called. Instead of 1298064639.9228 (or similar) as everywhere else on the page it returns values around 1296908080.167 or 1296908081.2987. Quite a bit off but relatively "constant".
 [2011-02-18 23:31 UTC] nospam at unclassified dot de
The seconds part of the return value seems to be my system boot time. I have now restarted the computer and the value points to that time. The fractional part is kind of oscillating around similar values. It's going up and down a bit every time but it has the tendency to decrease slowly. I have discovered a few other places in my application where it happens. But it's always the same database function. The same code.

$start0 = microtime(true);
$start = microtime(true);
if (abs($start - $start0) > 1)
{
	var_dump($start0);
	var_dump($start);
}

This should never print something but it does. Here are a few examples:

float(1298065510.0493) float(1298068208.1106)
float(1298065510.0533) float(1298068218.7475)
float(1298065510.0405) float(1298068225.1549)
float(1298065510.038) float(1298068231.7615)
float(1298065510.0269) float(1298068237.0667)
float(1298065510.0234) float(1298068244.8534)
float(1298065510.0266) float(1298068250.9826)
float(1298065510.0145) float(1298068257.6404)
float(1298065510.8087) float(1298068265.3026)
float(1298065510.809) float(1298068271.1601)
float(1298065510.8087) float(1298068277.0327)
float(1298065510.8029) float(1298068284.6319)
...
 [2011-06-09 13:51 UTC] ynn at free dot fr
There is a simpler test case :

for ($i=0 ; $i<=100000 ; $i++)
{
   $mt = microtime(true);
   if(isset($last) && $mt<$last)
       echo 'Last:'.$last.' - Current:'.$mt."\n";
   $last = $mt;
}


On Windows XP, PHP 5.3.5, I get outputs that looks like :

Last:1307620010.9549 - Current:1307620010.0533
Last:1307620010.9742 - Current:1307620010.0689
Last:1307620010.9742 - Current:1307620010.0689
Last:1307620010.983 - Current:1307620010.0845
Last:1307620010.9909 - Current:1307620010.0845
Last:1307620011.0142 - Current:1307620010.1158
Last:1307620011.0612 - Current:1307620010.147
Last:1307620011.0679 - Current:1307620010.1626
Last:1307620011.0865 - Current:1307620010.1783
Last:1307620011.115 - Current:1307620010.2095
 [2013-03-11 20:56 UTC] sixd@php.net
-Status: Open +Status: Duplicate
 [2013-03-11 20:56 UTC] sixd@php.net
Duplicate of bug #64370
 [2013-03-12 07:57 UTC] nospam at unclassified dot de
Wow, that was fast. Why was the other bug picked up to quickly? Where this thing is around for years and doing unimaginable damage...

Could somebody with sufficient access please tell the other bug that this is NOT limited to PHP 5.5 (as he emphasised many times) but also happened much earlier?
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Thu Nov 21 17:01:32 2024 UTC