Re: In search of a bug in Time::HiRes on Windows.
by PodMaster (Abbot) on Jun 15, 2005 at 03:07 UTC
|
C:\>perl5.6.1 time.hires.bug.466763.pl
1.68
1118804774.18816
1118804774.18823
1118804774.18829
1118804774.18834
1118804774.1884
1118804774.18851
1118804774.18857
1118804774.18866
1118804774.18872
1118804774.18877
C:\>perl5.6.2 time.hires.bug.466763.pl
1.68
1118804778.18835
1118804778.18842
1118804778.18847
1118804778.18853
1118804778.18859
1118804778.18864
1118804778.1887
1118804778.18876
1118804778.18881
1118804778.18887
C:\>perl5.8.4 time.hires.bug.466763.pl
1.68
1118804785.78195
1118804785.78199
1118804785.78203
1118804785.78207
1118804785.7821
1118804785.78214
1118804785.78217
1118804785.7822
1118804785.78224
1118804785.78227
C:\>perl5.8.6d time.hires.bug.466763.pl
1.65
1118804791.4676
1118804791.46766
1118804791.4677
1118804791.46774
1118804791.46778
1118804791.46782
1118804791.46786
1118804791.4679
1118804791.46794
1118804791.46798
MJD says "you can't just make shit up and expect the computer to know what you mean, retardo!" | I run a Win32 PPM repository for perl 5.6.x and 5.8.x -- I take requests (README). | ** The third rule of perl club is a statement of fact: pod is sexy. |
| [reply] [Watch: Dir/Any] [d/l] |
Re: In search of a bug in Time::HiRes on Windows.
by eyepopslikeamosquito (Archbishop) on Jun 15, 2005 at 03:04 UTC
|
1.65
1118804504.10359
1118804504.10371
1118804504.10383
1118804504.10393
1118804504.10403
1118804504.10416
1118804504.10425
1118804504.10435
1118804504.10446
1118804504.10456
| [reply] [Watch: Dir/Any] [d/l] |
Re: In search of a bug in Time::HiRes on Windows.
by kiat (Vicar) on Jun 15, 2005 at 03:15 UTC
|
With Perl version v5.8.6:
1.65
1118805186.85975
1118805186.85976
1118805186.85976
1118805186.85977
1118805186.85978
1118805186.85978
1118805186.85979
1118805186.85979
1118805186.8598
1118805186.8598
| [reply] [Watch: Dir/Any] [d/l] |
|
That's strange? The snippet I posted should only produce unique values, not duplicates.
Did you modify it to produce these results?
Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error.
Lingua non convalesco, consenesco et abolesco. -- Rule 1 has a caveat! -- Who broke the cabal?
"Science is about questioning the status quo. Questioning authority".
The "good enough" maybe good enough for the now, and perfection maybe unobtainable, but that should not preclude us from striving for perfection, when time, circumstance or desire allow.
| [reply] [Watch: Dir/Any] |
|
No, I ran your code as-is. Here's more:
perl time_bug.pl > time_bug.txt
1.65
1118806411.5004
1118806411.50041
1118806411.50041
1118806411.50042
1118806411.50043
1118806411.50043
1118806411.50044
1118806411.50044
1118806411.50045
1118806411.50045
Update:
When I ran (output to the screen)
perl time_bug.pl
i.e. without "> time_bug.txt", there're no duplicates. | [reply] [Watch: Dir/Any] [d/l] [select] |
Re: In search of a bug in Time::HiRes on Windows.
by jbrugger (Parson) on Jun 15, 2005 at 05:04 UTC
|
U:\>perl --version
This is perl, v5.8.6 built for cygwin-thread-multi-64int
Copyright 1987-2004, Larry Wall
Perl may be copied only under the terms of either the Artistic License or the
GNU General Public License, which may be found in the Perl 5 source kit.
Complete documentation for Perl, including FAQ lists, should be found on
this system using `man perl' or `perldoc perl'. If you have access to the
Internet, point your browser at http://www.perl.org/, the Perl Home Page.
U:\>perl test.pl
1.65
1118811736.68118
1118811736.68156
1118811736.68186
1118811736.68224
1118811736.68257
1118811736.68288
1118811736.68318
1118811736.68357
1118811736.68387
1118811736.68417
"We all agree on the necessity of compromise. We just can't agree on when it's necessary to compromise." - Larry Wall.
| [reply] [Watch: Dir/Any] |
Re: In search of a bug in Time::HiRes on Windows.
by K_M_McMahon (Hermit) on Jun 15, 2005 at 03:33 UTC
|
1.65
1118806227.5142
1118806227.51421
1118806227.51422
1118806227.51422
1118806227.51423
1118806227.51424
1118806227.51424
1118806227.51425
1118806227.51426
1118806227.51427
Perl Version
This is perl, v5.8.6 built for MSWin32-x86-multi-thread
(with 3 registered patches, see perl -V for more detail)
Copyright 1987-2004, Larry Wall
Binary build 811 provided by ActiveState Corp. http://www.ActiveState.
+com
ActiveState is a division of Sophos.
Built Dec 13 2004 09:52:01
Perl may be copied only under the terms of either the Artistic License
+ or the
GNU General Public License, which may be found in the Perl 5 source ki
+t.
Complete documentation for Perl, including FAQ lists, should be found
+on
this system using `man perl' or `perldoc perl'. If you have access to
+ the
Internet, point your browser at http://www.perl.org/, the Perl Home Pa
+ge.
Perl Version (More Detail)
-Kevin
my $a='62696c6c77667269656e6440676d61696c2e636f6d';
while ($a=~m/(^.{2})/s)
{print unpack('A',pack('H*',"$1"));$a=~s/^.{2}//s;}
| [reply] [Watch: Dir/Any] [d/l] [select] |
Re: In search of a bug in Time::HiRes on Windows.
by ikegami (Patriarch) on Jun 15, 2005 at 05:45 UTC
|
(n = 10,000)
>perl !.pl
1.2
1118813755.17075
1118813755.18637
(n = 100,000)
>perl !.pl
1.2
1118813761.18637
1118813761.202
1118813761.21762
1118813761.23325
1118813761.24887
1118813761.2645
>perl -v
This is perl, v5.8.0 built for MSWin32-x86-multi-thread
(with 1 registered patch, see perl -V for more detail)
Binary build 806 provided by ActiveState Corp. http://www.ActiveState.
+com
Built 00:45:44 Mar 31 2003
...
I had to use ppm to install Time::HiRes for 5.6.1. I had to reduce the loop to 10, down from 100,000:
(n=10)
>perl !.pl
1.63
1118814102.57754
1118814102.57761
1118814102.57767
1118814102.57773
1118814102.57793
1118814102.57799
1118814102.57805
1118814102.57812
1118814102.57818
1118814102.57824
>perl -v
This is perl, v5.6.1 built for MSWin32-x86-multi-thread
(with 1 registered patch, see perl -V for more detail)
Copyright 1987-2001, Larry Wall
Binary build 635 provided by ActiveState Corp. http://www.ActiveState.
+com
Built 15:34:21 Feb 4 2003
...
It seems 5.6.1's Time::HiRes has a much better resolution than 5.8.0's. Is that the bug for which you are searching? My 5.8.0 results seem different from everyone else's results. | [reply] [Watch: Dir/Any] [d/l] [select] |
|
Warning: Long & complicated story! (With a request at the end)
It seems 5.6.1 has a much better resolution than 5.8.0. Is that the bug for which you are searching?
It's not quite that simple. Time::HiRes v1.2 is a very old version I think which could explain your results. Later versions (circa. >= 1.53 ) have code which uses a high resolution performance counter to enhance the low resolution of the GetSystemTimeAsFileTime() api.
However, under some circumstances, the use of the high res timer doesn't seems to work correctly. For example:
On my system, doing it this way the resolution is around 70/80 uSeconds:
P:\test>perl -MTime::HiRes=time -wle"print time for 1 .. 10"
1118814859.12534
1118814859.12551
1118814859.12558
1118814859.12566
1118814859.12573
1118814859.1258
1118814859.12587
1118814859.12594
1118814859.12602
1118814859.12609
but in the debugger, it suddenly becomes 31.25 milliseconds:
P:\test>perl -MTime::HiRes=time -de1
perldb: Must not source insecure rcfile ./perldb.ini.
You or the superuser must be the owner, and it must not
be writable by anyone but its owner.
Loading DB routines from perl5db.pl version 1.25
Editor support available.
Enter h or `h h' for help, or `perldoc perldebug' for more help.
main::(-e:1): 1
DB<1> print time . $/ for 1 .. 20;;
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.6875
1118815107.71875
1118815107.71875
1118815107.71875
1118815107.71875
1118815107.71875
1118815107.71875
1118815107.71875
1118815107.73438
DB<2>
which is strange enough, but it gets stranger. I saw spurperl's comment in Re^2: Microseconds in Per regarding Time::HiRes resolution on Win32 and it reminded me of a similar effect I pursued a while ago after reading Unique filenames with Time::HiRes which lead to Re^4: Perl -de1 weirdness..
I was on a different machine/version of the OS back then, and when I tried to trackdown the problem, I couldn't reproduce it outside the debugger. Whilst I did raise a mention on p5p, a bug in a timer that only occurs inside the debugger isn't really critical.
However, and this is where it gets really strange, the other day when I read spurperl's comment, I ran the above test, and I was getting the 31.25 millsecond resolution outside of the debugger! Last night I decided to try and track it down again, and I ran some code using Win32::API to access the performance counter directly. Twiddled around a bit and then tried the test above again, and suddenly, the I was getting the 70/80 microsecond resolution outside of the debugger. I didn't install anything new.
Puzzled, I eventually tried rebooting to see what if any difference that made and it made none at all. I now have the high resolution timer outside of the debugger and nothing I have tried reverts me to the low res situation outside of the debugger.
Great you might say, but this is where I was on my old machine. I had the low-res timer always. Played with calling the performance counter, suddenly got the high res results and could find no way to revert outside of the debugger!
My feeling is that Windows is caching some state somewhere and that the calls inside Time::HiRes.xs are not triggering the enablement of the performance counter on their own. But once the performance counter has been enabled, Time::HiRes is able to use it from that point on. How/why that would be so I cannot imagine at this stage.
So, what I need is someone who has Time::HiRes v 1.53 or greater that is getting low-res results. I am not sure whether the Perl version is relevant or not yet. PodMaster showed that high resolution results are possible on every build.
If I can find someone with T::H >1.53 getting low-res results, then I will ask then to run the piece of Win32::API code that appeared to make the difference on my machine and see if it has the same enabling effect for them.
Is there any chance of you upgrading to T::H > 1.53 in your 5.8.x install?
If you cannot find a PPM, I could always email you the files from here.
Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error.
Lingua non convalesco, consenesco et abolesco. -- Rule 1 has a caveat! -- Who broke the cabal?
"Science is about questioning the status quo. Questioning authority".
The "good enough" maybe good enough for the now, and perfection maybe unobtainable, but that should not preclude us from striving for perfection, when time, circumstance or desire allow.
| [reply] [Watch: Dir/Any] [d/l] [select] |
Re: In search of a bug in Time::HiRes on Windows.
by GrandFather (Saint) on Jun 15, 2005 at 03:43 UTC
|
1.65
1118806618.62947
1118806618.62948
1118806618.62948
1118806618.62949
1118806618.6295
1118806618.6295
1118806618.62951
1118806618.62951
1118806618.62952
1118806618.62952
Perl is Huffman encoded by design.
| [reply] [Watch: Dir/Any] [d/l] |
Re: In search of a bug in Time::HiRes on Windows.
by fglock (Vicar) on Jun 15, 2005 at 05:23 UTC
|
This is all I get (Windows NT, perl 5.8.0):
1.2
| [reply] [Watch: Dir/Any] [d/l] |
|
| [reply] [Watch: Dir/Any] [d/l] |
|
1.2
1118892950.89816
1118892950.90818
| [reply] [Watch: Dir/Any] [d/l] |
|
|
Re: In search of a bug in Time::HiRes on Windows.
by NateTut (Deacon) on Jun 15, 2005 at 16:44 UTC
|
perl Time-HiRes-Test.pl
1.55
1118852932.57546
1118852932.57558
1118852932.57561
1118852932.57624
1118852932.57633
1118852932.59201
1118852932.59212
1118852932.59215
1118852932.59252
1118852932.59257
C:\My Documents\Clients\Dem\pl>perl -v
This is perl, v5.8.3 built for MSWin32-x86-multi-thread
(with 8 registered patches, see perl -V for more detail)
Copyright 1987-2003, Larry Wall
Binary build 809 provided by ActiveState Corp. http://www.ActiveState.
+com
ActiveState is a division of Sophos.
Built Feb 3 2004 00:28:51
If it matters: 733 MHz, Windows ME | [reply] [Watch: Dir/Any] [d/l] |
Re: In search of a bug in Time::HiRes on Windows.
by spurperl (Priest) on Jun 17, 2005 at 05:59 UTC
|
This is perl, v5.8.4 built for MSWin32-x86-multi-thread
(with 3 registered patches, see perl -V for more detail)
Copyright 1987-2004, Larry Wall
Binary build 810 provided by ActiveState Corp. http://www.ActiveState.com
ActiveState is a division of Sophos.
Built Jun 1 2004 11:52:21
Perl may be copied only under the terms of either the Artistic License or the
GNU General Public License, which may be found in the Perl 5 source kit.
Complete documentation for Perl, including FAQ lists, should be found on
this system using `man perl' or `perldoc perl'. If you have access to the
Internet, point your browser at http://www.perl.com/, the Perl Home Page.
The results are:
1.59
1118987794.35973
1118987794.35978
1118987794.3598
1118987794.35981
1118987794.35983
1118987794.35985
1118987794.35987
1118987794.35989
1118987794.35991
1118987794.35992
| [reply] [Watch: Dir/Any] |
|
| [reply] [Watch: Dir/Any] |
|
It looks like the problem went away, yes. Unfortunately, I don't remember how to reproduce the original problem. If I run into it again I'll let you know.
In the debugger I get:
DB<2> print time . $/ for 1 .. 20;;
1118999589.19879
1118999589.2088
1118999589.2088
1118999589.21882
1118999589.21882
1118999589.22883
1118999589.23884
1118999589.23884
1118999589.24886
1118999589.24886
1118999589.25887
1118999589.26889
1118999589.26889
1118999589.2789
1118999589.2789
1118999589.28892
1118999589.29893
1118999589.30894
1118999589.30894
1118999589.31896
| [reply] [Watch: Dir/Any] |
|