- changed status to open
- removed comment
Marek Blazewicz reports:
I was using the timer tree in Carpet. Because it was not too nicely outputted, and I had to format it manually each time, I've fixed it ;).
Keyword:
Marek Blazewicz reports:
I was using the timer tree in Carpet. Because it was not too nicely outputted, and I had to format it manually each time, I've fixed it ;).
Keyword:
Please apply
Marek says:
First for "untimed", the precision was 1, always. I unified it with other lines.
Secondly I've changed the width of the column float field (duration in s.) to the maximal printed length. These are # digits before decimal sep. (.) + 1 for dec. sep. + precision. The length of the field is computed once (log10(total time (which I assume is the largest number))) and passed to children via recurrence, to avoid unnecessary computations.
For '%' of total time I've used constant equation: 3 (log(100) + 1) + 1 + precision.
Thanks to these changes the time tree looks like tree ;)
The patch no longer applies, and since the output format seems to have changed in the meantime, there is no quick way to see how to merge.
Most of this code (sizing columns by precision) was implemented in , but not for the untimed part. Pull request
https://bitbucket.org/eschnett/carpet/pull-requests/43/timers-respect-precision-setting-for
implements it for the untimed part as well. A before / after example using this parfile:
ActiveThorns = "
CoordBase
Carpet
CarpetReduce
SymBase
Timers
"
Cactus::cctk_show_schedule = no
Carpet::output_timer_tree_every = 1024
Timers::output_precision = 5
Before:
------------------------------------------------------------------------------------------------------------------
Time Time Imblnc Timer gettimeof getrusage
percent secs percent secs secs
------------------------------------------------------------------------------------------------------------------
100.00000% 0.00226 0.00000% Evolve 0.002257 0.002219 5.844e+06
53.30084% 0.00120 0.00000% |_CallAnalysis 0.001203 0.001184 3.114e+06
27.78024% 0.00063 0.00000% | |_CCTK_ANALYSIS 0.000627 0.000616 1.62e+06
22.46345% 0.00051 0.00000% | | |_CallFunction 0.000507 0.000504 1.318e+06
4.38635% 0.00010 0.00000% | | | |_thorns 9.9e-05 9.6e-05 2.604e+05
18.1% 0.0 | | | |_untimed
5.3% 0.0 | | |_untimed
1.01905% 0.00002 0.00000% | |_CCTK_CHECKPOINT 2.3e-05 2.4e-05 6.385e+04
1.32920% 0.00003 0.00000% | |_CCTK_POSTSTEP 3e-05 3e-05 7.353e+04
2.25964% 0.00005 0.00000% | |_OutputGH 5.1e-05 5e-05 1.199e+05
1.15197% 0.00003 0.00000% | | |_OutputGH 2.6e-05 2.5e-05 2.414e+04
1.1% 0.0 | | |_untimed
20.9% 0.0 | |_untimed
27.64732% 0.00062 0.00000% |_CallEvol 0.000624 0.000616 1.616e+06
1.19628% 0.00003 0.00000% | |_CCTK_EVOL 2.7e-05 2.5e-05 6.141e+04
12.45016% 0.00028 0.00000% | |_CCTK_PRESTEP 0.000281 0.000276 7.335e+05
9.74745% 0.00022 0.00000% | | |_CallFunction 0.00022 0.000216 5.675e+05
1.28489% 0.00003 0.00000% | | | |_thorns 2.9e-05 2.6e-05 7.512e+04
8.5% 0.0 | | | |_untimed
2.7% 0.0 | | |_untimed
1.10767% 0.00003 0.00000% | |_CycleTimeLevels 2.5e-05 2.5e-05 6.917e+04
1.32920% 0.00003 0.00000% | |_Poison 3e-05 3e-05 7.887e+04
11.6% 0.0 | |_untimed
4.38635% 0.00010 0.00000% |_CallRegrid 9.9e-05 9.7e-05 2.591e+05
1.28489% 0.00003 0.00000% | |_CCTK_PREREGRID 2.9e-05 2.8e-05 7.511e+04
1.9% 0.0 | |_untimed
12.1% 0.0 | untimed
------------------------------------------------------------------------------------------------------------------
------------------------------------------------------------------------------------------------------------------
Time Time Imblnc Timer gettimeof getrusage
percent secs percent secs secs
------------------------------------------------------------------------------------------------------------------
100.01987% 0.01007 0.00000% meta mode 0.01007 0.006001 2.61e+07
40.23845% 0.00405 0.00000% |_meta mode 0.004052 0.003985 1.051e+07
2.55340% 0.00026 0.00000% | |_enter_global_mode 0.000257 0.000255 6.809e+05
25.04719% 0.00252 0.00000% | |_global mode 0.002521 0.002476 6.535e+06
1.11277% 0.00011 0.00000% | | |_enter_level_mode 0.000112 0.000112 2.47e+05
15.69796% 0.00158 0.00000% | | |_level(0) 0.00158 0.001541 4.067e+06
7.3% 0.0 | | |_untimed
11.8% 0.0 | |_untimed
59.8% 0.0 | untimed
------------------------------------------------------------------------------------------------------------------
After:
--------------------------------------------------------------------------------------------------------------
Time Time Imblnc Timer gettimeof getrusage
percent secs percent secs secs
--------------------------------------------------------------------------------------------------------------
100.00000% 0.00233 0.00000% Evolve 0.00233 0.001576
49.91416% 0.00116 0.00000% |_CallAnalysis 0.001163 0.000742
27.25322% 0.00064 0.00000% | |_CCTK_ANALYSIS 0.000635 0.000398
21.75966% 0.00051 0.00000% | | |_CallFunction 0.000507 0.000326
4.29185% 0.00010 0.00000% | | | |_thorns 0.0001 6.1e-05
17.46781% 0.00041 | | | |_untimed
5.49356% 0.00013 | | |_untimed
1.20172% 0.00003 0.00000% | |_CCTK_POSTSTEP 2.8e-05 1.6e-05
1.28755% 0.00003 0.00000% | |_OutputGH 3e-05 2e-05
19.22747% 0.00045 | |_untimed
29.57082% 0.00069 0.00000% |_CallEvol 0.000689 0.000488
1.07296% 0.00003 0.00000% | |_CCTK_EVOL 2.5e-05 1.9e-05
12.83262% 0.00030 0.00000% | |_CCTK_PRESTEP 0.000299 0.000218
9.82833% 0.00023 0.00000% | | |_CallFunction 0.000229 0.000164
1.45923% 0.00003 0.00000% | | | |_thorns 3.4e-05 2.7e-05
8.36910% 0.00020 | | | |_untimed
3.00429% 0.00007 | | |_untimed
1.11588% 0.00003 0.00000% | |_CycleTimeLevels 2.6e-05 1.9e-05
1.33047% 0.00003 0.00000% | |_Poison 3.1e-05 2.3e-05
13.21888% 0.00031 | |_untimed
5.06438% 0.00012 0.00000% |_CallRegrid 0.000118 8.9e-05
1.41631% 0.00003 0.00000% | |_CCTK_PREREGRID 3.3e-05 2.6e-05
2.31760% 0.00005 | |_untimed
13.34764% 0.00031 | untimed
--------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------------
Time Time Imblnc Timer gettimeof getrusage
percent secs percent secs secs
--------------------------------------------------------------------------------------------------------------
100.01924% 0.01040 0.00000% meta mode 0.0104 0.009338
40.35594% 0.00419 0.00000% |_meta mode 0.004197 0.003148
2.19336% 0.00023 0.00000% | |_enter_global_mode 0.000228 0.000163
25.35835% 0.00264 0.00000% | |_global mode 0.002636 0.002089
1.06782% 0.00011 0.00000% | | |_leave_level_mode 0.000111 8.9e-05
16.07504% 0.00167 0.00000% | | |_level(0) 0.001671 0.001324
7.24387% 0.00075 | | |_untimed
11.95767% 0.00124 | |_untimed
59.67292% 0.00620 | untimed
--------------------------------------------------------------------------------------------------------------
There remains some hard-coding, namely there is an assumption that the number of seconds will never require more than 6 digits (+ 1 char for the “dot” plus precision) for the integer part, ie fewer than 999999s or about 11.5days. If there is ever a cluster that allows for longer run times than that, then this may need to be adjusted.
Please review.
Unless objected I will apply this after 2021-03-10.