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