negative elapsed time?

saneel has asked for the wisdom of the Perl Monks concerning the following question:

Hi, I am using Time:HiRes module. I just measuring the before and after time as shown in the script below. However, in many cases the "after time" comes out less than "before time", when I run it on Windows with multi-core CPU's. I don't get this when I am running the below script on a VM which has Linux with only one processor allocated to it. Why could this be happening?

#!/usr/bin/perl -w


use Time::HiRes;


$count = 1000000; print "\nStarting loop\n";
for ($c = $count; $c >= 1; $c--)
{
   
   $t3 = 0; $t4 =0; $t5 = 0;  

   #print "\n";
   #print "t3: "; printf "%.2f\n",$t3;
   #print "t4: "; printf "%.2f\n",$t4;
   #print "\n";

  

   $t3 = Time::HiRes::time();  
    
   $t4 = Time::HiRes::time();
 
   $t5 = $t4-$t3;

   #print "t5: "; printf "%.6f\n",$t5;

   if($t5<=0)
   {
        print"\n Value negative in count: $c";
        print "\n t3: "; printf "%.6f",$t3;
        print "\n t4: "; printf "%.6f\n",$t4;
       print "\n Negative or zero value: $t5";
   }
 

}
print "\nEnd of loop\n";
[download]

Comment on negative elapsed time? Download Code

Replies are listed 'Best First'.
Re: negative elapsed time? (versions?) by BrowserUk (Patriarch) on Aug 08, 2011 at 15:18 UTC
I don't get any negative or zero results running your script under AS1007/Vista: `C:\test>junk14 Starting loop End of loop C:\test>perl -MTime::HiRes -E"say $Time::HiRes::VERSION" 1.9719` [download] What versions are you running? Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error. "Science is about questioning the status quo. Questioning authority". In the absence of evidence, opinion is indistinguishable from prejudice.	[reply] [d/l]
Re^2: negative elapsed time? (versions?) by saneel (Initiate) on Aug 08, 2011 at 15:31 UTC
Hi, I am using: perl 5, version 12, subversion 4 (v5.12.4) built for MSWin32-x86-multi-thread This is the sample output I am getting: Value negative in count: 5940052 t3: 1312816368.122099 t4: 1312816368.121128 Negative or zero value: -0.000970840454101563 Value negative in count: 996932 t3: 1312814653.022737 t4: 1312814653.022737 Negative or zero value: 0 Value negative in count: 996929 t3: 1312814653.023484 t4: 1312814653.023484 Negative or zero value: 0 Value negative in count: 996928 t3: 1312814653.024365 t4: 1312814653.024365 Negative or zero value: 0 Value negative in count: 996926 t3: 1312814653.024980 t4: 1312814653.024980 Negative or zero value: 0 Also, I tested in windows production servers, and I am getting these negative or zero values	[reply]
Re^3: negative elapsed time? (versions?) by BrowserUk (Patriarch) on Aug 08, 2011 at 15:35 UTC
Hm. I don't see any problems using 5.14 either: `C:\perl5.14-64\bin>.\perl.exe \test\junk14.pl Starting loop End of loop` [download] What versions of Time::HiRes and Windows are you using? Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error. "Science is about questioning the status quo. Questioning authority". In the absence of evidence, opinion is indistinguishable from prejudice.	[reply] [d/l]
Re^4: negative elapsed time? (versions?) by saneel (Initiate) on Aug 08, 2011 at 15:38 UTC
Re^5: negative elapsed time? (versions?) by BrowserUk (Patriarch) on Aug 08, 2011 at 15:44 UTC
Re: negative elapsed time? by FunkyMonk (Chancellor) on Aug 08, 2011 at 15:09 UTC
Does it make any difference if you change `if($t5<=0)` to `if($t5<0)` so you actually check for a negative value? Ps I don't see any negative values on my (not-a-vm) linux box.	[reply] [d/l] [select]
Re^2: negative elapsed time? by saneel (Initiate) on Aug 08, 2011 at 15:14 UTC
Hi, Most of times on windows, I get either negative or zero values, especially when the count value is high.	[reply]
Re: negative elapsed time? by Marshall (Canon) on Aug 08, 2011 at 15:40 UTC
~~This article explains the limitations of the Time Stamp Counter register on multi-core x86 CPU's: Wiki Time Stamp Counter.~~ Evidently not applicable as Hi:Res does something different? See note from BrowserUk. I am unaware of any hardware source for a high resolution time other than this CPU feature. I'd be curious if somebody knows of some alternative. As article mentions, MS provides an API for times, but it uses this hardware.	[reply]
Re^2: negative elapsed time? by BrowserUk (Patriarch) on Aug 08, 2011 at 18:43 UTC
I am unaware of any hardware source for a high resolution time other than this CPU feature. I'd be curious if somebody knows of some alternative. On windows, Time::HiRes uses QueryPerformanceCounter + GetSystemTimeAsFileTime. The former is underlain by the most accurate hardware timer available on the PC. This varies (increasing in accuracy) as the age of the hardware lessens. Since circa 2005, all modern PCs have had a High Precision Event Time available as a part of the hardware. This is unaffected by clock speed energy management and lies outside of the number of cores or hyper-threads. (Am I too scary to talk to?) Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error. "Science is about questioning the status quo. Questioning authority". In the absence of evidence, opinion is indistinguishable from prejudice.	[reply]
Re^2: negative elapsed time? (misinformation) by BrowserUk (Patriarch) on Aug 08, 2011 at 15:48 UTC
This article explains the limitations of the Time Stamp Counter register on multi-core x86 CPU's Which would be good information to post if Time::HiRes actually used the TSC! Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error. "Science is about questioning the status quo. Questioning authority". In the absence of evidence, opinion is indistinguishable from prejudice.	[reply]
Re^2: negative elapsed time? by saneel (Initiate) on Aug 08, 2011 at 15:44 UTC
So, is there way where i could program the code to run on only a single core?	[reply]
Re^3: negative elapsed time? by BrowserUk (Patriarch) on Aug 08, 2011 at 22:55 UTC
So, is there way where i could program the code to run on only a single core? Yes. See the /AFFINITY switch to the windows `start` command: `AFFINITY The new application will have the specified processor affinity mask, expressed as a hexadecimal number.` [download] But I do not think that is the problem here. (As might be evidenced by your lack of response to Re^5: negative elapsed time? (versions?)?) Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error. "Science is about questioning the status quo. Questioning authority". In the absence of evidence, opinion is indistinguishable from prejudice.	[reply] [d/l] [select]
Re: negative elapsed time? by zentara (Archbishop) on Aug 08, 2011 at 14:58 UTC
Please wrap your code in '<code>' tags. I'm not really a human, but I play one on earth. Old Perl Programmer Haiku ................... flash japh	[reply]

Back to Seekers of Perl Wisdom