timbunce/devel-nytprof — pull request #26 by bulk88 (2014-03-29 08:20:19+00:00)
Title: win32 QueryPerformanceCounter code

QueryPerformanceCounter commit needs some remaining work but I need some answers from you first. QPC with NYTProf seems to work for my personal code. Many lines that were 0 S are now 2-5 us or higher. nmake test passes with the new QPC, but I keep getting this in the console.

```
Summary: statements profiled 16 (=16-0), sum of time 0.000217s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 16 (=16-0), sum of time 0.000204s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 16 (=16-0), sum of time 0.000224s, profile spanned
0.000000s
t/test60-subname.t ..... 36/65 The sum of the statement timings is 1.$% of the t
otal time profiling. (Values slightly over 100% can be due simply to cumulative
timing errors, whereas larger values can indicate a problem with the clock used.
)
Summary: statements profiled 16 (=16-0), sum of time 0.000212s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 16 (=16-0), sum of time 0.000213s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 16 (=16-0), sum of time 0.000225s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 16 (=16-0), sum of time 0.000218s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 16 (=16-0), sum of time 0.000212s, profile spanned
0.000000s
t/test60-subname.t ..... 56/65 The sum of the statement timings is 1.$% of the t
otal time profiling. (Values slightly over 100% can be due simply to cumulative
timing errors, whereas larger values can indicate a problem with the clock used.
)
Summary: statements profiled 16 (=16-0), sum of time 0.000201s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 16 (=16-0), sum of time 0.000220s, profile spanned
0.000000s
t/test60-subname.t ..... ok
t/test61-submerge.t .... PERL5DB=BEGIN {require q}
t/test61-submerge.t .... 1/65 The sum of the statement timings is 1.$% of the to
tal time profiling. (Values slightly over 100% can be due simply to cumulative t
iming errors, whereas larger values can indicate a problem with the clock used.)

Summary: statements profiled 13 (=13-0), sum of time 0.000304s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000320s, profile spanned
0.000000s
t/test61-submerge.t .... 8/65 The sum of the statement timings is 1.$% of the to
tal time profiling. (Values slightly over 100% can be due simply to cumulative t
iming errors, whereas larger values can indicate a problem with the clock used.)

Summary: statements profiled 13 (=13-0), sum of time 0.000307s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=22-9), sum of time 0.000309s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000310s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000274s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=22-9), sum of time 0.000289s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=22-9), sum of time 0.000289s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000306s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=22-9), sum of time 0.000312s, profile spanned
0.000000s
t/test61-submerge.t .... 40/65 The sum of the statement timings is 1.$% of the t
otal time profiling. (Values slightly over 100% can be due simply to cumulative
timing errors, whereas larger values can indicate a problem with the clock used.
)
Summary: statements profiled 13 (=13-0), sum of time 0.000298s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000301s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000389s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000312s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000370s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 13 (=13-0), sum of time 0.000302s, profile spanned
0.000000s
t/test61-submerge.t .... ok
t/test62-subcaller1.t .. PERL5DB=BEGIN {require q}
t/test62-subcaller1.t .. 1/65 The sum of the statement timings is 1.$% of the to
tal time profiling. (Values slightly over 100% can be due simply to cumulative t
iming errors, whereas larger values can indicate a problem with the clock used.)

Summary: statements profiled 45 (=45-0), sum of time 0.003848s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=60-15), sum of time 0.003658s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=60-15), sum of time 0.003690s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=45-0), sum of time 0.003360s, profile spanned
0.000000s
t/test62-subcaller1.t .. 16/65 The sum of the statement timings is 1.$% of the t
otal time profiling. (Values slightly over 100% can be due simply to cumulative
timing errors, whereas larger values can indicate a problem with the clock used.
)
Summary: statements profiled 45 (=45-0), sum of time 0.004253s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=60-15), sum of time 0.003608s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=45-0), sum of time 0.003438s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=45-0), sum of time 0.003727s, profile spanned
0.000000s
t/test62-subcaller1.t .. 40/65 The sum of the statement timings is 1.$% of the t
otal time profiling. (Values slightly over 100% can be due simply to cumulative
timing errors, whereas larger values can indicate a problem with the clock used.
)
Summary: statements profiled 45 (=45-0), sum of time 0.003948s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=45-0), sum of time 0.003533s, profile spanned
0.000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 45 (=45-0), sum of time 0.003299s, profile spanned
0.000000s
t/test62-subcaller1.t .. ok
t/test70-subexcl.t ..... PERL5DB=BEGIN {require q}
t/test70-subexcl.t ..... ok
t/test80-recurs.t ...... PERL5DB=BEGIN {require q}
t/test80-recurs.t ...... ok
t/test81-swash.t ....... PERL5DB=BEGIN {require q}
t/test81-swash.t ....... 1/49 The sum of the statement timings is 1.$% of the to
tal time profiling. (Values slightly over 100% can be due simply to cumulative t
iming errors, whereas larger values can indicate a problem with the clock used.)

Summary: statements profiled 3 (=3-0), sum of time 0.000036s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000038s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000032s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000038s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000037s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000037s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000032s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000036s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000036s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000035s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000037s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000036s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000036s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000039s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000032s, profile spanned 0.
000000s
The sum of the statement timings is 1.$% of the total time profiling. (Values sl
ightly over 100% can be due simply to cumulative timing errors, whereas larger v
alues can indicate a problem with the clock used.)
Summary: statements profiled 3 (=3-0), sum of time 0.000037s, profile spanned 0.
000000s
t/test81-swash.t ....... ok
t/test82-version.t ..... PERL5DB=BEGIN {require q}
t/test82-version.t ..... ok
t/test90-strsubref.t ... PERL5DB=BEGIN {require q}
t/test90-strsubref.t ... ok
t/zzz.t ................ # Tests ended at Sat Mar 29 04:10:59 2014
t/zzz.t ................ ok
All tests successful.
Files=53, Tests=4466, 213 wallclock secs ( 1.06 usr + 0.09 sys = 1.16 CPU)
Result: PASS

C:\sources\devel-nytprof>
```