1/* Timing variables for measuring compiler performance.
2 Copyright (C) 2000-2023 Free Software Foundation, Inc.
3 Contributed by Alex Samuel <samuel@codesourcery.com>
4
5This file is part of GCC.
6
7GCC is free software; you can redistribute it and/or modify it under
8the terms of the GNU General Public License as published by the Free
9Software Foundation; either version 3, or (at your option) any later
10version.
11
12GCC is distributed in the hope that it will be useful, but WITHOUT ANY
13WARRANTY; without even the implied warranty of MERCHANTABILITY or
14FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
15for more details.
16
17You should have received a copy of the GNU General Public License
18along with GCC; see the file COPYING3. If not see
19<http://www.gnu.org/licenses/>. */
20
21#include "config.h"
22#include "system.h"
23#include "coretypes.h"
24#include "timevar.h"
25#include "options.h"
26#include "json.h"
27
28#ifndef HAVE_CLOCK_T
29typedef int clock_t;
30#endif
31
32#ifndef HAVE_STRUCT_TMS
33struct tms
34{
35 clock_t tms_utime;
36 clock_t tms_stime;
37 clock_t tms_cutime;
38 clock_t tms_cstime;
39};
40#endif
41
42#ifndef RUSAGE_SELF
43# define RUSAGE_SELF 0
44#endif
45
46/* Calculation of scale factor to convert ticks to seconds.
47 We mustn't use CLOCKS_PER_SEC except with clock(). */
48#if HAVE_SYSCONF && defined _SC_CLK_TCK
49# define TICKS_PER_SECOND sysconf (_SC_CLK_TCK) /* POSIX 1003.1-1996 */
50#else
51# ifdef CLK_TCK
52# define TICKS_PER_SECOND CLK_TCK /* POSIX 1003.1-1988; obsolescent */
53# else
54# ifdef HZ
55# define TICKS_PER_SECOND HZ /* traditional UNIX */
56# else
57# define TICKS_PER_SECOND 100 /* often the correct value */
58# endif
59# endif
60#endif
61
62/* Prefer times to getrusage to clock (each gives successively less
63 information). */
64#ifdef HAVE_TIMES
65# if defined HAVE_DECL_TIMES && !HAVE_DECL_TIMES
66 extern clock_t times (struct tms *);
67# endif
68# define USE_TIMES
69# define HAVE_USER_TIME
70# define HAVE_SYS_TIME
71# define HAVE_WALL_TIME
72#else
73#ifdef HAVE_GETRUSAGE
74# if defined HAVE_DECL_GETRUSAGE && !HAVE_DECL_GETRUSAGE
75 extern int getrusage (int, struct rusage *);
76# endif
77# define USE_GETRUSAGE
78# define HAVE_USER_TIME
79# define HAVE_SYS_TIME
80#else
81#ifdef HAVE_CLOCK
82# if defined HAVE_DECL_CLOCK && !HAVE_DECL_CLOCK
83 extern clock_t clock (void);
84# endif
85# define USE_CLOCK
86# define HAVE_USER_TIME
87#endif
88#endif
89#endif
90
91/* libc is very likely to have snuck a call to sysconf() into one of
92 the underlying constants, and that can be very slow, so we have to
93 precompute them. Whose wonderful idea was it to make all those
94 _constants_ variable at run time, anyway? */
95#define NANOSEC_PER_SEC 1000000000
96#ifdef USE_TIMES
97static uint64_t ticks_to_nanosec;
98#define TICKS_TO_NANOSEC (NANOSEC_PER_SEC / TICKS_PER_SECOND)
99#endif
100
101#ifdef USE_CLOCK
102static uint64_t clocks_to_nanosec;
103#define CLOCKS_TO_NANOSEC (NANOSEC_PER_SEC / CLOCKS_PER_SEC)
104#endif
105
106/* Non-NULL if timevars should be used. In GCC, this happens with
107 the -ftime-report flag. */
108
109timer *g_timer;
110
111/* Total amount of memory allocated by garbage collector. */
112
113size_t timevar_ggc_mem_total;
114
115/* The amount of memory that will cause us to report the timevar even
116 if the time spent is not significant. */
117
118#define GGC_MEM_BOUND (1 << 20)
119
120/* See timevar.h for an explanation of timing variables. */
121
122static void get_time (struct timevar_time_def *);
123static void timevar_accumulate (struct timevar_time_def *,
124 struct timevar_time_def *,
125 struct timevar_time_def *);
126
127/* The implementation of timing events for jit client code, allowing
128 arbitrary named items to appear on the timing stack. */
129
130class timer::named_items
131{
132 public:
133 named_items (timer *t);
134 ~named_items ();
135
136 void push (const char *item_name);
137 void pop ();
138 void print (FILE *fp, const timevar_time_def *total);
139
140 json::value *make_json () const;
141
142 private:
143 /* Which timer instance does this relate to? */
144 timer *m_timer;
145
146 /* Dictionary, mapping from item names to timevar_def.
147 Note that currently we merely store/compare the raw string
148 pointers provided by client code; we don't take a copy,
149 or use strcmp. */
150 typedef hash_map <const char *, timer::timevar_def> hash_map_t;
151 hash_map_t m_hash_map;
152
153 /* The order in which items were originally inserted. */
154 auto_vec <const char *> m_names;
155};
156
157/* The constructor for class timer::named_items. */
158
159timer::named_items::named_items (timer *t)
160: m_timer (t),
161 m_hash_map (),
162 m_names ()
163{
164}
165
166/* The destructor for class timer::named_items. */
167
168timer::named_items::~named_items ()
169{
170}
171
172/* Push the named item onto the timer stack. */
173
174void
175timer::named_items::push (const char *item_name)
176{
177 gcc_assert (item_name);
178
179 bool existed;
180 timer::timevar_def *def = &m_hash_map.get_or_insert (k: item_name, existed: &existed);
181 if (!existed)
182 {
183 def->elapsed.user = 0;
184 def->elapsed.sys = 0;
185 def->elapsed.wall = 0;
186 def->name = item_name;
187 def->standalone = 0;
188 m_names.safe_push (obj: item_name);
189 }
190 m_timer->push_internal (tv: def);
191}
192
193/* Pop the top item from the timer stack. */
194
195void
196timer::named_items::pop ()
197{
198 m_timer->pop_internal ();
199}
200
201/* Print the given client item. Helper function for timer::print. */
202
203void
204timer::named_items::print (FILE *fp, const timevar_time_def *total)
205{
206 fprintf (stream: fp, format: "Client items:\n");
207 for (const char *item_name : m_names)
208 {
209 timer::timevar_def *def = m_hash_map.get (k: item_name);
210 gcc_assert (def);
211 m_timer->print_row (fp, total, name: def->name, elapsed: def->elapsed);
212 }
213}
214
215/* Create a json value representing this object, suitable for use
216 in SARIF output. */
217
218json::value *
219timer::named_items::make_json () const
220{
221 json::array *arr = new json::array ();
222 for (const char *item_name : m_names)
223 {
224 hash_map_t &mut_map = const_cast <hash_map_t &> (m_hash_map);
225 timer::timevar_def *def = mut_map.get (k: item_name);
226 gcc_assert (def);
227 arr->append (v: def->make_json ());
228 }
229 return arr;
230}
231
232/* Fill the current times into TIME. The definition of this function
233 also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
234 HAVE_WALL_TIME macros. */
235
236static void
237get_time (struct timevar_time_def *now)
238{
239 now->user = 0;
240 now->sys = 0;
241 now->wall = 0;
242 now->ggc_mem = timevar_ggc_mem_total;
243
244 {
245#ifdef USE_TIMES
246 struct tms tms;
247 now->wall = times (buffer: &tms) * ticks_to_nanosec;
248 now->user = tms.tms_utime * ticks_to_nanosec;
249 now->sys = tms.tms_stime * ticks_to_nanosec;
250#endif
251#ifdef USE_GETRUSAGE
252 struct rusage rusage;
253 getrusage (RUSAGE_SELF, &rusage);
254 now->user = rusage.ru_utime.tv_sec * NANOSEC_PER_SEC
255 + rusage.ru_utime.tv_usec * 1000;
256 now->sys = rusage.ru_stime.tv_sec * NANOSEC_PER_SEC
257 + rusage.ru_stime.tv_usec * 1000;
258#endif
259#ifdef USE_CLOCK
260 now->user = clock () * clocks_to_nanosec;
261#endif
262 }
263}
264
265/* Add the difference between STOP_TIME and START_TIME to TIMER. */
266
267static void
268timevar_accumulate (struct timevar_time_def *timer,
269 struct timevar_time_def *start_time,
270 struct timevar_time_def *stop_time)
271{
272 timer->user += stop_time->user - start_time->user;
273 timer->sys += stop_time->sys - start_time->sys;
274 timer->wall += stop_time->wall - start_time->wall;
275 timer->ggc_mem += stop_time->ggc_mem - start_time->ggc_mem;
276}
277
278/* Get the difference between STOP_TIME and START_TIME. */
279
280static void
281timevar_diff (struct timevar_time_def *out,
282 const timevar_time_def &start_time,
283 const timevar_time_def &stop_time)
284{
285 out->user = stop_time.user - start_time.user;
286 out->sys = stop_time.sys - start_time.sys;
287 out->wall = stop_time.wall - start_time.wall;
288 out->ggc_mem = stop_time.ggc_mem - start_time.ggc_mem;
289}
290
291/* Class timer's constructor. */
292
293timer::timer () :
294 m_stack (NULL),
295 m_unused_stack_instances (NULL),
296 m_start_time (),
297 m_jit_client_items (NULL)
298{
299 /* Zero all elapsed times. */
300 memset (s: m_timevars, c: 0, n: sizeof (m_timevars));
301
302 /* Initialize the names of timing variables. */
303#define DEFTIMEVAR(identifier__, name__) \
304 m_timevars[identifier__].name = name__;
305#include "timevar.def"
306#undef DEFTIMEVAR
307
308 /* Initialize configuration-specific state.
309 Ideally this would be one-time initialization. */
310#ifdef USE_TIMES
311 ticks_to_nanosec = TICKS_TO_NANOSEC;
312#endif
313#ifdef USE_CLOCK
314 clocks_to_nanosec = CLOCKS_TO_NANOSEC;
315#endif
316}
317
318/* Class timer's destructor. */
319
320timer::~timer ()
321{
322 timevar_stack_def *iter, *next;
323
324 for (iter = m_stack; iter; iter = next)
325 {
326 next = iter->next;
327 free (ptr: iter);
328 }
329 for (iter = m_unused_stack_instances; iter; iter = next)
330 {
331 next = iter->next;
332 free (ptr: iter);
333 }
334 for (unsigned i = 0; i < TIMEVAR_LAST; ++i)
335 delete m_timevars[i].children;
336
337 delete m_jit_client_items;
338}
339
340/* Initialize timing variables. */
341
342void
343timevar_init (void)
344{
345 if (g_timer)
346 return;
347
348 g_timer = new timer ();
349}
350
351/* Push TIMEVAR onto the timing stack. No further elapsed time is
352 attributed to the previous topmost timing variable on the stack;
353 subsequent elapsed time is attributed to TIMEVAR, until it is
354 popped or another element is pushed on top.
355
356 TIMEVAR cannot be running as a standalone timer. */
357
358void
359timer::push (timevar_id_t timevar)
360{
361 struct timevar_def *tv = &m_timevars[timevar];
362 push_internal (tv);
363}
364
365/* Push TV onto the timing stack, either one of the builtin ones
366 for a timevar_id_t, or one provided by client code to libgccjit. */
367
368void
369timer::push_internal (struct timevar_def *tv)
370{
371 struct timevar_stack_def *context;
372 struct timevar_time_def now;
373
374 gcc_assert (tv);
375
376 /* Mark this timing variable as used. */
377 tv->used = 1;
378
379 /* Can't push a standalone timer. */
380 gcc_assert (!tv->standalone);
381
382 /* What time is it? */
383 get_time (now: &now);
384
385 /* If the stack isn't empty, attribute the current elapsed time to
386 the old topmost element. */
387 if (m_stack)
388 timevar_accumulate (timer: &m_stack->timevar->elapsed, start_time: &m_start_time, stop_time: &now);
389
390 /* Reset the start time; from now on, time is attributed to
391 TIMEVAR. */
392 m_start_time = now;
393
394 /* See if we have a previously-allocated stack instance. If so,
395 take it off the list. If not, malloc a new one. */
396 if (m_unused_stack_instances != NULL)
397 {
398 context = m_unused_stack_instances;
399 m_unused_stack_instances = m_unused_stack_instances->next;
400 }
401 else
402 context = XNEW (struct timevar_stack_def);
403
404 /* Fill it in and put it on the stack. */
405 context->timevar = tv;
406 context->next = m_stack;
407 m_stack = context;
408}
409
410/* Pop the topmost timing variable element off the timing stack. The
411 popped variable must be TIMEVAR. Elapsed time since the that
412 element was pushed on, or since it was last exposed on top of the
413 stack when the element above it was popped off, is credited to that
414 timing variable. */
415
416void
417timer::pop (timevar_id_t timevar)
418{
419 gcc_assert (&m_timevars[timevar] == m_stack->timevar);
420
421 pop_internal ();
422}
423
424/* Pop the topmost item from the stack, either one of the builtin ones
425 for a timevar_id_t, or one provided by client code to libgccjit. */
426
427void
428timer::pop_internal ()
429{
430 struct timevar_time_def now;
431 struct timevar_stack_def *popped = m_stack;
432
433 /* What time is it? */
434 get_time (now: &now);
435
436 /* Attribute the elapsed time to the element we're popping. */
437 timevar_accumulate (timer: &popped->timevar->elapsed, start_time: &m_start_time, stop_time: &now);
438
439 /* Take the item off the stack. */
440 m_stack = m_stack->next;
441
442 /* Record the elapsed sub-time to the parent as well. */
443 if (m_stack && time_report_details)
444 {
445 if (! m_stack->timevar->children)
446 m_stack->timevar->children = new child_map_t (5);
447 bool existed_p;
448 timevar_time_def &time
449 = m_stack->timevar->children->get_or_insert (k: popped->timevar, existed: &existed_p);
450 if (! existed_p)
451 memset (s: &time, c: 0, n: sizeof (timevar_time_def));
452 timevar_accumulate (timer: &time, start_time: &m_start_time, stop_time: &now);
453 }
454
455 /* Reset the start time; from now on, time is attributed to the
456 element just exposed on the stack. */
457 m_start_time = now;
458
459 /* Don't delete the stack element; instead, add it to the list of
460 unused elements for later use. */
461 popped->next = m_unused_stack_instances;
462 m_unused_stack_instances = popped;
463}
464
465/* Start timing TIMEVAR independently of the timing stack. Elapsed
466 time until timevar_stop is called for the same timing variable is
467 attributed to TIMEVAR. */
468
469void
470timevar_start (timevar_id_t timevar)
471{
472 if (!g_timer)
473 return;
474
475 g_timer->start (tv: timevar);
476}
477
478/* See timevar_start above. */
479
480void
481timer::start (timevar_id_t timevar)
482{
483 struct timevar_def *tv = &m_timevars[timevar];
484
485 /* Mark this timing variable as used. */
486 tv->used = 1;
487
488 /* Don't allow the same timing variable to be started more than
489 once. */
490 gcc_assert (!tv->standalone);
491 tv->standalone = 1;
492
493 get_time (now: &tv->start_time);
494}
495
496/* Stop timing TIMEVAR. Time elapsed since timevar_start was called
497 is attributed to it. */
498
499void
500timevar_stop (timevar_id_t timevar)
501{
502 if (!g_timer)
503 return;
504
505 g_timer->stop (tv: timevar);
506}
507
508/* See timevar_stop above. */
509
510void
511timer::stop (timevar_id_t timevar)
512{
513 struct timevar_def *tv = &m_timevars[timevar];
514 struct timevar_time_def now;
515
516 /* TIMEVAR must have been started via timevar_start. */
517 gcc_assert (tv->standalone);
518 tv->standalone = 0; /* Enable a restart. */
519
520 get_time (now: &now);
521 timevar_accumulate (timer: &tv->elapsed, start_time: &tv->start_time, stop_time: &now);
522}
523
524
525/* Conditionally start timing TIMEVAR independently of the timing stack.
526 If the timer is already running, leave it running and return true.
527 Otherwise, start the timer and return false.
528 Elapsed time until the corresponding timevar_cond_stop
529 is called for the same timing variable is attributed to TIMEVAR. */
530
531bool
532timevar_cond_start (timevar_id_t timevar)
533{
534 if (!g_timer)
535 return false;
536
537 return g_timer->cond_start (tv: timevar);
538}
539
540/* See timevar_cond_start above. */
541
542bool
543timer::cond_start (timevar_id_t timevar)
544{
545 struct timevar_def *tv = &m_timevars[timevar];
546
547 /* Mark this timing variable as used. */
548 tv->used = 1;
549
550 if (tv->standalone)
551 return true; /* The timevar is already running. */
552
553 /* Don't allow the same timing variable
554 to be unconditionally started more than once. */
555 tv->standalone = 1;
556
557 get_time (now: &tv->start_time);
558 return false; /* The timevar was not already running. */
559}
560
561/* Conditionally stop timing TIMEVAR. The RUNNING parameter must come
562 from the return value of a dynamically matching timevar_cond_start.
563 If the timer had already been RUNNING, do nothing. Otherwise, time
564 elapsed since timevar_cond_start was called is attributed to it. */
565
566void
567timevar_cond_stop (timevar_id_t timevar, bool running)
568{
569 if (!g_timer || running)
570 return;
571
572 g_timer->cond_stop (tv: timevar);
573}
574
575/* See timevar_cond_stop above. */
576
577void
578timer::cond_stop (timevar_id_t timevar)
579{
580 struct timevar_def *tv;
581 struct timevar_time_def now;
582
583 tv = &m_timevars[timevar];
584
585 /* TIMEVAR must have been started via timevar_cond_start. */
586 gcc_assert (tv->standalone);
587 tv->standalone = 0; /* Enable a restart. */
588
589 get_time (now: &now);
590 timevar_accumulate (timer: &tv->elapsed, start_time: &tv->start_time, stop_time: &now);
591}
592
593/* Push the named item onto the timing stack. */
594
595void
596timer::push_client_item (const char *item_name)
597{
598 gcc_assert (item_name);
599
600 /* Lazily create the named_items instance. */
601 if (!m_jit_client_items)
602 m_jit_client_items = new named_items (this);
603
604 m_jit_client_items->push (item_name);
605}
606
607/* Pop the top-most client item from the timing stack. */
608
609void
610timer::pop_client_item ()
611{
612 gcc_assert (m_jit_client_items);
613 m_jit_client_items->pop ();
614}
615
616/* Validate that phase times are consistent. */
617
618void
619timer::validate_phases (FILE *fp) const
620{
621 unsigned int /* timevar_id_t */ id;
622 const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed;
623 uint64_t phase_user = 0;
624 uint64_t phase_sys = 0;
625 uint64_t phase_wall = 0;
626 size_t phase_ggc_mem = 0;
627 static char phase_prefix[] = "phase ";
628
629 for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
630 {
631 const timevar_def *tv = &m_timevars[(timevar_id_t) id];
632
633 /* Don't evaluate timing variables that were never used. */
634 if (!tv->used)
635 continue;
636
637 if (startswith (str: tv->name, prefix: phase_prefix))
638 {
639 phase_user += tv->elapsed.user;
640 phase_sys += tv->elapsed.sys;
641 phase_wall += tv->elapsed.wall;
642 phase_ggc_mem += tv->elapsed.ggc_mem;
643 }
644 }
645
646 if (phase_user > total->user
647 || phase_sys > total->sys
648 || phase_wall > total->wall
649 || phase_ggc_mem > total->ggc_mem)
650 {
651
652 fprintf (stream: fp, format: "Timing error: total of phase timers exceeds total time.\n");
653 if (phase_user > total->user)
654 fprintf (stream: fp, format: "user %13" PRIu64 " > %13" PRIu64 "\n",
655 phase_user, total->user);
656 if (phase_sys > total->sys)
657 fprintf (stream: fp, format: "sys %13" PRIu64 " > %13" PRIu64 "\n",
658 phase_sys, total->sys);
659 if (phase_wall > total->wall)
660 fprintf (stream: fp, format: "wall %13" PRIu64 " > %13" PRIu64 "\n",
661 phase_wall, total->wall);
662 if (phase_ggc_mem > total->ggc_mem)
663 fprintf (stream: fp, format: "ggc_mem %13lu > %13lu\n", (unsigned long)phase_ggc_mem,
664 (unsigned long)total->ggc_mem);
665 gcc_unreachable ();
666 }
667}
668
669#define nanosec_to_floating_sec(NANO) ((double)(NANO) * 1e-9)
670#define percent_of(TOTAL, SUBTOTAL) \
671 ((TOTAL) == 0 ? 0 : ((double)SUBTOTAL / TOTAL) * 100)
672/* Helper function for timer::print. */
673
674void
675timer::print_row (FILE *fp,
676 const timevar_time_def *total,
677 const char *name, const timevar_time_def &elapsed)
678{
679 /* The timing variable name. */
680 fprintf (stream: fp, format: " %-35s:", name);
681
682#ifdef HAVE_USER_TIME
683 /* Print user-mode time for this process. */
684 fprintf (stream: fp, format: "%7.2f (%3.0f%%)",
685 nanosec_to_floating_sec (elapsed.user),
686 percent_of (total->user, elapsed.user));
687#endif /* HAVE_USER_TIME */
688
689#ifdef HAVE_SYS_TIME
690 /* Print system-mode time for this process. */
691 fprintf (stream: fp, format: "%7.2f (%3.0f%%)",
692 nanosec_to_floating_sec (elapsed.sys),
693 percent_of (total->sys, elapsed.sys));
694#endif /* HAVE_SYS_TIME */
695
696#ifdef HAVE_WALL_TIME
697 /* Print wall clock time elapsed. */
698 fprintf (stream: fp, format: "%7.2f (%3.0f%%)",
699 nanosec_to_floating_sec (elapsed.wall),
700 percent_of (total->wall, elapsed.wall));
701#endif /* HAVE_WALL_TIME */
702
703 /* Print the amount of ggc memory allocated. */
704 fprintf (stream: fp, PRsa (6) " (%3.0f%%)",
705 SIZE_AMOUNT (elapsed.ggc_mem),
706 (total->ggc_mem == 0
707 ? 0
708 : (float) elapsed.ggc_mem / total->ggc_mem) * 100);
709
710 putc (c: '\n', stream: fp);
711}
712
713/* Return whether ELAPSED is all zero. */
714
715bool
716timer::all_zero (const timevar_time_def &elapsed)
717{
718 /* 5000000 nanosec == 5e-3 seconds. */
719 uint64_t tiny = 5000000;
720 return (elapsed.user < tiny
721 && elapsed.sys < tiny
722 && elapsed.wall < tiny
723 && elapsed.ggc_mem < GGC_MEM_BOUND);
724}
725
726/* Summarize timing variables to FP. The timing variable TV_TOTAL has
727 a special meaning -- it's considered to be the total elapsed time,
728 for normalizing the others, and is displayed last. */
729
730void
731timer::print (FILE *fp)
732{
733 /* Only print stuff if we have some sort of time information. */
734#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
735 unsigned int /* timevar_id_t */ id;
736 const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed;
737 struct timevar_time_def now;
738
739 /* Update timing information in case we're calling this from GDB. */
740
741 if (fp == 0)
742 fp = stderr;
743
744 /* What time is it? */
745 get_time (now: &now);
746
747 /* If the stack isn't empty, attribute the current elapsed time to
748 the old topmost element. */
749 if (m_stack)
750 timevar_accumulate (timer: &m_stack->timevar->elapsed, start_time: &m_start_time, stop_time: &now);
751
752 /* Reset the start time; from now on, time is attributed to
753 TIMEVAR. */
754 m_start_time = now;
755
756 fprintf (stream: fp, format: "\n%-35s%16s%14s%14s%14s\n", "Time variable", "usr", "sys",
757 "wall", "GGC");
758 if (m_jit_client_items)
759 fputs (s: "GCC items:\n", stream: fp);
760 for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
761 {
762 const timevar_def *tv = &m_timevars[(timevar_id_t) id];
763
764 /* Don't print the total execution time here; that goes at the
765 end. */
766 if ((timevar_id_t) id == TV_TOTAL)
767 continue;
768
769 /* Don't print timing variables that were never used. */
770 if (!tv->used)
771 continue;
772
773 bool any_children_with_time = false;
774 if (tv->children)
775 for (child_map_t::iterator i = tv->children->begin ();
776 i != tv->children->end (); ++i)
777 if (! all_zero (elapsed: (*i).second))
778 {
779 any_children_with_time = true;
780 break;
781 }
782
783 /* Don't print timing variables if we're going to get a row of
784 zeroes. Unless there are children with non-zero time. */
785 if (! any_children_with_time
786 && all_zero (elapsed: tv->elapsed))
787 continue;
788
789 print_row (fp, total, name: tv->name, elapsed: tv->elapsed);
790
791 if (tv->children)
792 for (child_map_t::iterator i = tv->children->begin ();
793 i != tv->children->end (); ++i)
794 {
795 timevar_def *tv2 = (*i).first;
796 /* Don't print timing variables if we're going to get a row of
797 zeroes. */
798 if (! all_zero (elapsed: (*i).second))
799 {
800 char lname[256];
801 snprintf (s: lname, maxlen: 256, format: "`- %s", tv2->name);
802 print_row (fp, total, name: lname, elapsed: (*i).second);
803 }
804 }
805 }
806 if (m_jit_client_items)
807 m_jit_client_items->print (fp, total);
808
809 /* Print total time. */
810 fprintf (stream: fp, format: " %-35s:", "TOTAL");
811#ifdef HAVE_USER_TIME
812 fprintf (stream: fp, format: "%7.2f ", nanosec_to_floating_sec (total->user));
813#endif
814#ifdef HAVE_SYS_TIME
815 fprintf (stream: fp, format: "%8.2f ", nanosec_to_floating_sec (total->sys));
816#endif
817#ifdef HAVE_WALL_TIME
818 fprintf (stream: fp, format: "%8.2f ", nanosec_to_floating_sec (total->wall));
819#endif
820 fprintf (stream: fp, PRsa (7) "\n", SIZE_AMOUNT (total->ggc_mem));
821
822 if (CHECKING_P || flag_checking)
823 fprintf (stream: fp, format: "Extra diagnostic checks enabled; compiler may run slowly.\n");
824 if (CHECKING_P)
825 fprintf (stream: fp, format: "Configure with --enable-checking=release to disable checks.\n");
826#ifndef ENABLE_ASSERT_CHECKING
827 fprintf (fp, "Internal checks disabled; compiler is not suited for release.\n");
828 fprintf (fp, "Configure with --enable-checking=release to enable checks.\n");
829#endif
830
831#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
832 || defined (HAVE_WALL_TIME) */
833
834 validate_phases (fp);
835}
836
837/* Create a json value representing this object, suitable for use
838 in SARIF output. */
839
840json::object *
841make_json_for_timevar_time_def (const timevar_time_def &ttd)
842{
843 json::object *obj = new json::object ();
844 obj->set (key: "user",
845 v: new json::float_number (nanosec_to_floating_sec (ttd.user)));
846 obj->set (key: "sys", v: new json::float_number (nanosec_to_floating_sec (ttd.sys)));
847 obj->set (key: "wall",
848 v: new json::float_number (nanosec_to_floating_sec (ttd.wall)));
849 obj->set (key: "ggc_mem", v: new json::integer_number (ttd.ggc_mem));
850 return obj;
851}
852#undef nanosec_to_floating_sec
853#undef percent_of
854
855/* Create a json value representing this object, suitable for use
856 in SARIF output. */
857
858json::value *
859timer::timevar_def::make_json () const
860{
861 json::object *timevar_obj = new json::object ();
862 timevar_obj->set (key: "name", v: new json::string (name));
863 timevar_obj->set (key: "elapsed", v: make_json_for_timevar_time_def (ttd: elapsed));
864
865 if (children)
866 {
867 bool any_children_with_time = false;
868 for (auto i : *children)
869 if (!all_zero (elapsed: i.second))
870 {
871 any_children_with_time = true;
872 break;
873 }
874 if (any_children_with_time)
875 {
876 json::array *children_arr = new json::array ();
877 timevar_obj->set (key: "children", v: children_arr);
878 for (auto i : *children)
879 {
880 /* Don't emit timing variables if we're going to get a row of
881 zeroes. */
882 if (all_zero (elapsed: i.second))
883 continue;
884 json::object *child_obj = new json::object;
885 children_arr->append (v: child_obj);
886 child_obj->set (key: "name", v: new json::string (i.first->name));
887 child_obj->set (key: "elapsed",
888 v: make_json_for_timevar_time_def (ttd: i.second));
889 }
890 }
891 }
892
893 return timevar_obj;
894}
895
896/* Create a json value representing this object, suitable for use
897 in SARIF output. */
898
899json::value *
900timer::make_json () const
901{
902 /* Only generate stuff if we have some sort of time information. */
903#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
904 json::object *report_obj = new json::object ();
905 json::array *json_arr = new json::array ();
906 report_obj->set (key: "timevars", v: json_arr);
907
908 for (unsigned id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
909 {
910 const timevar_def *tv = &m_timevars[(timevar_id_t) id];
911
912 /* Don't print the total execution time here; this isn't initialized
913 by the time the sarif output runs. */
914 if ((timevar_id_t) id == TV_TOTAL)
915 continue;
916
917 /* Don't emit timing variables that were never used. */
918 if (!tv->used)
919 continue;
920
921 bool any_children_with_time = false;
922 if (tv->children)
923 for (child_map_t::iterator i = tv->children->begin ();
924 i != tv->children->end (); ++i)
925 if (! all_zero (elapsed: (*i).second))
926 {
927 any_children_with_time = true;
928 break;
929 }
930
931 /* Don't emit timing variables if we're going to get a row of
932 zeroes. Unless there are children with non-zero time. */
933 if (! any_children_with_time
934 && all_zero (elapsed: tv->elapsed))
935 continue;
936
937 json_arr->append (v: tv->make_json ());
938 }
939
940 /* Special-case for total. */
941 {
942 /* Get our own total up till now, without affecting TV_TOTAL. */
943 struct timevar_time_def total_now;
944 struct timevar_time_def total_elapsed;
945 get_time (now: &total_now);
946 timevar_diff (out: &total_elapsed, start_time: m_timevars[TV_TOTAL].start_time, stop_time: total_now);
947
948 json::object *total_obj = new json::object();
949 json_arr->append (v: total_obj);
950 total_obj->set (key: "name", v: new json::string ("TOTAL"));
951 total_obj->set (key: "elapsed", v: make_json_for_timevar_time_def (ttd: total_elapsed));
952 }
953
954 if (m_jit_client_items)
955 report_obj->set (key: "client_items", v: m_jit_client_items->make_json ());
956
957 report_obj->set (key: "CHECKING_P", v: new json::literal ((bool)CHECKING_P));
958 report_obj->set (key: "flag_checking", v: new json::literal ((bool)flag_checking));
959
960 return report_obj;
961
962#else /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
963 || defined (HAVE_WALL_TIME) */
964 return NULL;
965#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
966 || defined (HAVE_WALL_TIME) */
967}
968
969/* Get the name of the topmost item. For use by jit for validating
970 inputs to gcc_jit_timer_pop. */
971const char *
972timer::get_topmost_item_name () const
973{
974 if (m_stack)
975 return m_stack->timevar->name;
976 else
977 return NULL;
978}
979
980/* Prints a message to stderr stating that time elapsed in STR is
981 TOTAL (given in microseconds). */
982
983void
984print_time (const char *str, long total)
985{
986 long all_time = get_run_time ();
987 fprintf (stderr,
988 format: "time in %s: %ld.%06ld (%ld%%)\n",
989 str, total / 1000000, total % 1000000,
990 all_time == 0 ? 0
991 : (long) (((100.0 * (double) total) / (double) all_time) + .5));
992}
993

source code of gcc/timevar.cc