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