- changed status to open
- removed comment
Improve output format of Carpet timer trees
Issue #1232
resolved
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:
Comments (8)
-
reporter
-
- changed status to open
- removed comment
Please apply
-
reporter
- removed comment
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 ;)
-
- changed status to open
- removed comment
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-forimplements 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 = 5Before:
------------------------------------------------------------------------------------------------------------------ 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.
-
-
- edited description
- changed status to resolved
- Log in to comment
