gcc/timevar.cc

   1 /* Timing variables for measuring compiler performance.
   2    Copyright (C) 2000-2024 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 #ifndef HAVE_CLOCK_T
  29 typedef int clock_t;
  30 #endif
  31
  32 #ifndef HAVE_STRUCT_TMS
  33 struct 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
  97 static uint64_t ticks_to_nanosec;
  98 #define TICKS_TO_NANOSEC (NANOSEC_PER_SEC / TICKS_PER_SECOND)
  99 #endif
 100
 101 #ifdef USE_CLOCK
 102 static 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
 109 timer *g_timer;
 110
 111 /* Total amount of memory allocated by garbage collector.  */
 112
 113 size_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
 122 static void get_time (struct timevar_time_def *);
 123 static 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
 130 class 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
 159 timer::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
 168 timer::named_items::~named_items ()
 169 {
 170 }
 171
 172 /* Push the named item onto the timer stack.  */
 173
 174 void
 175 timer::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 (item_name, &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 (item_name);
 189     }
 190   m_timer->push_internal (def);
 191 }
 192
 193 /* Pop the top item from the timer stack.  */
 194
 195 void
 196 timer::named_items::pop ()
 197 {
 198   m_timer->pop_internal ();
 199 }
 200
 201 /* Print the given client item.  Helper function for timer::print.  */
 202
 203 void
 204 timer::named_items::print (FILE *fp, const timevar_time_def *total)
 205 {
 206   fprintf (fp, "Client items:\n");
 207   for (const char *item_name : m_names)
 208     {
 209       timer::timevar_def *def = m_hash_map.get (item_name);
 210       gcc_assert (def);
 211       m_timer->print_row (fp, total, def->name, def->elapsed);
 212     }
 213 }
 214
 215 /* Create a json value representing this object, suitable for use
 216    in SARIF output.  */
 217
 218 json::value *
 219 timer::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 (item_name);
 226       gcc_assert (def);
 227       arr->append (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
 236 static void
 237 get_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 (&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
 267 static void
 268 timevar_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
 280 static void
 281 timevar_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
 293 timer::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 (m_timevars, 0, 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
 320 timer::~timer ()
 321 {
 322   timevar_stack_def *iter, *next;
 323
 324   for (iter = m_stack; iter; iter = next)
 325     {
 326       next = iter->next;
 327       free (iter);
 328     }
 329   for (iter = m_unused_stack_instances; iter; iter = next)
 330     {
 331       next = iter->next;
 332       free (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
 342 void
 343 timevar_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
 358 void
 359 timer::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
 368 void
 369 timer::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);
 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 (&m_stack->timevar->elapsed, &m_start_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
 416 void
 417 timer::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
 427 void
 428 timer::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);
 435
 436   /* Attribute the elapsed time to the element we're popping.  */
 437   timevar_accumulate (&popped->timevar->elapsed, &m_start_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 (popped->timevar, &existed_p);
 450       if (! existed_p)
 451         memset (&time, 0, sizeof (timevar_time_def));
 452       timevar_accumulate (&time, &m_start_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
 469 void
 470 timevar_start (timevar_id_t timevar)
 471 {
 472   if (!g_timer)
 473     return;
 474
 475   g_timer->start (timevar);
 476 }
 477
 478 /* See timevar_start above.  */
 479
 480 void
 481 timer::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 (&tv->start_time);
 494 }
 495
 496 /* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
 497    is attributed to it.  */
 498
 499 void
 500 timevar_stop (timevar_id_t timevar)
 501 {
 502   if (!g_timer)
 503     return;
 504
 505   g_timer->stop (timevar);
 506 }
 507
 508 /* See timevar_stop above.  */
 509
 510 void
 511 timer::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);
 521   timevar_accumulate (&tv->elapsed, &tv->start_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
 531 bool
 532 timevar_cond_start (timevar_id_t timevar)
 533 {
 534   if (!g_timer)
 535     return false;
 536
 537   return g_timer->cond_start (timevar);
 538 }
 539
 540 /* See timevar_cond_start above.  */
 541
 542 bool
 543 timer::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 (&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
 566 void
 567 timevar_cond_stop (timevar_id_t timevar, bool running)
 568 {
 569   if (!g_timer || running)
 570     return;
 571
 572   g_timer->cond_stop (timevar);
 573 }
 574
 575 /* See timevar_cond_stop above.  */
 576
 577 void
 578 timer::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);
 590   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
 591 }
 592
 593 /* Push the named item onto the timing stack.  */
 594
 595 void
 596 timer::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
 609 void
 610 timer::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
 618 void
 619 timer::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 (tv->name, 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 (fp, "Timing error: total of phase timers exceeds total time.\n");
 653       if (phase_user > total->user)
 654         fprintf (fp, "user    %13" PRIu64 " > %13" PRIu64 "\n",
 655                  phase_user, total->user);
 656       if (phase_sys > total->sys)
 657         fprintf (fp, "sys     %13" PRIu64 " > %13" PRIu64 "\n",
 658                  phase_sys, total->sys);
 659       if (phase_wall > total->wall)
 660         fprintf (fp, "wall    %13" PRIu64 " > %13" PRIu64 "\n",
 661                  phase_wall, total->wall);
 662       if (phase_ggc_mem > total->ggc_mem)
 663         fprintf (fp, "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
 674 void
 675 timer::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 (fp, " %-35s:", name);
 681
 682 #ifdef HAVE_USER_TIME
 683   /* Print user-mode time for this process.  */
 684   fprintf (fp, "%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 (fp, "%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 (fp, "%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 (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 ('\n', fp);
 711 }
 712
 713 /* Return whether ELAPSED is all zero.  */
 714
 715 bool
 716 timer::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
 730 void
 731 timer::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);
 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 (&m_stack->timevar->elapsed, &m_start_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 (fp, "\n%-35s%16s%14s%14s%14s\n", "Time variable", "usr", "sys",
 757            "wall", "GGC");
 758   if (m_jit_client_items)
 759     fputs ("GCC items:\n", 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 ((*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 (tv->elapsed))
 787         continue;
 788
 789       print_row (fp, total, tv->name, 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 ((*i).second))
 799               {
 800                 char lname[256];
 801                 snprintf (lname, 256, "`- %s", tv2->name);
 802                 print_row (fp, total, lname, (*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 (fp, " %-35s:", "TOTAL");
 811 #ifdef HAVE_USER_TIME
 812   fprintf (fp, "%7.2f      ", nanosec_to_floating_sec (total->user));
 813 #endif
 814 #ifdef HAVE_SYS_TIME
 815   fprintf (fp, "%8.2f      ", nanosec_to_floating_sec (total->sys));
 816 #endif
 817 #ifdef HAVE_WALL_TIME
 818   fprintf (fp, "%8.2f      ", nanosec_to_floating_sec (total->wall));
 819 #endif
 820   fprintf (fp, PRsa (7) "\n", SIZE_AMOUNT (total->ggc_mem));
 821
 822   if (CHECKING_P || flag_checking)
 823     fprintf (fp, "Extra diagnostic checks enabled; compiler may run slowly.\n");
 824   if (CHECKING_P)
 825     fprintf (fp, "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
 840 json::object *
 841 make_json_for_timevar_time_def (const timevar_time_def &ttd)
 842 {
 843   json::object *obj = new json::object ();
 844   obj->set_float ("user", nanosec_to_floating_sec (ttd.user));
 845   obj->set_float ("sys", nanosec_to_floating_sec (ttd.sys));
 846   obj->set_float ("wall", nanosec_to_floating_sec (ttd.wall));
 847   obj->set_integer ("ggc_mem", ttd.ggc_mem);
 848   return obj;
 849 }
 850 #undef nanosec_to_floating_sec
 851 #undef percent_of
 852
 853 /* Create a json value representing this object, suitable for use
 854    in SARIF output.  */
 855
 856 json::value *
 857 timer::timevar_def::make_json () const
 858 {
 859   json::object *timevar_obj = new json::object ();
 860   timevar_obj->set_string ("name", name);
 861   timevar_obj->set ("elapsed", make_json_for_timevar_time_def (elapsed));
 862
 863   if (children)
 864     {
 865       bool any_children_with_time = false;
 866       for (auto i : *children)
 867         if (!all_zero (i.second))
 868           {
 869             any_children_with_time = true;
 870             break;
 871           }
 872       if (any_children_with_time)
 873         {
 874           json::array *children_arr = new json::array ();
 875           timevar_obj->set ("children", children_arr);
 876           for (auto i : *children)
 877             {
 878               /* Don't emit timing variables if we're going to get a row of
 879                  zeroes.  */
 880               if (all_zero (i.second))
 881                 continue;
 882               json::object *child_obj = new json::object;
 883               children_arr->append (child_obj);
 884               child_obj->set_string ("name", i.first->name);
 885               child_obj->set ("elapsed",
 886                               make_json_for_timevar_time_def (i.second));
 887             }
 888         }
 889     }
 890
 891   return timevar_obj;
 892 }
 893
 894 /* Create a json value representing this object, suitable for use
 895    in SARIF output.  */
 896
 897 json::value *
 898 timer::make_json () const
 899 {
 900   /* Only generate stuff if we have some sort of time information.  */
 901 #if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
 902   json::object *report_obj = new json::object ();
 903   json::array *json_arr = new json::array ();
 904   report_obj->set ("timevars", json_arr);
 905
 906   for (unsigned id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
 907     {
 908       const timevar_def *tv = &m_timevars[(timevar_id_t) id];
 909
 910       /* Don't print the total execution time here; this isn't initialized
 911          by the time the sarif output runs.  */
 912       if ((timevar_id_t) id == TV_TOTAL)
 913         continue;
 914
 915       /* Don't emit timing variables that were never used.  */
 916       if (!tv->used)
 917         continue;
 918
 919       bool any_children_with_time = false;
 920       if (tv->children)
 921         for (child_map_t::iterator i = tv->children->begin ();
 922              i != tv->children->end (); ++i)
 923           if (! all_zero ((*i).second))
 924             {
 925               any_children_with_time = true;
 926               break;
 927             }
 928
 929       /* Don't emit timing variables if we're going to get a row of
 930          zeroes.  Unless there are children with non-zero time.  */
 931       if (! any_children_with_time
 932           && all_zero (tv->elapsed))
 933         continue;
 934
 935       json_arr->append (tv->make_json ());
 936     }
 937
 938   /* Special-case for total.  */
 939   {
 940     /* Get our own total up till now, without affecting TV_TOTAL.  */
 941     struct timevar_time_def total_now;
 942     struct timevar_time_def total_elapsed;
 943     get_time (&total_now);
 944     timevar_diff (&total_elapsed, m_timevars[TV_TOTAL].start_time, total_now);
 945
 946     json::object *total_obj = new json::object();
 947     json_arr->append (total_obj);
 948     total_obj->set_string ("name", "TOTAL");
 949     total_obj->set ("elapsed", make_json_for_timevar_time_def (total_elapsed));
 950   }
 951
 952   if (m_jit_client_items)
 953     report_obj->set ("client_items", m_jit_client_items->make_json ());
 954
 955   report_obj->set_bool ("CHECKING_P", CHECKING_P);
 956   report_obj->set_bool ("flag_checking", flag_checking);
 957
 958   return report_obj;
 959
 960 #else /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 961           || defined (HAVE_WALL_TIME) */
 962   return NULL;
 963 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 964           || defined (HAVE_WALL_TIME) */
 965 }
 966
 967 /* Get the name of the topmost item.  For use by jit for validating
 968    inputs to gcc_jit_timer_pop.  */
 969 const char *
 970 timer::get_topmost_item_name () const
 971 {
 972   if (m_stack)
 973     return m_stack->timevar->name;
 974   else
 975     return NULL;
 976 }
 977
 978 /* Prints a message to stderr stating that time elapsed in STR is
 979    TOTAL (given in microseconds).  */
 980
 981 void
 982 print_time (const char *str, long total)
 983 {
 984   long all_time = get_run_time ();
 985   fprintf (stderr,
 986            "time in %s: %ld.%06ld (%ld%%)\n",
 987            str, total / 1000000, total % 1000000,
 988            all_time == 0 ? 0
 989            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
 990 }