SitePoint Sponsor

User Tag List

Page 1 of 2 12 LastLast
Results 1 to 25 of 37
  1. #1
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)

    How to measure time with microsecond precision on a 32-bit system?

    I have a simple way to measure the execution time of some php code, it's simply getting the values of microtime(float) and subtracting one from the other. For example:
    PHP Code:
    $st microtime(true);

    for (
    $i=0$i<10000$i++) {
        
    $a $i;
    }

    $dur microtime(true) - $st;
    echo 
    $dur
    However, on a 32-bit Windows system the result is very inaccurate and every time I run this script I get either 0.015625 or 0, nothing in between. I suppose this is due to floats having little precision on 32-bit systems. On a 64-bit Linux production server I get values like 0.0025119781494141.

    How do I measure duration accurately? I'm trying to find a simplest solution, so far the best I can think of is use microtime() without true, split and concatenate the string and use bc functions for calculation. Are there any better ways?

  2. #2
    Programming Team silver trophybronze trophy
    Mittineague's Avatar
    Join Date
    Jul 2005
    Location
    West Springfield, Massachusetts
    Posts
    17,138
    Mentioned
    190 Post(s)
    Tagged
    2 Thread(s)
    Is this for RYO benchmarking? If so there may be a package out there that has everything already figured out.
    eg. (old) http://pear.php.net/package/Benchmark

  3. #3
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Mittineague View Post
    Is this for RYO benchmarking? If so there may be a package out there that has everything already figured out.
    eg. (old) http://pear.php.net/package/Benchmark
    An external PEAR library is too much for my needs, occasionally I just want to inject 2-3 lines of simple code to benchmark a piece of code without any external dependencies. But I looked at the source of this package and it uses the same method of counting time as I was contemplating earlier - textual microtime() result + bcsub() to calculate the difference. So I tried this method in my code:

    PHP Code:
    function countDuration($start$end) {
        
    $segm explode(' '$start);
        
    $timeStart $segm[1] . substr($segm[0], 1);
        
        
    $segm explode(' '$end);
        
    $timeEnd $segm[1] . substr($segm[0], 1);
        
        return 
    bcsub($timeEnd$timeStart6);
    }


    $start microtime();

    for (
    $i=0$i<10000$i++) {
        
    $a $i;
    }

    $dur countDuration($startmicrotime());
    echo 
    $dur
    And guess what? The same problem persists on the 32-bit Windows system - I get either 0.015625 or 0. I'm inclined to think that floats are not the problem but more likely microtime() is reporting time with very small precision in the first place. What can I do then?

  4. #4
    SitePoint Mentor silver trophy
    Rubble's Avatar
    Join Date
    Dec 2005
    Location
    Cambridge, England
    Posts
    2,392
    Mentioned
    81 Post(s)
    Tagged
    3 Thread(s)
    I have had a look back and I did some speed test a few years ago using XAMPP on probably a 32 bit XP setup - I do not think I had vista at that time but if it was it would also have been 32bit and the results were:
    1st run
    0.299100001653 average time
    2nd run
    0.298720002174 average time
    3rd run
    0.298156666756 average time
    4th run
    0.298293328285 average time
    5th run
    0.298613333702 average time

    Which are not " 0.015625 or 0"

    I can not try it now as I am using 64bit Windows 7.

    I have had a look back and the code I used was:
    PHP Code:
    for ( $i=0$i<=9$i++ ){

          
    $mtime microtime(); 
          
    $mtime explode(' '$mtime); 
          
    $mtime $mtime[1] + $mtime[0]; 
          
    $starttime $mtime

    exec("convert $image -resize 100x100 command.jpg");

     
    $mtime microtime(); 
          
    $mtime explode(" "$mtime); 
          
    $mtime $mtime[1] + $mtime[0]; 
          
    $endtime $mtime
          
    $totaltime = ($endtime $starttime); 

    // Record the time
     
    write_results$save"$totaltime\r\n" );
     
     }; 
    Last edited by Rubble; Jan 6, 2014 at 14:55. Reason: Altered the php code as I found the original code

  5. #5
    Programming Team silver trophybronze trophy
    Mittineague's Avatar
    Join Date
    Jul 2005
    Location
    West Springfield, Massachusetts
    Posts
    17,138
    Mentioned
    190 Post(s)
    Tagged
    2 Thread(s)
    I've never worried much about such small amounts of time and so never looked much into it.
    Interesting stuff.

    It does indeed seem to be related to how time is handled. eg. this on NTP (Network Time Protocol) http://php.net/microtime
    All these timing scripts rely on microtime which relies on gettimebyday(2)

    This can be inaccurate on servers that run ntp to syncronise the servers
    time.
    And there's SNTP (Simple NTP), And Windows uses it's own version http://en.wikipedia.org/wiki/Network_Time_Protocol
    Windows Time service

    All Microsoft Windows versions since Windows 2000 and Windows XP include the Windows Time service ("W32Time"),[13] which has the ability to sync the computer clock to an NTP server. The version in Windows 2000 and Windows XP only implements Simple NTP, and violates several aspects of the NTP version 3 standard.[14] Beginning with Windows Server 2003 and Windows Vista, a compliant implementation of full NTP is included.[
    EDIT
    When I did some code with microtime() a couples back there was more processing involved between "start" and "end".
    Rubble's "exec" would also be more resource hungry than a simple for loop.

    Maybe there's no way to test "fast" code accurately?

  6. #6
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Rubble, your case is different because you are measuring image manipulation which takes almost 1/3 of a second so it's obvious you wouldn't get 0.015625 or 0 because your conversion lasts many times longer than either of these values. I'm measuring a for loop that gets executed much quicker and it looks like the duration is around the borderline of microtime accuracy.

    Anyway, I've found this bug: Bug #64633 :: microtime regression - resolution reduced to 64 ticks per second. Due to some changes in PHP code the accuracy of microtime was reduced to 1/64 of a second, which is exactly 0.015625. So it looks like there's no way around it on Windows systems, at least on Windows 7. They don't mention anything about 32 vs 64-bit versions so I'm not sure if this makes any difference. They also mention there are different API calls on Windows 8 but it's also uncertain if the problem is resolved on Win 8.

  7. #7
    Programming Team silver trophybronze trophy
    Mittineague's Avatar
    Join Date
    Jul 2005
    Location
    West Springfield, Massachusetts
    Posts
    17,138
    Mentioned
    190 Post(s)
    Tagged
    2 Thread(s)
    Good find. Seems 0.015 isn't very precise for something one would think was. For "humans" not noticeable, but for processors it sure is.
    What is misleading is why offer float precision when the data it's working with isn't precise. Gads!

  8. #8
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Mittineague View Post
    Maybe there's no way to test "fast" code accurately?
    It seems true on Windows systems. Being able to time such small amounts of time is not critical but sometimes it's useful - for example, you can take some piece of code outside of a large loop and benchmark it without any loss of precision.

    But this limitation has its side effects - for example, uniqid() suffers from the same lack of accuracy if not used with the more entropy option - and on my system I was able to get 313 same uniqid() values in a loop!

    Anyway, I doubt it's impossible to get accurate microsecond time on Windows - I'm sure any OS needs way more accuracy than 1/64s. for its proper functioning! How many internal commands can be executed within 1/64s.? I suppose quite a lot on modern machines...

  9. #9
    Hosting Team Leader silver trophybronze trophy
    cpradio's Avatar
    Join Date
    Jun 2002
    Location
    Ohio
    Posts
    5,112
    Mentioned
    152 Post(s)
    Tagged
    0 Thread(s)
    Couldn't you use xDebug to profile your code? Create a very simple test.php that does what you want, profile it and look at the call hierarchy/stack?

  10. #10
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by cpradio View Post
    Couldn't you use xDebug to profile your code? Create a very simple test.php that does what you want, profile it and look at the call hierarchy/stack?
    I suppose that is an option but here I wanted a most simple method without any dependencies on xDebug and other extensions and I wanted this to be portable across different remote installations where often I don't have xDebug.

    Apart from that, doesn't xDebug skew the results, I mean if you turn profiling on then some additional execution must get in the way of normal script flow to take the measurements. I once had a problem of some piece of php code running slow because xDebug extension was enabled (unfortunately, I don't remember what this was about).

  11. #11
    Hosting Team Leader silver trophybronze trophy
    cpradio's Avatar
    Join Date
    Jun 2002
    Location
    Ohio
    Posts
    5,112
    Mentioned
    152 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Lemon Juice View Post
    I suppose that is an option but here I wanted a most simple method without any dependencies on xDebug and other extensions and I wanted this to be portable across different remote installations where often I don't have xDebug.
    That's fair enough. And a very good reason to rule it out.

    Quote Originally Posted by Lemon Juice View Post
    Apart from that, doesn't xDebug skew the results, I mean if you turn profiling on then some additional execution must get in the way of normal script flow to take the measurements. I once had a problem of some piece of php code running slow because xDebug extension was enabled (unfortunately, I don't remember what this was about).
    It shouldn't really skew the results, as the injection it does, should be before and after, not during the execution. You would likely see a decrease in your execution from a end-user standpoint because it is collecting the additional data (if you were to leave it enabled). That is why I use extensions that enable me to quickly turn it on or off, so I'm not impacted by it unless I know I want it. Nonetheless, it shouldn't affect the actual time it takes to execute the code block (but again, I'll usually run the same code block a few times -- 10 for example, and take the average; after removing the first and last execution).

    As for the problem at hand. I now wish I had a 32 bit machine to try out a few tests... Unfortunately, I only have 64 bit systems... I'll have to see if I get the time to build a 32 bit virtual machine, but it may be a while. Sorry.

  12. #12
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by cpradio View Post
    It shouldn't really skew the results, as the injection it does, should be before and after, not during the execution. You would likely see a decrease in your execution from a end-user standpoint because it is collecting the additional data (if you were to leave it enabled). That is why I use extensions that enable me to quickly turn it on or off, so I'm not impacted by it unless I know I want it. Nonetheless, it shouldn't affect the actual time it takes to execute the code block (but again, I'll usually run the same code block a few times -- 10 for example, and take the average; after removing the first and last execution).
    Thanks, I haven't really used xdebug profiling apart from testing it once or twice so I don't have much experience with it. Can you set it up so that only lines from A to B are profiled in a given script?

    Quote Originally Posted by cpradio View Post
    As for the problem at hand. I now wish I had a 32 bit machine to try out a few tests... Unfortunately, I only have 64 bit systems... I'll have to see if I get the time to build a 32 bit virtual machine, but it may be a while. Sorry.
    But if you have a windows 64 machine it would be also interesting to know how it behaves since from what I have found it's not certain whether the bitness has anything to do with the problem. If you could run the simple code from my first post here and see what accuracy you get?

  13. #13
    Programming Team silver trophybronze trophy
    Mittineague's Avatar
    Join Date
    Jul 2005
    Location
    West Springfield, Massachusetts
    Posts
    17,138
    Mentioned
    190 Post(s)
    Tagged
    2 Thread(s)
    The code from the OP using Win7
    Code:
    0.0104820728302
    0.0029540061950684
    0.0029098987579346
    0.002979040145874
    0.0029270648956299
    0.0029220581054688
    0.002918004989624
    0.002997875213623
    0.002924919128418
    0.0029458999633789

  14. #14
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Mittineague View Post
    The code from the OP using Win7
    Pretty good results, thanks. Is this Win7 64-bit?

    Edit: Is your php + apache installation 64-bit as well?

  15. #15
    Programming Team silver trophybronze trophy
    Mittineague's Avatar
    Join Date
    Jul 2005
    Location
    West Springfield, Massachusetts
    Posts
    17,138
    Mentioned
    190 Post(s)
    Tagged
    2 Thread(s)
    The OS is 64 bit, but both PHP(5.3.10) and Apache(2.2.22) are 32 bit

  16. #16
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Mittineague View Post
    The OS is 64 bit, but both PHP(5.3.10) and Apache(2.2.22) are 32 bit
    Oh, so I'm afraid we have another variable - your PHP version is pretty old and according to the bug report the problem began after bug #64370 was fixed, which happened at version 5.3.24 in the 5.3.x series. My PHP version is 5.3.26 so you are most probably still immune to this problem. So we still don't know whether 64-bit OS has anything to do with it....

  17. #17
    Hosting Team Leader silver trophybronze trophy
    cpradio's Avatar
    Join Date
    Jun 2002
    Location
    Ohio
    Posts
    5,112
    Mentioned
    152 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Lemon Juice View Post
    Thanks, I haven't really used xdebug profiling apart from testing it once or twice so I don't have much experience with it. Can you set it up so that only lines from A to B are profiled in a given script?
    Not that I know of. I've only used it to test the full execution of a process though, as I then go back and review it for out of place items.
    1) High method call times (a method taking over X milliseconds/seconds to run)
    2) High method executions (a method being executed 100+ times)
    3) Several methods being called repeatedly (is there a way to refactor or pass along a result instead of calling it each time it is needed)

    Once I get through that list, I then get nit-picky and start to look at method execution sorted by time taken, and I'll look at the top X percent and see if they can be improved any.

    Quote Originally Posted by Lemon Juice View Post
    But if you have a windows 64 machine it would be also interesting to know how it behaves since from what I have found it's not certain whether the bitness has anything to do with the problem. If you could run the simple code from my first post here and see what accuracy you get?
    Yeah, I can do that. I'll run it from work too tomorrow, so I get two different sets (as my work setup is far different than my home setup).

  18. #18
    Hosting Team Leader silver trophybronze trophy
    cpradio's Avatar
    Join Date
    Jun 2002
    Location
    Ohio
    Posts
    5,112
    Mentioned
    152 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Lemon Juice View Post
    Oh, so I'm afraid we have another variable - your PHP version is pretty old and according to the bug report the problem began after bug #64370 was fixed, which happened at version 5.3.24 in the 5.3.x series. My PHP version is 5.3.26 so you are most probably still immune to this problem. So we still don't know whether 64-bit OS has anything to do with it....
    o.O interesting... I'll definitely post my PHP version and I'll take apache out of the mix by running it through PHP directly.

  19. #19
    Hosting Team Leader silver trophybronze trophy
    cpradio's Avatar
    Join Date
    Jun 2002
    Location
    Ohio
    Posts
    5,112
    Mentioned
    152 Post(s)
    Tagged
    0 Thread(s)
    First Post Duration is your original code in your initial post, the second post duration is the code using bcsub

    PHP Version: 5.4.4-14+deb7u7

    Through Apache 2.2.22:
    Code:
    First Post Duration: 0.0034639835357666
    First Post Duration: 0.0045969486236572
    First Post Duration: 0.0042259693145752
    First Post Duration: 0.0035078525543213
    First Post Duration: 0.0015749931335449
    First Post Duration: 0.0019831657409668
    First Post Duration: 0.0016257762908936
    First Post Duration: 0.0016179084777832
    First Post Duration: 0.0016410350799561
    First Post Duration: 0.0016181468963623
    Second Post Duration: 0.001704
    Second Post Duration: 0.001578
    Second Post Duration: 0.001615
    Second Post Duration: 0.001597
    Second Post Duration: 0.001598
    Second Post Duration: 0.001599
    Second Post Duration: 0.001571
    Second Post Duration: 0.001477
    Second Post Duration: 0.001992
    Second Post Duration: 0.001521
    Through PHP directly
    Code:
    First Post Duration: 0.0038580894470215
    First Post Duration: 0.0039410591125488
    First Post Duration: 0.0042870044708252
    First Post Duration: 0.004223108291626
    First Post Duration: 0.0042579174041748
    First Post Duration: 0.0025999546051025
    First Post Duration: 0.0015888214111328
    First Post Duration: 0.0016119480133057
    First Post Duration: 0.0015580654144287
    First Post Duration: 0.0016000270843506
    Second Post Duration: 0.001609
    Second Post Duration: 0.003847
    Second Post Duration: 0.003861
    Second Post Duration: 0.004273
    Second Post Duration: 0.003091
    Second Post Duration: 0.001775
    Second Post Duration: 0.001759
    Second Post Duration: 0.001782
    Second Post Duration: 0.001933
    Second Post Duration: 0.001934

  20. #20
    Programming Team silver trophybronze trophy
    Mittineague's Avatar
    Join Date
    Jul 2005
    Location
    West Springfield, Massachusetts
    Posts
    17,138
    Mentioned
    190 Post(s)
    Tagged
    2 Thread(s)
    I switched to 5.3.26 and got mostly 0
    Code:
    0.015600919723511
    0
    .....
    0.015599966049194
    0
    .....
    0.01560115814209
    0
    ......
    EDIT
    similar with 5.3.28
    Code:
    0.015599966049194
    0
    .....
    0.015600204467773
    0
    .....
    0.015599966049194
    0
    .....
    EDIT
    version 5.4.23 seems even worse, a lot more 0 and when not, the exact same amount
    Code:
    0
    .....
    0.015599966049194
    0
    .....
    0.015599966049194
    0
    .....
    0.015599966049194
    0
    .....

  21. #21
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by cpradio View Post
    First Post Duration is your original code in your initial post, the second post duration is the code using bcsub

    PHP Version: 5.4.4-14+deb7u7

    Through Apache 2.2.22:
    Code:
    First Post Duration: 0.0034639835357666
    First Post Duration: 0.0045969486236572
    First Post Duration: 0.0042259693145752
    First Post Duration: 0.0035078525543213
    First Post Duration: 0.0015749931335449
    First Post Duration: 0.0019831657409668
    First Post Duration: 0.0016257762908936
    First Post Duration: 0.0016179084777832
    First Post Duration: 0.0016410350799561
    First Post Duration: 0.0016181468963623
    Second Post Duration: 0.001704
    Second Post Duration: 0.001578
    Second Post Duration: 0.001615
    Second Post Duration: 0.001597
    Second Post Duration: 0.001598
    Second Post Duration: 0.001599
    Second Post Duration: 0.001571
    Second Post Duration: 0.001477
    Second Post Duration: 0.001992
    Second Post Duration: 0.001521
    In PHP 5.4.x bug #64370 was fixed at 5.4.14 so your PHP version must be still too old for this problem to manifest and you get pretty meaningful measurements.

    Quote Originally Posted by Mittineague View Post
    I switched to 5.3.26 and got mostly 0
    Code:
    0.015600919723511
    0
    .....
    0.015599966049194
    0
    .....
    0.01560115814209
    0
    ......
    EDIT
    similar with 5.3.28
    Code:
    0.015599966049194
    0
    .....
    0.015600204467773
    0
    .....
    0.015599966049194
    0
    .....
    EDIT
    version 5.4.23 seems even worse, a lot more 0 and when not, the exact same amount
    Code:
    0
    .....
    0.015599966049194
    0
    .....
    0.015599966049194
    0
    .....
    0.015599966049194
    0
    .....
    So these results are roughly consistent with mine - you seem to be getting some minor accuracy variations that are hard to explain (perhaps it's because floats on 64-bit system are more accurate?) but generally the accuracy is around 1/64s.

    Thanks guys for testing, the moral of the story is that 64-bit Windows doesn't help and it's some internal PHP problem that is hard to resolve by the devs. Well, it looks like we have to live with it.

  22. #22
    Hosting Team Leader silver trophybronze trophy
    cpradio's Avatar
    Join Date
    Jun 2002
    Location
    Ohio
    Posts
    5,112
    Mentioned
    152 Post(s)
    Tagged
    0 Thread(s)
    Okay, so I upgraded to PHP 5.5.7-1~dotdeb.1

    Through Apache 2.2.22
    Code:
    First Post Duration: 0.0046329498291016
    First Post Duration: 0.0046679973602295
    First Post Duration: 0.0050249099731445
    First Post Duration: 0.0050790309906006
    First Post Duration: 0.0042960643768311
    First Post Duration: 0.0034949779510498
    First Post Duration: 0.0015449523925781
    First Post Duration: 0.0015799999237061
    First Post Duration: 0.0015418529510498
    First Post Duration: 0.001471996307373
    Second Post Duration: 0.001558
    Second Post Duration: 0.001532
    Second Post Duration: 0.001640
    Second Post Duration: 0.001737
    Second Post Duration: 0.001674
    Second Post Duration: 0.001706
    Second Post Duration: 0.001642
    Second Post Duration: 0.001712
    Second Post Duration: 0.001661
    Second Post Duration: 0.001602
    Through PHP directly:
    Code:
    First Post Duration: 0.0017070770263672
    First Post Duration: 0.0016820430755615
    First Post Duration: 0.0013980865478516
    First Post Duration: 0.0014219284057617
    First Post Duration: 0.0014159679412842
    First Post Duration: 0.0013940334320068
    First Post Duration: 0.0014259815216064
    First Post Duration: 0.0015621185302734
    First Post Duration: 0.0015759468078613
    First Post Duration: 0.0015280246734619
    Second Post Duration: 0.001577
    Second Post Duration: 0.001821
    Second Post Duration: 0.001600
    Second Post Duration: 0.001687
    Second Post Duration: 0.001730
    Second Post Duration: 0.001730
    Second Post Duration: 0.001506
    Second Post Duration: 0.001730
    Second Post Duration: 0.001721
    Second Post Duration: 0.001707
    So it seems they fixed it somewhere? Or 64 bit isn't affected...

  23. #23
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by cpradio View Post
    Okay, so I upgraded to PHP 5.5.7-1~dotdeb.1
    If your php version is dotdeb isn't it running on Debian... ?

  24. #24
    Hosting Team Leader silver trophybronze trophy
    cpradio's Avatar
    Join Date
    Jun 2002
    Location
    Ohio
    Posts
    5,112
    Mentioned
    152 Post(s)
    Tagged
    0 Thread(s)
    Quote Originally Posted by Lemon Juice View Post
    If your php version is dotdeb isn't it running on Debian... ?
    Yes, but the package I pulled (php 5.5.7) was from dotdeb.org, as they give you access to the latest PHP/Apache packages without running the entire system in the Testing/Unstable repo officially offered by Debian. Debian's stable repo is only permitting 5.4.4, so my choices were, compile from source, or find a repo that gave me a more "latest" version of PHP than Debian's stable (I choose the latter for convenience sake).

  25. #25
    SitePoint Guru bronze trophy
    Join Date
    Dec 2003
    Location
    Poland
    Posts
    930
    Mentioned
    7 Post(s)
    Tagged
    0 Thread(s)
    I was asking because this problem seems to exist only on Windows systems, so if you are running linux then I suppose any php version will work well for microtime


Bookmarks

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •