1 /*============================================================================
2 * Application timer statistics and graphs
3 *============================================================================*/
4
5 /*
6 This file is part of Code_Saturne, a general-purpose CFD tool.
7
8 Copyright (C) 1998-2021 EDF S.A.
9
10 This program is free software; you can redistribute it and/or modify it under
11 the terms of the GNU General Public License as published by the Free Software
12 Foundation; either version 2 of the License, or (at your option) any later
13 version.
14
15 This program is distributed in the hope that it will be useful, but WITHOUT
16 ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
17 FOR A PARTICULAR PURPOSE. See the GNU General Public License for more
18 details.
19
20 You should have received a copy of the GNU General Public License along with
21 this program; if not, write to the Free Software Foundation, Inc., 51 Franklin
22 Street, Fifth Floor, Boston, MA 02110-1301, USA.
23 */
24
25 /*----------------------------------------------------------------------------*/
26
27 #if defined(HAVE_CONFIG_H)
28 # include "cs_config.h"
29 #endif
30
31 #if defined(HAVE_CLOCK_GETTIME)
32 #if !defined(_POSIX_C_SOURCE)
33 #define _POSIX_C_SOURCE 200112L
34 #endif
35 #endif
36
37 /*-----------------------------------------------------------------------------*/
38
39 #include "cs_defs.h"
40
41 /*----------------------------------------------------------------------------
42 * Standard C library headers
43 *----------------------------------------------------------------------------*/
44
45 #include <math.h>
46 #include <string.h>
47 #include <time.h>
48
49 /*----------------------------------------------------------------------------
50 * Local headers
51 *----------------------------------------------------------------------------*/
52
53 #include "bft_error.h"
54 #include "bft_mem.h"
55
56 #include "cs_map.h"
57 #include "cs_timer.h"
58 #include "cs_time_plot.h"
59
60 /*----------------------------------------------------------------------------
61 * Header for the current file
62 *----------------------------------------------------------------------------*/
63
64 #include "cs_timer_stats.h"
65
66 /*----------------------------------------------------------------------------*/
67
68 BEGIN_C_DECLS
69
70 /*=============================================================================
71 * Additional doxygen documentation
72 *============================================================================*/
73
74 /*!
75 \file cs_timer_stats.c
76 Application timer statistics and graphs.
77
78 These statistics are intended to provide a synthetic view of the relative
79 costs of various operations and stages, and are defined as sets of trees
80 so as to allow a form of grouping.
81
82 This logic does not replace having specific timers for operators,
83 which allow for more detail, but more difficult to provide an overview for.
84 Timer statistics also allow for incrementing results from base timers
85 (in addition to starting/stopping their own timers), so they may be used
86 to assist logging and plotting of other timers.
87 */
88
89 /*! \cond DOXYGEN_SHOULD_SKIP_THIS */
90
91 /*-----------------------------------------------------------------------------
92 * Local type definitions
93 *-----------------------------------------------------------------------------*/
94
95 /* Field key definitions */
96
97 typedef struct {
98
99 char *label; /* Associated label */
100
101 int root_id; /* Parent id */
102 int parent_id; /* Parent id */
103
104 bool plot; /* true if plot desired */
105 bool active; /* true if active, false otherwise */
106 cs_timer_t t_start; /* Start time if active */
107
108 cs_timer_counter_t t_cur; /* Counter since last output */
109 cs_timer_counter_t t_tot; /* Total time counter */
110
111 } cs_timer_stats_t;
112
113 /*-------------------------------------------------------------------------------
114 * Local macro documentation
115 *-----------------------------------------------------------------------------*/
116
117 /*-----------------------------------------------------------------------------
118 * Local static variable definitions
119 *-----------------------------------------------------------------------------*/
120
121 /* timer options */
122
123 static int _plot_frequency = 1;
124 static int _plot_buffer_steps = -1;
125 static double _plot_flush_wtime = 3600;
126 static cs_time_plot_format_t _plot_format = CS_TIME_PLOT_CSV;
127
128 /* Timer status */
129
130 static int _time_id = -1, _start_time_id = -1;
131 static int _n_roots = 0;
132 static int *_active_id = NULL;
133 static cs_time_plot_t *_time_plot = NULL;
134
135 /* Field definitions */
136
137 static int _n_stats = 0;
138 static int _n_stats_max = 0;
139 static cs_timer_stats_t *_stats= NULL;
140
141 static cs_map_name_to_id_t *_name_map = NULL;
142
143 /*============================================================================
144 * Private function definitions
145 *============================================================================*/
146
147 /*----------------------------------------------------------------------------
148 * Check if a timer is a parent of another
149 *
150 * parameters:
151 * id_0 <-- id of statistic 0
152 * id_1 <-- id of statistic 1
153 *
154 * return:
155 * true if id_0 is a parent of id_1
156 *----------------------------------------------------------------------------*/
157
158 static inline bool
_is_parent(int id_0,int id_1)159 _is_parent(int id_0,
160 int id_1)
161 {
162 bool retval = false;
163
164 if (id_0 < 0 || id_0 == id_1)
165 retval = true;
166 else if (id_0 > id_1)
167 retval = false;
168
169 else {
170 cs_timer_stats_t *s = _stats + id_1;
171 while (s->parent_id > -1) {
172 if (s->parent_id == id_0) {
173 retval = true;
174 break;
175 }
176 else
177 s = _stats + s->parent_id;
178 }
179 }
180
181 return retval;
182 }
183
184 /*----------------------------------------------------------------------------
185 * Return common parent id of two statistics
186 *
187 * parameters:
188 * id_0 <-- id of statistic 0
189 * id_1 <-- id of statistic 1
190 *
191 * return:
192 * common parent id of two statistics
193 *----------------------------------------------------------------------------*/
194
195 static inline int
_common_parent_id(int id_0,int id_1)196 _common_parent_id(int id_0,
197 int id_1)
198 {
199 int p0 = id_0, p1 = id_1;
200
201 while (p0 != p1 && p0 > -1 && p1 > -1) {
202 if (p0 < p1)
203 p1 = (_stats + p1)->parent_id;
204 else
205 p0 = (_stats + p0)->parent_id;
206 }
207
208 if (p0 != p1)
209 p0 = -1;
210
211 return p0;
212 }
213
214 /*----------------------------------------------------------------------------
215 * Create time plots
216 *----------------------------------------------------------------------------*/
217
218 static void
_build_time_plot(void)219 _build_time_plot(void)
220 {
221 const char **stats_labels;
222 BFT_MALLOC(stats_labels, _n_stats, const char *);
223
224 int stats_count = 0;
225
226 for (int stats_id = 0; stats_id < _n_stats; stats_id++) {
227 cs_timer_stats_t *s = _stats + stats_id;
228 if (s->plot) {
229 stats_labels[stats_count] = s->label;
230 stats_count++;
231 }
232 }
233
234 if (stats_count > 0)
235 _time_plot = cs_time_plot_init_probe("timer_stats",
236 "",
237 _plot_format,
238 true,
239 _plot_flush_wtime,
240 _plot_buffer_steps,
241 stats_count,
242 NULL,
243 NULL,
244 stats_labels);
245
246 BFT_FREE(stats_labels);
247 }
248
249 /*----------------------------------------------------------------------------
250 * Output time plots
251 *----------------------------------------------------------------------------*/
252
253 static void
_output_time_plot(void)254 _output_time_plot(void)
255 {
256 cs_real_t *vals;
257 BFT_MALLOC(vals, _n_stats, cs_real_t);
258
259 int stats_count = 0;
260
261 for (int stats_id = 0; stats_id < _n_stats; stats_id++) {
262
263 cs_timer_stats_t *s = _stats + stats_id;
264 if (s->plot) {
265 vals[stats_count] = s->t_cur.nsec*1e-9;
266 stats_count++;
267 }
268
269 }
270
271 cs_time_plot_vals_write(_time_plot,
272 _time_id,
273 -1.,
274 stats_count,
275 vals);
276
277 BFT_FREE(vals);
278 }
279
280 /*! (DOXYGEN_SHOULD_SKIP_THIS) \endcond */
281
282 /*============================================================================
283 * Public function definitions
284 *============================================================================*/
285
286 /*----------------------------------------------------------------------------*/
287 /*!
288 * \brief Initialize timer statistics handling.
289 *
290 * This creates 2 statistic timer trees, whose roots ids are:
291 * - 0 for computational operations
292 * - 1 for computational stages
293 */
294 /*----------------------------------------------------------------------------*/
295
296 void
cs_timer_stats_initialize(void)297 cs_timer_stats_initialize(void)
298 {
299 int id;
300
301 _time_id = 0;
302 _start_time_id = 0;
303
304 if (_name_map != NULL)
305 cs_timer_stats_finalize();
306
307 _name_map = cs_map_name_to_id_create();
308
309 id = cs_timer_stats_create(NULL, "operations", "total");
310 cs_timer_stats_start(id);
311
312 id = cs_timer_stats_create(NULL, "stages", "total");
313 cs_timer_stats_start(id);
314 cs_timer_stats_set_plot(id, 0);
315
316 }
317
318 /*----------------------------------------------------------------------------*/
319 /*!
320 * \brief Finalize timer statistics handling.
321 */
322 /*----------------------------------------------------------------------------*/
323
324 void
cs_timer_stats_finalize(void)325 cs_timer_stats_finalize(void)
326 {
327 cs_timer_stats_increment_time_step();
328
329 if (_time_plot != NULL)
330 cs_time_plot_finalize(&_time_plot);
331
332 _time_id = -1;
333
334 for (int stats_id = 0; stats_id < _n_stats; stats_id++) {
335 cs_timer_stats_t *s = _stats + stats_id;
336 BFT_FREE(s->label);
337 }
338
339 BFT_FREE(_stats);
340
341 BFT_FREE(_active_id);
342 _n_roots = 0;
343
344 cs_map_name_to_id_destroy(&_name_map);
345
346 _n_stats = 0;
347 _n_stats_max = 0;
348 }
349
350 /*----------------------------------------------------------------------------*/
351 /*!
352 * \brief Set a start time for time stats.
353 *
354 * This is useful to shift the time id for restarts. This function must
355 * not be called after \ref cs_timer_stats_increment_time_step.
356 *
357 * \param[in] time_id associated starting time id
358 */
359 /*----------------------------------------------------------------------------*/
360
361 void
cs_timer_stats_set_start_time(int time_id)362 cs_timer_stats_set_start_time(int time_id)
363 {
364 if (_time_id <= 0 && _start_time_id <= 0) {
365 _time_id = time_id;
366 _start_time_id = time_id;
367 }
368 }
369
370 /*----------------------------------------------------------------------------*/
371 /*!
372 * \brief Set global timer statistics plot options.
373 *
374 * This function is only effective before the first call to
375 * \ref cs_timer_stats_increment_time_step.
376 *
377 * \param[in] format associated file format
378 * \param[in] frequency plot every n time steps
379 * \param[in] n_buffer_steps number of time steps in output buffer if
380 * file is not to be kept open
381 * \param[in] flush_wtime elapsed time interval between file flushes
382 * (if < 0, no forced flush)
383 */
384 /*----------------------------------------------------------------------------*/
385
386 void
cs_timer_stats_set_plot_options(cs_time_plot_format_t format,int frequency,int n_buffer_steps,double flush_wtime)387 cs_timer_stats_set_plot_options(cs_time_plot_format_t format,
388 int frequency,
389 int n_buffer_steps,
390 double flush_wtime)
391 {
392 _plot_format = format;
393
394 _plot_frequency = frequency;
395 _plot_buffer_steps = n_buffer_steps;
396 _plot_flush_wtime = flush_wtime;
397 }
398
399 /*----------------------------------------------------------------------------*/
400 /*!
401 * \brief Increment time step for timer statistics.
402 */
403 /*----------------------------------------------------------------------------*/
404
405 void
cs_timer_stats_increment_time_step(void)406 cs_timer_stats_increment_time_step(void)
407 {
408 cs_timer_t t_incr = cs_timer_time();
409
410 /* Update start and current time for active statistics
411 (should be only root statistics if used properly) */
412
413 for (int stats_id = 0; stats_id < _n_stats; stats_id++) {
414 cs_timer_stats_t *s = _stats + stats_id;
415 if (s->active) {
416 cs_timer_counter_add_diff(&(s->t_cur), &(s->t_start), &t_incr);
417 s->t_start = t_incr;
418 }
419 }
420
421 /* Now output data */
422
423 if ( _time_plot == NULL && _time_id < _start_time_id + 1
424 && cs_glob_rank_id < 1)
425 _build_time_plot();
426
427 if (_time_id % _plot_frequency == 0) {
428
429 if (_time_plot != NULL)
430 _output_time_plot();
431
432 for (int stats_id = 0; stats_id < _n_stats; stats_id++) {
433 cs_timer_stats_t *s = _stats + stats_id;
434 CS_TIMER_COUNTER_ADD(s->t_tot, s->t_tot, s->t_cur);
435 CS_TIMER_COUNTER_INIT(s->t_cur);
436 }
437
438 }
439
440 _time_id += 1;
441 }
442
443 /*----------------------------------------------------------------------------*/
444 /*!
445 * \brief Create a timer statistics structure.
446 *
447 * \param[in] parent_name name of parent statistic, or NULL
448 * \param[in] name associated canonical name
449 * \param[in] label associated label, or NULL
450 *
451 * \return id of new timer stats structure
452 */
453 /*----------------------------------------------------------------------------*/
454
455 int
cs_timer_stats_create(const char * parent_name,const char * name,const char * label)456 cs_timer_stats_create(const char *parent_name,
457 const char *name,
458 const char *label)
459 {
460 /* Determine parent id, create new series if none */
461
462 const char *_parent_name = NULL;
463 int parent_id = -1;
464 int root_id = -1;
465
466 if (parent_name != NULL) {
467 if (strlen(parent_name) > 0)
468 _parent_name = parent_name;
469 }
470
471 if (_parent_name == NULL) {
472 BFT_REALLOC(_active_id, _n_roots+1, int);
473 _active_id[_n_roots] = -1;
474 root_id = _n_roots;
475 _n_roots += 1;
476 }
477 else {
478 parent_id = cs_map_name_to_id_try(_name_map, parent_name);
479 if (parent_id < 0)
480 bft_error(__FILE__, __LINE__, 0,
481 _("Timer statistics \"%s\"\n"
482 " parent \"%s\" not defined."),
483 name, parent_name);
484 }
485
486 cs_timer_stats_t *s;
487
488 /* Insert entry in map */
489
490 int stats_id = cs_map_name_to_id(_name_map, name);
491
492 if (stats_id < _n_stats) {
493 s = _stats + stats_id;
494 bft_error(__FILE__, __LINE__, 0,
495 _("Timer statistics \"%s\"\n"
496 " is already defined, with id %d and parent %d."),
497 name, stats_id, s->parent_id);
498 }
499 else
500 _n_stats = stats_id + 1;
501
502 /* Reallocate pointers if necessary */
503
504 if (_n_stats > _n_stats_max) {
505 if (_n_stats_max == 0)
506 _n_stats_max = 8;
507 else
508 _n_stats_max *= 2;
509 BFT_REALLOC(_stats, _n_stats_max, cs_timer_stats_t);
510 }
511
512 /* Now build new statistics */
513
514 s = _stats + stats_id;
515
516 s->label = NULL;
517 if (label != NULL) {
518 size_t l_len = strlen(label);
519 if (l_len > 0) {
520 BFT_MALLOC(s->label, l_len + 1, char);
521 strcpy(s->label, label);
522 }
523 }
524 if (s->label == NULL) {
525 BFT_MALLOC(s->label, strlen(name) + 1, char);
526 strcpy(s->label, name);
527 }
528
529 s->parent_id = parent_id;
530 if (root_id < 0)
531 s->root_id = (_stats + parent_id)->root_id;
532 else
533 s->root_id = root_id;
534
535 s->plot = true;
536 s->active = false;
537
538 CS_TIMER_COUNTER_INIT(s->t_cur);
539 CS_TIMER_COUNTER_INIT(s->t_tot);
540
541 return stats_id;
542 }
543
544 /*----------------------------------------------------------------------------*/
545 /*!
546 * \brief Return the id of a defined statistic based on its name.
547 *
548 * If no timer with the given name exists, -1 is returned.
549 *
550 * \param[in] name statitic name
551 *
552 * \return id of the statistic, or -1 if not found
553 */
554 /*----------------------------------------------------------------------------*/
555
556 int
cs_timer_stats_id_by_name(const char * name)557 cs_timer_stats_id_by_name(const char *name)
558 {
559 return cs_map_name_to_id_try(_name_map, name);
560 }
561
562 /*----------------------------------------------------------------------------*/
563 /*!
564 * \brief Enable or disable plotting for a timer statistic.
565 *
566 * By default plotting is enabled for all statistics, except root statistic 1
567 * (as it measures the same total time as root 0, with a different subtree).
568 *
569 * This function is only effective before the first call to
570 * \ref cs_timer_stats_increment_time_step.
571 *
572 * \param[in] id id of statistic
573 * \param[in] plot 0 to disable, 1 to enable
574 */
575 /*----------------------------------------------------------------------------*/
576
577 void
cs_timer_stats_set_plot(int id,int plot)578 cs_timer_stats_set_plot(int id,
579 int plot)
580 {
581 if (id < 0 || id > _n_stats || _time_plot != NULL) return;
582
583 cs_timer_stats_t *s = _stats + id;
584 s->plot = (plot != 0) ? true : false;
585 }
586
587 /*----------------------------------------------------------------------------*/
588 /*!
589 * \brief indicate if a timer for a given statistic is currently active.
590 *
591 * \param[in] id id of statistic
592 *
593 * \return 1 if active, 0 otherwise
594 */
595 /*----------------------------------------------------------------------------*/
596
597 int
cs_timer_stats_is_active(int id)598 cs_timer_stats_is_active(int id)
599 {
600 int retval = 0;
601 if (id >= 0 && id < _n_stats) {
602 cs_timer_stats_t *s = _stats + id;
603 if (s->active)
604 retval = 1;
605 }
606 return retval;
607 }
608
609 /*----------------------------------------------------------------------------*/
610 /*!
611 * \brief Start a timer for a given statistic.
612 *
613 * Parents of the current statistic are also started, if not active.
614 *
615 * If a timer with the same root but different parents is active, we assume
616 * the current operation is a subset of the active timer, so the timer is
617 * not started, so as to avoid having a sum of parts larger than the total.
618 *
619 * \param[in] id id of statistic
620 */
621 /*----------------------------------------------------------------------------*/
622
623 void
cs_timer_stats_start(int id)624 cs_timer_stats_start(int id)
625 {
626 if (id < 0 || id > _n_stats) return;
627
628 cs_timer_stats_t *s = _stats + id;
629
630 cs_timer_t t_start = cs_timer_time();
631
632 const int root_id = s->root_id;
633
634 /* If a timer with the same root but different parents is active,
635 simply return */
636
637 if (! _is_parent(_active_id[root_id], id))
638 return;
639
640 int parent_id = _common_parent_id(id, _active_id[root_id]);
641
642 /* Start timer and inactive parents */
643
644 for (int p_id = id; p_id > parent_id; p_id = (_stats + p_id)->parent_id) {
645
646 s = _stats + p_id;
647
648 if (s->active == false) {
649 s->active = true;
650 s->t_start = t_start;
651 }
652
653 }
654
655 _active_id[root_id] = id;
656 }
657
658 /*----------------------------------------------------------------------------*/
659 /*!
660 * \brief Stop a timer for a given statistic.
661 *
662 * Children of the current statistic are also stopped, if active.
663 *
664 * \param[in] id id of statistic
665 */
666 /*----------------------------------------------------------------------------*/
667
668 void
cs_timer_stats_stop(int id)669 cs_timer_stats_stop(int id)
670 {
671 if (id < 0 || id > _n_stats) return;
672
673 cs_timer_stats_t *s = _stats + id;
674
675 cs_timer_t t_stop = cs_timer_time();
676
677 /* Stop timer and active children */
678
679 const int root_id = s->root_id;
680
681 while (_is_parent(id, _active_id[root_id])) {
682
683 s = _stats + _active_id[root_id];
684
685 if (s->active == true) {
686 s->active = false;
687 _active_id[root_id] = s->parent_id;
688 cs_timer_counter_add_diff(&(s->t_cur), &(s->t_start), &t_stop);
689 }
690
691 }
692 }
693
694 /*----------------------------------------------------------------------------*/
695 /*!
696 * \brief Start a timer for a given statistic, stopping previous timers
697 * of the same type which are not a parent, and starting inactive
698 * parent timers if necessary.
699 *
700 * \param[in] id id of statistic with same root
701 *
702 * \return id of previously active statistic, or -1 in case of error
703 */
704 /*----------------------------------------------------------------------------*/
705
706 int
cs_timer_stats_switch(int id)707 cs_timer_stats_switch(int id)
708 {
709 int retval = -1;
710
711 if (id < 0 || id > _n_stats) return retval;
712
713 cs_timer_stats_t *s = _stats + id;
714
715 cs_timer_t t_switch = cs_timer_time();
716
717 const int root_id = s->root_id;
718
719 retval = _active_id[root_id];
720
721 if (_active_id[root_id] == id)
722 return retval; /* Nothing to do, already current */
723
724 int parent_id = _common_parent_id(id, _active_id[root_id]);
725
726 /* Stop all active timers of same type which are lower level than the
727 common parent. */
728
729 while (parent_id != _active_id[root_id]) {
730
731 s = _stats + _active_id[root_id];
732
733 if (s->active == true) {
734 s->active = false;
735 _active_id[root_id] = s->parent_id;
736 cs_timer_counter_add_diff(&(s->t_cur), &(s->t_start), &t_switch);
737 }
738
739 }
740
741 /* Start all inactive timers of the same type which are lower level
742 than the common parent */
743
744 for (int p_id = id; p_id > parent_id; p_id = (_stats + p_id)->parent_id) {
745
746 s = _stats + p_id;
747
748 if (s->active == false) {
749 s->active = true;
750 s->t_start = t_switch;
751 }
752
753 }
754
755 _active_id[root_id] = id;
756
757 return retval;
758 }
759
760 /*----------------------------------------------------------------------------*/
761 /*!
762 * \brief Add a timing range to an inactive timer.
763 *
764 * This does not modify parent timers, so consistency of active and inactive
765 * timers must be ensured by the caller.
766 *
767 * \param[in] id id of statistic
768 * \param[in] t0 oldest timer value
769 * \param[in] t1 most recent timer value
770 */
771 /*----------------------------------------------------------------------------*/
772
773 void
cs_timer_stats_add_diff(int id,const cs_timer_t * t0,const cs_timer_t * t1)774 cs_timer_stats_add_diff(int id,
775 const cs_timer_t *t0,
776 const cs_timer_t *t1)
777 {
778 if (id < 0 || id > _n_stats) return;
779
780 cs_timer_stats_t *s = _stats + id;
781
782 if (s->active == false)
783 cs_timer_counter_add_diff(&(s->t_cur), t0, t1);
784 }
785
786 /*----------------------------------------------------------------------------*/
787 /*!
788 * \brief Define default timer statistics
789 *
790 * This creates 2 statistic timer trees, whose roots ids are:
791 * - 0 for computational operations
792 * - 1 for computational stages
793 */
794 /*----------------------------------------------------------------------------*/
795
796 void
cs_timer_stats_define_defaults(void)797 cs_timer_stats_define_defaults(void)
798 {
799 int id;
800
801 /* Operations */
802
803 cs_timer_stats_create("operations",
804 "mesh_processing",
805 "mesh processing");
806
807 id = cs_timer_stats_create("mesh_processing",
808 "mesh_io",
809 "mesh io");
810 cs_timer_stats_set_plot(id, 0);
811
812 id = cs_timer_stats_create("operations",
813 "postprocessing_output",
814 "post-processing output");
815 cs_timer_stats_set_plot(id, 0);
816
817 /* Stages */
818
819 id = cs_timer_stats_create ("stages",
820 "checkpoint_restart_stage",
821 "checkpoint/restart");
822
823 id = cs_timer_stats_create("stages",
824 "postprocessing_stage",
825 "post-processing");
826 }
827
828 /*-----------------------------------------------------------------------------*/
829
830 END_C_DECLS
831