Do we have a timing overhead again?

[valassi]

From @hageboeck presentation https://indico.cern.ch/event/1292145/
There is a flamegraph where fortran counters (again!) seem to have an overhead

To be checked: are we using the "good" clock source on the O/S, or still the one that relies on expensive system cals?

Se ethe long discussions in #116 (and maybe #117)

Low priority

[valassi]

To be done anyway: compile counters with -O3 as suggested by @hageboeck
See [6aed8a8](https://github.com/madgraph5/madgraph4gpu/commit/6aed8a8957a7292d690d0cb5208bf889be482e57)957a7292d690d0cb5208bf889be482e57 in MR #642

From the discussion: "we are being unfair to Fortran because there is an overhead in its timing measurements"

[cosmicexplorer47]

Great presentation by @hageboeck! 🔥 The flamegraph analysis shared in this video (link: https://indico.cern.ch/event/1292145/) reveals some interesting findings about the overhead in fortran counters. 📈 It would be worth looking into whether we're utilizing the "good" clock source on our operating system or if we're still relying on those expensive system calls. 🕵️‍♂️ Check out the engaging discussions in threads #116 and maybe #117 for more insights on this topic. ⚡️ However, at the moment, addressing this issue seems to be of low priority. Keep up the great work! 👍

[valassi]

To be done anyway: compile counters with -O3 as suggested by @hageboeck See [6aed8a8957a7292d690d0cb5208bf889be482e57]([6aed8a8](https://github.com/madgraph5/madgraph4gpu/commit/6aed8a8957a7292d690d0cb5208bf889be482e57)957a7292d690d0cb5208bf889be482e57) in MR #642

From the discussion: "we are being unfair to Fortran because there is an overhead in its timing measurements"

This is now addressed in #740 and will be fixed in an upcoming patch by @hageboeck

[valassi]

I am not sure if we have a systematic timing overhead as in the past. At that time this was a problem with the O/S not using the right std::chrono implementation. I think this is gone.

However, even on a good O/S, the std::chrono implementation of timers does have an overhead. This is qute obvious in my timing exercises for sample_get_x in WIP PR #970.

Because of that, I implemented a new timer implementation based on rdtsc. This may have issues (or not?) in multi threaded environments, but for the timing exercises I do most of the time it looks good enough. This is in PR #970.

See for instance here 2cddbdb

 [COUNTERS] *** USING RDTSC-BASED TIMERS ***
 [COUNTERS] PROGRAM TOTAL                         :    3.9912s
 [COUNTERS] Fortran Other                  (  0 ) :    0.1225s
 [COUNTERS] Fortran Initialise(I/O)        (  1 ) :    0.0669s
 [COUNTERS] Fortran Random2Momenta         (  3 ) :    2.8019s for  1170103 events => throughput is 2.39E-06 events/s
 [COUNTERS] Fortran PDFs                   (  4 ) :    0.1025s for    49152 events => throughput is 2.09E-06 events/s
 [COUNTERS] Fortran UpdateScaleCouplings   (  5 ) :    0.1329s for    16384 events => throughput is 8.11E-06 events/s
 [COUNTERS] Fortran Reweight               (  6 ) :    0.0513s for    16384 events => throughput is 3.13E-06 events/s
 [COUNTERS] Fortran Unweight(LHE-I/O)      (  7 ) :    0.0653s for    16384 events => throughput is 3.99E-06 events/s
 [COUNTERS] Fortran SamplePutPoint         (  8 ) :    0.1188s for  1170103 events => throughput is 1.02E-07 events/s
 [COUNTERS] PROGRAM SampleGetX             ( 10 ) :    1.6723s for 15211307 events => throughput is 1.10E-07 events/s
 [COUNTERS] CudaCpp Initialise             ( 11 ) :    0.4680s
 [COUNTERS] CudaCpp Finalise               ( 12 ) :    0.0262s
 [COUNTERS] CudaCpp MEs                    ( 19 ) :    0.0349s for    16384 events => throughput is 2.13E-06 events/s
 [COUNTERS] OVERALL NON-MEs                ( 21 ) :    3.9563s
 [COUNTERS] OVERALL MEs                    ( 22 ) :    0.0349s for    16384 events => throughput is 2.13E-06 events/s

 [COUNTERS] *** USING STD::CHRONO TIMERS ***
 [COUNTERS] PROGRAM TOTAL                         :    4.8516s
 [COUNTERS] Fortran Other                  (  0 ) :    0.1718s
 [COUNTERS] Fortran Initialise(I/O)        (  1 ) :    0.0679s
 [COUNTERS] Fortran Random2Momenta         (  3 ) :    3.5816s for  1170103 events => throughput is 3.06E-06 events/s
 [COUNTERS] Fortran PDFs                   (  4 ) :    0.1041s for    49152 events => throughput is 2.12E-06 events/s
 [COUNTERS] Fortran UpdateScaleCouplings   (  5 ) :    0.1351s for    16384 events => throughput is 8.24E-06 events/s
 [COUNTERS] Fortran Reweight               (  6 ) :    0.0520s for    16384 events => throughput is 3.17E-06 events/s
 [COUNTERS] Fortran Unweight(LHE-I/O)      (  7 ) :    0.0653s for    16384 events => throughput is 3.98E-06 events/s
 [COUNTERS] Fortran SamplePutPoint         (  8 ) :    0.1432s for  1170103 events => throughput is 1.22E-07 events/s
 [COUNTERS] PROGRAM SampleGetX             ( 10 ) :    2.0685s for 15211307 events => throughput is 1.36E-07 events/s
 [COUNTERS] CudaCpp Initialise             ( 11 ) :    0.4697s
 [COUNTERS] CudaCpp Finalise               ( 12 ) :    0.0261s
 [COUNTERS] CudaCpp MEs                    ( 19 ) :    0.0349s for    16384 events => throughput is 2.13E-06 events/s
 [COUNTERS] OVERALL NON-MEs                ( 21 ) :    4.8167s
 [COUNTERS] OVERALL MEs                    ( 22 ) :    0.0349s for    16384 events => throughput is 2.13E-06 events/s

I keep rdtsc as the default. There is an env variable which falls back to chrono.

I am closing this now.