git.cworth.org Git - fips/blob - metrics.c

   1 /* Copyright © 2013, Intel Corporation
   2  *
   3  * Permission is hereby granted, free of charge, to any person obtaining a copy
   4  * of this software and associated documentation files (the "Software"), to deal
   5  * in the Software without restriction, including without limitation the rights
   6  * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
   7  * copies of the Software, and to permit persons to whom the Software is
   8  * furnished to do so, subject to the following conditions:
   9  *
  10  * The above copyright notice and this permission notice shall be included in
  11  * all copies or substantial portions of the Software.
  12  *
  13  * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
  14  * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
  15  * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
  16  * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
  17  * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
  18  * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
  19  * THE SOFTWARE.
  20  */
  21
  22 #define _GNU_SOURCE
  23
  24 #include <inttypes.h>
  25
  26 #include <stdio.h>
  27 #include <stdlib.h>
  28 #include <assert.h>
  29 #include <time.h>
  30 #include <sys/time.h>
  31 #include <string.h>
  32 #include <errno.h>
  33
  34 #include "fips-dispatch-gl.h"
  35
  36 #include "metrics.h"
  37 #include "context.h"
  38 #include "metrics-info.h"
  39 #include "xmalloc.h"
  40
  41 int frames;
  42 int verbose;
  43
  44 #define MAX_MONITORS_IN_FLIGHT 1000
  45
  46 /* Timer query */
  47 typedef struct timer_query
  48 {
  49         unsigned id;
  50
  51         metrics_op_t op;
  52         struct timer_query *next;
  53 } timer_query_t;
  54
  55 /* Performance-monitor query */
  56 typedef struct monitor
  57 {
  58         unsigned id;
  59
  60         metrics_op_t op;
  61         struct monitor *next;
  62 } monitor_t;
  63
  64 typedef struct op_metrics
  65 {
  66         /* This happens to also be the index into the
  67          * metrics->op_metrics array currently
  68          */
  69         metrics_op_t op;
  70         double time_ns;
  71
  72         double **counters;
  73 } op_metrics_t;
  74
  75 struct metrics
  76 {
  77         /* Description of all available peformance counters, counter
  78          * groups, their names and IDs, etc. */
  79         metrics_info_t *info;
  80
  81         /* The current operation being measured. */
  82         metrics_op_t op;
  83
  84         /* GL_TIME_ELAPSED query for which glEndQuery has not yet
  85          * been called. */
  86         unsigned timer_begun_id;
  87
  88         /* GL_TIME_ELAPSED queries for which glEndQuery has been
  89          * called, (but results have not yet been queried). */
  90         timer_query_t *timer_head;
  91         timer_query_t *timer_tail;
  92
  93         /* Performance monitor for which glEndPerfMonitorAMD has not
  94          * yet been called. */
  95         unsigned monitor_begun_id;
  96
  97         /* Performance monitors for which glEndPerfMonitorAMD has
  98          * been called, (but results have not yet been queried). */
  99         monitor_t *monitor_head;
 100         monitor_t *monitor_tail;
 101
 102         int monitors_in_flight;
 103
 104         unsigned num_op_metrics;
 105         op_metrics_t *op_metrics;
 106
 107         /* Per-frame time and latency measurement. */
 108         GLint64 swap_begin_timestamp;
 109         unsigned swap_end_timestamp_id;
 110         GLint64 previous_swap_end_timestamp;
 111
 112         struct timespec previous_cpu_time_ts;
 113         struct timespec cpu_time_ts;
 114 };
 115
 116 metrics_t *
 117 metrics_create (metrics_info_t *info)
 118 {
 119         metrics_t *metrics;
 120
 121         metrics = xmalloc (sizeof (metrics_t));
 122
 123         metrics->info = info;
 124
 125         metrics->op = 0;
 126
 127         metrics->timer_begun_id = 0;
 128
 129         metrics->timer_head = NULL;
 130         metrics->timer_tail = NULL;
 131
 132         metrics->monitor_begun_id = 0;
 133
 134         metrics->monitor_head = NULL;
 135         metrics->monitor_tail = NULL;
 136
 137         metrics->monitors_in_flight = 0;
 138
 139         metrics->num_op_metrics = 0;
 140         metrics->op_metrics = NULL;
 141
 142         glGenQueries (1, &metrics->swap_end_timestamp_id);
 143
 144         /* Get the first frame timestamp started immediately. */
 145         glQueryCounter (metrics->swap_end_timestamp_id, GL_TIMESTAMP);
 146
 147         /* As well as the initial CPU time. */
 148         clock_gettime (CLOCK_PROCESS_CPUTIME_ID, &metrics->cpu_time_ts);
 149
 150         return metrics;
 151 }
 152
 153 void
 154 metrics_fini (metrics_t *metrics)
 155 {
 156         timer_query_t *timer, *timer_next;
 157         monitor_t *monitor, *monitor_next;
 158
 159         /* Discard and cleanup any outstanding queries. */
 160         if (metrics->timer_begun_id) {
 161                 glEndQuery (GL_TIME_ELAPSED);
 162                 glDeleteQueries (1, &metrics->timer_begun_id);
 163                 metrics->timer_begun_id = 0;
 164         }
 165
 166         for (timer = metrics->timer_head;
 167              timer;
 168              timer = timer_next)
 169         {
 170                 glDeleteQueries (1, &timer->id);
 171                 timer_next = timer->next;
 172                 free (timer);
 173         }
 174         metrics->timer_head = NULL;
 175         metrics->timer_tail = NULL;
 176
 177         if (metrics->info->have_perfmon) {
 178
 179                 if (metrics->monitor_begun_id) {
 180                         glEndPerfMonitorAMD (metrics->monitor_begun_id);
 181                         glDeletePerfMonitorsAMD (1, &metrics->monitor_begun_id);
 182                         metrics->monitor_begun_id = 0;
 183                 }
 184
 185                 for (monitor = metrics->monitor_head;
 186                      monitor;
 187                      monitor = monitor_next)
 188                 {
 189                         glDeletePerfMonitorsAMD (1, &monitor->id);
 190                         monitor_next = monitor->next;
 191                         free (monitor);
 192                 }
 193                 metrics->monitor_head = NULL;
 194                 metrics->monitor_tail = NULL;
 195
 196         }
 197
 198         metrics->monitors_in_flight = 0;
 199 }
 200
 201 void
 202 metrics_destroy (metrics_t *metrics)
 203 {
 204         metrics_fini (metrics);
 205
 206         free (metrics);
 207 }
 208
 209 static const char *
 210 metrics_op_string (metrics_op_t op)
 211 {
 212         if (op >= METRICS_OP_SHADER)
 213                 return "Shader program";
 214
 215         switch (op)
 216         {
 217         case METRICS_OP_ACCUM:
 218                 return "glAccum*(+)";
 219         case METRICS_OP_BUFFER_DATA:
 220                 return "glBufferData(+)";
 221         case METRICS_OP_BUFFER_SUB_DATA:
 222                 return "glCopyBufferSubData*";
 223         case METRICS_OP_BITMAP:
 224                 return "glBitmap*";
 225         case METRICS_OP_BLIT_FRAMEBUFFER:
 226                 return "glBlitFramebuffer*";
 227         case METRICS_OP_CLEAR:
 228                 return "glClear(+)";
 229         case METRICS_OP_CLEAR_BUFFER_DATA:
 230                 return "glCearBufferData(+)";
 231         case METRICS_OP_CLEAR_TEX_IMAGE:
 232                 return "glClearTexImage(+)";
 233         case METRICS_OP_COPY_PIXELS:
 234                 return "glCopyPixels";
 235         case METRICS_OP_COPY_TEX_IMAGE:
 236                 return "glCopyTexImage(+)";
 237         case METRICS_OP_DRAW_PIXELS:
 238                 return "glDrawPixels";
 239         case METRICS_OP_GET_TEX_IMAGE:
 240                 return "glGetTexImage(+)";
 241         case METRICS_OP_READ_PIXELS:
 242                 return "glReadPixels*";
 243         case METRICS_OP_TEX_IMAGE:
 244                 return "glTexImage*(+)";
 245         default:
 246                 fprintf (stderr, "fips: Internal error: "
 247                          "Unknown metrics op value: %d\n", op);
 248                 exit (1);
 249         }
 250
 251         return "";
 252 }
 253
 254 void
 255 metrics_counter_start (metrics_t *metrics)
 256 {
 257         unsigned i;
 258
 259         /* Initialize the timer_query object. */
 260         glGenQueries (1, &metrics->timer_begun_id);
 261
 262         /* Most everything else in this function is
 263          * performance-monitor related. If we don't have that
 264          * extension, just start the timer query and be done. */
 265         if (! metrics->info->have_perfmon) {
 266                 glBeginQuery (GL_TIME_ELAPSED, metrics->timer_begun_id);
 267                 return;
 268         }
 269
 270         /* Initialize the performance-monitor object */
 271         glGenPerfMonitorsAMD (1, &metrics->monitor_begun_id);
 272
 273         for (i = 0; i < metrics->info->num_groups; i++)
 274         {
 275                 metrics_group_info_t *group;
 276                 int num_counters;
 277
 278                 group = &metrics->info->groups[i];
 279
 280                 num_counters = group->num_counters;
 281                 if (group->max_active_counters < group->num_counters)
 282                 {
 283                         fprintf (stderr, "Warning: Only monitoring %d/%d counters from group %d\n",
 284                                  group->max_active_counters,
 285                                  group->num_counters, i);
 286                         num_counters = group->max_active_counters;
 287
 288                 }
 289
 290                 glSelectPerfMonitorCountersAMD(metrics->monitor_begun_id,
 291                                                GL_TRUE, group->id,
 292                                                num_counters,
 293                                                group->counter_ids);
 294         }
 295
 296         /* Start the queries */
 297         glBeginQuery (GL_TIME_ELAPSED, metrics->timer_begun_id);
 298
 299         glBeginPerfMonitorAMD (metrics->monitor_begun_id);
 300 }
 301
 302 void
 303 metrics_counter_stop (metrics_t *metrics)
 304 {
 305         timer_query_t *timer;
 306         monitor_t *monitor;
 307
 308         /* Stop the current timer and monitor. */
 309         glEndQuery (GL_TIME_ELAPSED);
 310
 311         if (metrics->info->have_perfmon)
 312                 glEndPerfMonitorAMD (metrics->monitor_begun_id);
 313
 314         /* Add these IDs to our lists of outstanding queries and
 315          * monitors so the results can be collected later. */
 316         timer = xmalloc (sizeof (timer_query_t));
 317
 318         timer->op = metrics->op;
 319         timer->id = metrics->timer_begun_id;
 320         timer->next = NULL;
 321
 322         if (metrics->timer_tail) {
 323                 metrics->timer_tail->next = timer;
 324                 metrics->timer_tail = timer;
 325         } else {
 326                 metrics->timer_tail = timer;
 327                 metrics->timer_head = timer;
 328         }
 329
 330         if (metrics->info->have_perfmon) {
 331                 /* Create a new performance-monitor query */
 332                 monitor = xmalloc (sizeof (monitor_t));
 333
 334                 monitor->op = metrics->op;
 335                 monitor->id = metrics->monitor_begun_id;
 336                 monitor->next = NULL;
 337
 338                 if (metrics->monitor_tail) {
 339                         metrics->monitor_tail->next = monitor;
 340                         metrics->monitor_tail = monitor;
 341                 } else {
 342                         metrics->monitor_tail = monitor;
 343                         metrics->monitor_head = monitor;
 344                 }
 345         }
 346
 347         metrics->monitors_in_flight++;
 348
 349         /* Avoid being a resource hog and collect outstanding results
 350          * once we have sent off a large number of
 351          * queries. (Presumably, many of the outstanding queries are
 352          * available by now.)
 353          */
 354         if (metrics->monitors_in_flight > MAX_MONITORS_IN_FLIGHT)
 355                 metrics_collect_available (metrics);
 356 }
 357
 358 void
 359 metrics_set_current_op (metrics_t *metrics, metrics_op_t op)
 360 {
 361         metrics->op = op;
 362 }
 363
 364 metrics_op_t
 365 metrics_get_current_op (metrics_t *metrics)
 366 {
 367         return metrics->op;
 368 }
 369
 370 static void
 371 op_metrics_init (metrics_info_t *info, op_metrics_t *metrics, metrics_op_t op)
 372 {
 373         unsigned i, j;
 374
 375         metrics->op = op;
 376         metrics->time_ns = 0.0;
 377
 378         metrics->counters = xmalloc (sizeof(double *) * info->num_groups);
 379
 380         for (i = 0; i < info->num_groups; i++) {
 381                 metrics->counters[i] = xmalloc (sizeof (double) *
 382                                                 info->groups[i].num_counters);
 383                 for (j = 0; j < info->groups[i].num_counters; j++)
 384                         metrics->counters[i][j] = 0.0;
 385         }
 386 }
 387
 388 static op_metrics_t *
 389 _get_op_metrics (metrics_t *metrics, metrics_op_t op)
 390 {
 391         unsigned i;
 392
 393         if (op >= metrics->num_op_metrics)
 394         {
 395                 metrics->op_metrics = realloc (metrics->op_metrics,
 396                                                (op + 1) * sizeof (op_metrics_t));
 397                 for (i = metrics->num_op_metrics; i < op + 1; i++)
 398                         op_metrics_init (metrics->info, &metrics->op_metrics[i], i);
 399
 400                 metrics->num_op_metrics = op + 1;
 401         }
 402
 403         return &metrics->op_metrics[op];
 404 }
 405
 406 static void
 407 accumulate_program_metrics (metrics_t *metrics, metrics_op_t op,
 408                             GLuint *result, GLuint size)
 409 {
 410 #define CONSUME(var)                                                    \
 411         if (p + sizeof(var) > ((unsigned char *) result) + size)        \
 412         {                                                               \
 413                 fprintf (stderr, "Unexpected end-of-buffer while "      \
 414                          "parsing results\n");                          \
 415                 value = 0.0;                                            \
 416                 break;                                                  \
 417         }                                                               \
 418         (var) = *((typeof(var) *) p);                                   \
 419         p += sizeof(var);
 420
 421         metrics_info_t *info = metrics->info;
 422         op_metrics_t *op_metrics = _get_op_metrics (metrics, op);
 423         unsigned char *p = (unsigned char *) result;
 424
 425         while (p < ((unsigned char *) result) + size)
 426         {
 427                 GLuint group_id, group_index;
 428                 GLuint counter_id, counter_index;
 429                 metrics_group_info_t *group;
 430                 double value;
 431                 unsigned i;
 432
 433                 CONSUME (group_id);
 434                 CONSUME (counter_id);
 435
 436                 for (i = 0; i < info->num_groups; i++) {
 437                         if (info->groups[i].id == group_id)
 438                                 break;
 439                 }
 440                 group_index = i;
 441                 assert (group_index < info->num_groups);
 442                 group = &info->groups[group_index];
 443
 444                 for (i = 0; i < group->num_counters; i++) {
 445                         if (group->counter_ids[i] == counter_id)
 446                                 break;
 447                 }
 448                 counter_index = i;
 449                 assert (counter_index < group->num_counters);
 450
 451                 switch (group->counter_types[counter_index])
 452                 {
 453                         uint uint_value;
 454                         uint64_t uint64_value;
 455                         float float_value;
 456                 case GL_UNSIGNED_INT:
 457                         CONSUME (uint_value);
 458                         value = uint_value;
 459                         break;
 460                 case GL_UNSIGNED_INT64_AMD:
 461                         CONSUME (uint64_value);
 462                         value = uint64_value;
 463                         break;
 464                 case GL_PERCENTAGE_AMD:
 465                 case GL_FLOAT:
 466                         CONSUME (float_value);
 467                         value = float_value;
 468                         break;
 469                 default:
 470                         fprintf (stderr, "fips: Warning: Unknown counter value type (%d)\n",
 471                                  group->counter_types[counter_index]);
 472                         value = 0.0;
 473                         break;
 474                 }
 475
 476                 op_metrics->counters[group_index][counter_index] += value;
 477         }
 478 }
 479
 480 static void
 481 accumulate_program_time (metrics_t *metrics, metrics_op_t op, unsigned time_ns)
 482 {
 483         op_metrics_t *op_metrics;
 484
 485         op_metrics = _get_op_metrics (metrics, op);
 486
 487         op_metrics->time_ns += time_ns;
 488 }
 489
 490 typedef struct per_stage_metrics
 491 {
 492         op_metrics_t *metrics;
 493         shader_stage_info_t *stage;
 494         double time_ns;
 495         double active;
 496 } per_stage_metrics_t;
 497
 498 static int
 499 _is_shader_stage_counter (metrics_info_t *info,
 500                           unsigned group_index,
 501                           unsigned counter_index)
 502 {
 503         shader_stage_info_t *stage;
 504         unsigned i;
 505
 506         for (i = 0; i < info->num_shader_stages; i++) {
 507                 stage = &info->stages[i];
 508
 509                 if (stage->active_group_index == group_index &&
 510                     stage->active_counter_index == counter_index)
 511                 {
 512                         return 1;
 513                 }
 514
 515                 if (stage->stall_group_index == group_index &&
 516                     stage->stall_counter_index == counter_index)
 517                 {
 518                         return 1;
 519                 }
 520         }
 521
 522         return 0;
 523 }
 524
 525 static void
 526 print_per_stage_metrics (metrics_t *metrics,
 527                          per_stage_metrics_t *per_stage,
 528                          double total)
 529 {
 530         metrics_info_t *info = metrics->info;
 531         op_metrics_t *op_metrics = per_stage->metrics;
 532         metrics_group_info_t *group;
 533         const char *op_string;
 534         unsigned group_index, counter;
 535         double value;
 536
 537         /* Don't print anything for stages with no alloted time. */
 538         if (per_stage->time_ns == 0.0)
 539                 return;
 540
 541         op_string = metrics_op_string (op_metrics->op);
 542
 543         printf ("%21s", op_string);
 544
 545         if (op_metrics->op >= METRICS_OP_SHADER) {
 546                 printf (" %3d", op_metrics->op - METRICS_OP_SHADER);
 547         } else {
 548                 printf ("    ");
 549
 550         }
 551
 552         if (per_stage->stage)
 553                 printf (" %cS:", per_stage->stage->name[0]);
 554         else
 555                 printf ("   :");
 556
 557         printf ("\t%7.2f ms (%4.1f%%)",
 558                 per_stage->time_ns / 1e6,
 559                 per_stage->time_ns / total * 100);
 560
 561         if (per_stage->active)
 562                 printf (", %4.1f%% active", per_stage->active * 100);
 563
 564         printf ("\n");
 565
 566         /* I'm not seeing a lot of value printing the rest of these
 567          * performance counters by default yet. Use --verbose to get
 568          * them for now. */
 569         if (! verbose)
 570                 return;
 571
 572         printf ("[");
 573         for (group_index = 0; group_index < info->num_groups; group_index++) {
 574                 group = &info->groups[group_index];
 575                 for (counter = 0; counter < group->num_counters; counter++) {
 576
 577                         /* Don't print this counter value if it's a
 578                          * per-stage cycle counter, (which we have
 579                          * already accounted for). */
 580                         if (_is_shader_stage_counter (info, group_index, counter))
 581                                 continue;
 582
 583                         value = op_metrics->counters[group_index][counter];
 584                         if (value == 0.0)
 585                                 continue;
 586                         printf ("%s: %.2f ", group->counter_names[counter],
 587                                 value / 1e6);
 588                 }
 589         }
 590         printf ("]\n");
 591 }
 592
 593 static int
 594 time_compare(const void *in_a, const void *in_b, void *arg unused)
 595 {
 596         const per_stage_metrics_t *a = in_a;
 597         const per_stage_metrics_t *b = in_b;
 598
 599
 600         if (a->time_ns < b->time_ns)
 601                 return -1;
 602         if (a->time_ns > b->time_ns)
 603                 return 1;
 604         return 0;
 605 }
 606
 607 static void
 608 print_program_metrics (metrics_t *metrics)
 609 {
 610         metrics_info_t *info = metrics->info;
 611         unsigned num_shader_stages = info->num_shader_stages;
 612         per_stage_metrics_t *sorted, *per_stage;
 613         double total_time, op_cycles;
 614         op_metrics_t *op;
 615         unsigned group_index, counter_index;
 616         unsigned i, j, num_sorted;
 617
 618         if (! info->have_perfmon &&
 619             ! info->printed_missing_perfmon_warning)
 620         {
 621                 fprintf (stderr,
 622                          "Warning: The GL_AMD_performance_monitor extensions is not available.\n"
 623                          "         Some fips features, (such as per-shader-stage timings),\n"
 624                          "         will not be available.\n");
 625
 626                 info->printed_missing_perfmon_warning = true;
 627         }
 628
 629         /* Make a sorted list of the per-stage operations by time
 630          * used, and figure out the total so we can print percentages.
 631          */
 632         if (num_shader_stages)
 633                 num_sorted = metrics->num_op_metrics * num_shader_stages;
 634         else
 635                 num_sorted = metrics->num_op_metrics;
 636
 637         sorted = xmalloc (sizeof (*sorted) * num_sorted);
 638
 639         total_time = 0.0;
 640
 641         for (i = 0; i < metrics->num_op_metrics; i++) {
 642
 643                 op = &metrics->op_metrics[i];
 644
 645                 /* Accumulate total time across all ops. */
 646                 total_time += op->time_ns;
 647
 648                 /* Also, find total cycles in all stages of this op. */
 649                 op_cycles = 0.0;
 650
 651                 if (num_shader_stages == 0) {
 652                         per_stage = &sorted[i];
 653                         per_stage->metrics = op;
 654                         per_stage->stage = NULL;
 655                         per_stage->time_ns = op->time_ns;
 656                         per_stage->active = 0.0;
 657                 }
 658
 659                 for (j = 0; j < num_shader_stages; j++) {
 660                         /* Active cycles */
 661                         group_index = info->stages[j].active_group_index;
 662                         counter_index = info->stages[j].active_counter_index;
 663                         op_cycles += op->counters[group_index][counter_index];
 664
 665                         /* Stall cycles */
 666                         group_index = info->stages[j].stall_group_index;
 667                         counter_index = info->stages[j].stall_counter_index;
 668                         op_cycles += op->counters[group_index][counter_index];
 669                 }
 670
 671                 for (j = 0; j < num_shader_stages; j++) {
 672                         double active_cycles, stall_cycles, stage_cycles;
 673
 674                         /* Active cycles */
 675                         group_index = info->stages[j].active_group_index;
 676                         counter_index = info->stages[j].active_counter_index;
 677                         active_cycles = op->counters[group_index][counter_index];
 678
 679                         /* Stall cycles */
 680                         group_index = info->stages[j].stall_group_index;
 681                         counter_index = info->stages[j].stall_counter_index;
 682                         stall_cycles = op->counters[group_index][counter_index];
 683
 684                         stage_cycles = active_cycles + stall_cycles;
 685
 686                         per_stage = &sorted[i * num_shader_stages + j];
 687                         per_stage->metrics = op;
 688
 689                         if (op_cycles) {
 690                                 per_stage->stage = &info->stages[j];
 691                                 per_stage->time_ns = op->time_ns * (stage_cycles / op_cycles);
 692                         } else {
 693                                 /* If we don't have any per-stage cycle counts
 694                                  * for this operation, then use the first
 695                                  * stage as a placeholder for all the time,
 696                                  * but NULL-ify the stage info so that the
 697                                  * report doesn't lie about this time being
 698                                  * from any particular stage. */
 699                                 per_stage->stage = NULL;
 700                                 if (j == 0) {
 701                                         per_stage->time_ns = op->time_ns;
 702                                 } else {
 703                                         per_stage->time_ns = 0.0;
 704                                 }
 705                         }
 706
 707                         if (stage_cycles) {
 708                                 per_stage->active = active_cycles / stage_cycles;
 709                         } else {
 710                                 per_stage->active = 0.0;
 711                         }
 712                 }
 713         }
 714
 715         qsort_r (sorted, num_sorted, sizeof (*sorted),
 716                  time_compare, metrics->op_metrics);
 717
 718         for (i = 0; i < num_sorted; i++)
 719                 print_per_stage_metrics (metrics, &sorted[i], total_time);
 720
 721         free (sorted);
 722 }
 723
 724 void
 725 metrics_collect_available (metrics_t *metrics)
 726 {
 727         /* Consume all timer queries that are ready. */
 728         timer_query_t *timer = metrics->timer_head;
 729
 730         while (timer) {
 731                 GLuint available, elapsed;
 732
 733                 glGetQueryObjectuiv (timer->id,
 734                                      GL_QUERY_RESULT_AVAILABLE, &available);
 735                 if (! available)
 736                         break;
 737
 738                 glGetQueryObjectuiv (timer->id,
 739                                      GL_QUERY_RESULT, &elapsed);
 740
 741                 accumulate_program_time (metrics, timer->op, elapsed);
 742
 743                 metrics->timer_head = timer->next;
 744                 if (metrics->timer_head == NULL)
 745                         metrics->timer_tail = NULL;
 746
 747                 glDeleteQueries (1, &timer->id);
 748
 749                 free (timer);
 750                 timer = metrics->timer_head;
 751         }
 752
 753         if (! metrics->info->have_perfmon)
 754                 return;
 755
 756         /* And similarly for all performance monitors that are ready. */
 757         monitor_t *monitor = metrics->monitor_head;
 758
 759         while (monitor) {
 760                 GLuint available, result_size, *result;
 761                 GLint bytes_written;
 762
 763                 glGetPerfMonitorCounterDataAMD (monitor->id,
 764                                                 GL_PERFMON_RESULT_AVAILABLE_AMD,
 765                                                 sizeof (available), &available,
 766                                                 NULL);
 767                 if (! available)
 768                         break;
 769
 770                 glGetPerfMonitorCounterDataAMD (monitor->id,
 771                                                 GL_PERFMON_RESULT_SIZE_AMD,
 772                                                 sizeof (result_size),
 773                                                 &result_size, NULL);
 774
 775                 result = xmalloc (result_size);
 776
 777                 glGetPerfMonitorCounterDataAMD (monitor->id,
 778                                                 GL_PERFMON_RESULT_AMD,
 779                                                 result_size, result,
 780                                                 &bytes_written);
 781
 782                 accumulate_program_metrics (metrics, monitor->op, result, result_size);
 783
 784                 free (result);
 785
 786                 metrics->monitor_head = monitor->next;
 787                 if (metrics->monitor_head == NULL)
 788                         metrics->monitor_tail = NULL;
 789
 790                 glDeletePerfMonitorsAMD (1, &monitor->id);
 791
 792                 free (monitor);
 793
 794                 metrics->monitors_in_flight--;
 795
 796                 monitor = metrics->monitor_head;
 797         }
 798 }
 799
 800 /* Return the difference from ts0 to ts1 as floating-point seconds. */
 801 #define TIMESPEC_DIFF(ts0, ts1) (double) (ts1.tv_sec - ts0.tv_sec + \
 802                                           (ts1.tv_nsec - ts0.tv_nsec) / 1e9)
 803
 804 void
 805 metrics_end_frame_pre_swap (metrics_t *metrics)
 806 {
 807         GLuint64 swap_end_timestamp, frame_time_ns, latency_ns;
 808         double cpu_time;
 809
 810         /* Don't leave any counters running over the end_frame work we
 811          * do here. The counters will be started again at the end of
 812          * metrics_end_frame_post_swap.  */
 813
 814         metrics_counter_stop (metrics);
 815
 816         /* Now that an entire frame's worth of content has gone by, we
 817          * can be sure that the timer quiery for the previous frame's
 818          * swap is available.
 819          *
 820          * Note: The only case in which this query isn't immediately
 821          * available would be if there was effectively nothing in this
 822          * frame. In that case, triggering a block on this query
 823          * result is not a concern (since an empty frame is not
 824          * interesting, and all of our counters are stopped anyway).
 825          *
 826          * Accepting this one block is much better than adding a
 827          * linked list for these results that would reaslisticly never
 828          * have more than one entry anyway.
 829          */
 830
 831         glGetQueryObjectui64v (metrics->swap_end_timestamp_id,
 832                                GL_QUERY_RESULT, &swap_end_timestamp);
 833
 834         if (frames == 0) {
 835                 /* Print header */
 836                 printf ("# frame: Frame_Number Frame_Time_milliseconds Frame_latency_milliseconds CPU_load GPU_load\n");
 837         } else {
 838                 /* Subtract previous frame's times to get frame times. */
 839                 frame_time_ns = swap_end_timestamp - metrics->previous_swap_end_timestamp;
 840
 841                 latency_ns = swap_end_timestamp - metrics->swap_begin_timestamp;
 842
 843                 cpu_time = TIMESPEC_DIFF (metrics->previous_cpu_time_ts, metrics->cpu_time_ts);
 844
 845                 /* We've waited one frame to ensure we have a timestamp
 846                  * result. So the time we've actually measured here is
 847                  * for the previous frame. */
 848                 printf ("frame: %d %g %g %g %g\n",
 849                         frames - 1,
 850                         (double) frame_time_ns / 1e6,
 851                         (double) latency_ns / 1e6,
 852                         cpu_time / (frame_time_ns / 1e9),
 853                         0.0);
 854         }
 855
 856         metrics->previous_swap_end_timestamp = swap_end_timestamp;
 857         metrics->previous_cpu_time_ts = metrics->cpu_time_ts;
 858
 859         /* Before the actual swap call, we get the current timestamp
 860          * value. This is a synchronous get so we can use this as the
 861          * baseline for a frame latency measurment. */
 862
 863         glGetInteger64v (GL_TIMESTAMP, &metrics->swap_begin_timestamp);
 864 }
 865
 866 void
 867 metrics_end_frame_post_swap (metrics_t *metrics)
 868 {
 869         static int initialized = 0;
 870         static struct timeval tv_start, tv_now;
 871         int err;
 872
 873         /* Now that the swap command has been queued, we issue an
 874          * asynchronous query of the timestamp value. Comparing this
 875          * to the synchronous get we just sent in
 876          * metrics_end_frame_pre_swap allows us to measure the
 877          * per-frame swap latency. */
 878
 879         glQueryCounter (metrics->swap_end_timestamp_id, GL_TIMESTAMP);
 880
 881         /* Query the total amount of CPU time spent by this process. */
 882         err = clock_gettime (CLOCK_PROCESS_CPUTIME_ID, &metrics->cpu_time_ts);
 883         if (err == -1 ) {
 884                 fprintf (stderr, "Failed to query CPU time with clock_gettime: %s\n",
 885                          strerror (errno));
 886                 exit (1);
 887         }
 888
 889         if (! initialized) {
 890                 gettimeofday (&tv_start, NULL);
 891                 if (getenv ("FIPS_VERBOSE"))
 892                         verbose = 1;
 893                 initialized = 1;
 894         }
 895
 896         metrics_collect_available (metrics);
 897
 898         frames++;
 899
 900         if (frames % 15 == 0) {
 901                 double fps;
 902
 903                 gettimeofday (&tv_now, NULL);
 904
 905                 fps = (double) frames / (tv_now.tv_sec - tv_start.tv_sec +
 906                                          (tv_now.tv_usec - tv_start.tv_usec) / 1.0e6);
 907
 908                 printf("FPS: %.3f\n", fps);
 909
 910                 print_program_metrics (metrics);
 911         }
 912
 913         /* Start the counter up again now that we're done. */
 914         metrics_counter_start (metrics);
 915 }