1 /* Copyright © 2013, Intel Corporation
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:
10 * The above copyright notice and this permission notice shall be included in
11 * all copies or substantial portions of the Software.
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
31 #include "fips-dispatch-gl.h"
35 #include "metrics-info.h"
41 #define MAX_MONITORS_IN_FLIGHT 1000
44 typedef struct timer_query
49 struct timer_query *next;
52 /* Performance-monitor query */
53 typedef struct monitor
61 typedef struct op_metrics
63 /* This happens to also be the index into the
64 * metrics->op_metrics array currently
74 /* Description of all available peformance counters, counter
75 * groups, their names and IDs, etc. */
78 /* The current operation being measured. */
81 /* GL_TIME_ELAPSED query for which glEndQuery has not yet
83 unsigned timer_begun_id;
85 /* GL_TIME_ELAPSED queries for which glEndQuery has been
86 * called, (but results have not yet been queried). */
87 timer_query_t *timer_head;
88 timer_query_t *timer_tail;
90 /* Performance monitor for which glEndPerfMonitorAMD has not
92 unsigned monitor_begun_id;
94 /* Performance monitors for which glEndPerfMonitorAMD has
95 * been called, (but results have not yet been queried). */
96 monitor_t *monitor_head;
97 monitor_t *monitor_tail;
99 int monitors_in_flight;
101 unsigned num_op_metrics;
102 op_metrics_t *op_metrics;
104 /* Per-frame time and latency measurement. */
105 GLint64 swap_begin_timestamp;
106 unsigned swap_end_timestamp_id;
107 GLint64 previous_swap_end_timestamp;
111 metrics_create (metrics_info_t *info)
115 metrics = xmalloc (sizeof (metrics_t));
117 metrics->info = info;
121 metrics->timer_begun_id = 0;
123 metrics->timer_head = NULL;
124 metrics->timer_tail = NULL;
126 metrics->monitor_begun_id = 0;
128 metrics->monitor_head = NULL;
129 metrics->monitor_tail = NULL;
131 metrics->monitors_in_flight = 0;
133 metrics->num_op_metrics = 0;
134 metrics->op_metrics = NULL;
136 glGenQueries (1, &metrics->swap_end_timestamp_id);
138 /* Get the first frame timestamp started immediately. */
139 glQueryCounter (metrics->swap_end_timestamp_id, GL_TIMESTAMP);
145 metrics_fini (metrics_t *metrics)
147 timer_query_t *timer, *timer_next;
148 monitor_t *monitor, *monitor_next;
150 /* Discard and cleanup any outstanding queries. */
151 if (metrics->timer_begun_id) {
152 glEndQuery (GL_TIME_ELAPSED);
153 glDeleteQueries (1, &metrics->timer_begun_id);
154 metrics->timer_begun_id = 0;
157 for (timer = metrics->timer_head;
161 glDeleteQueries (1, &timer->id);
162 timer_next = timer->next;
165 metrics->timer_head = NULL;
166 metrics->timer_tail = NULL;
168 if (metrics->info->have_perfmon) {
170 if (metrics->monitor_begun_id) {
171 glEndPerfMonitorAMD (metrics->monitor_begun_id);
172 glDeletePerfMonitorsAMD (1, &metrics->monitor_begun_id);
173 metrics->monitor_begun_id = 0;
176 for (monitor = metrics->monitor_head;
178 monitor = monitor_next)
180 glDeletePerfMonitorsAMD (1, &monitor->id);
181 monitor_next = monitor->next;
184 metrics->monitor_head = NULL;
185 metrics->monitor_tail = NULL;
189 metrics->monitors_in_flight = 0;
193 metrics_destroy (metrics_t *metrics)
195 metrics_fini (metrics);
201 metrics_op_string (metrics_op_t op)
203 if (op >= METRICS_OP_SHADER)
204 return "Shader program";
208 case METRICS_OP_ACCUM:
209 return "glAccum*(+)";
210 case METRICS_OP_BUFFER_DATA:
211 return "glBufferData(+)";
212 case METRICS_OP_BUFFER_SUB_DATA:
213 return "glCopyBufferSubData*";
214 case METRICS_OP_BITMAP:
216 case METRICS_OP_BLIT_FRAMEBUFFER:
217 return "glBlitFramebuffer*";
218 case METRICS_OP_CLEAR:
220 case METRICS_OP_CLEAR_BUFFER_DATA:
221 return "glCearBufferData(+)";
222 case METRICS_OP_CLEAR_TEX_IMAGE:
223 return "glClearTexImage(+)";
224 case METRICS_OP_COPY_PIXELS:
225 return "glCopyPixels";
226 case METRICS_OP_COPY_TEX_IMAGE:
227 return "glCopyTexImage(+)";
228 case METRICS_OP_DRAW_PIXELS:
229 return "glDrawPixels";
230 case METRICS_OP_GET_TEX_IMAGE:
231 return "glGetTexImage(+)";
232 case METRICS_OP_READ_PIXELS:
233 return "glReadPixels*";
234 case METRICS_OP_TEX_IMAGE:
235 return "glTexImage*(+)";
237 fprintf (stderr, "fips: Internal error: "
238 "Unknown metrics op value: %d\n", op);
246 metrics_counter_start (metrics_t *metrics)
250 /* Initialize the timer_query object. */
251 glGenQueries (1, &metrics->timer_begun_id);
253 /* Most everything else in this function is
254 * performance-monitor related. If we don't have that
255 * extension, just start the timer query and be done. */
256 if (! metrics->info->have_perfmon) {
257 glBeginQuery (GL_TIME_ELAPSED, metrics->timer_begun_id);
261 /* Initialize the performance-monitor object */
262 glGenPerfMonitorsAMD (1, &metrics->monitor_begun_id);
264 for (i = 0; i < metrics->info->num_groups; i++)
266 metrics_group_info_t *group;
269 group = &metrics->info->groups[i];
271 num_counters = group->num_counters;
272 if (group->max_active_counters < group->num_counters)
274 fprintf (stderr, "Warning: Only monitoring %d/%d counters from group %d\n",
275 group->max_active_counters,
276 group->num_counters, i);
277 num_counters = group->max_active_counters;
281 glSelectPerfMonitorCountersAMD(metrics->monitor_begun_id,
287 /* Start the queries */
288 glBeginQuery (GL_TIME_ELAPSED, metrics->timer_begun_id);
290 glBeginPerfMonitorAMD (metrics->monitor_begun_id);
294 metrics_counter_stop (metrics_t *metrics)
296 timer_query_t *timer;
299 /* Stop the current timer and monitor. */
300 glEndQuery (GL_TIME_ELAPSED);
302 if (metrics->info->have_perfmon)
303 glEndPerfMonitorAMD (metrics->monitor_begun_id);
305 /* Add these IDs to our lists of outstanding queries and
306 * monitors so the results can be collected later. */
307 timer = xmalloc (sizeof (timer_query_t));
309 timer->op = metrics->op;
310 timer->id = metrics->timer_begun_id;
313 if (metrics->timer_tail) {
314 metrics->timer_tail->next = timer;
315 metrics->timer_tail = timer;
317 metrics->timer_tail = timer;
318 metrics->timer_head = timer;
321 if (metrics->info->have_perfmon) {
322 /* Create a new performance-monitor query */
323 monitor = xmalloc (sizeof (monitor_t));
325 monitor->op = metrics->op;
326 monitor->id = metrics->monitor_begun_id;
327 monitor->next = NULL;
329 if (metrics->monitor_tail) {
330 metrics->monitor_tail->next = monitor;
331 metrics->monitor_tail = monitor;
333 metrics->monitor_tail = monitor;
334 metrics->monitor_head = monitor;
338 metrics->monitors_in_flight++;
340 /* Avoid being a resource hog and collect outstanding results
341 * once we have sent off a large number of
342 * queries. (Presumably, many of the outstanding queries are
345 if (metrics->monitors_in_flight > MAX_MONITORS_IN_FLIGHT)
346 metrics_collect_available (metrics);
350 metrics_set_current_op (metrics_t *metrics, metrics_op_t op)
356 metrics_get_current_op (metrics_t *metrics)
362 op_metrics_init (metrics_info_t *info, op_metrics_t *metrics, metrics_op_t op)
367 metrics->time_ns = 0.0;
369 metrics->counters = xmalloc (sizeof(double *) * info->num_groups);
371 for (i = 0; i < info->num_groups; i++) {
372 metrics->counters[i] = xmalloc (sizeof (double) *
373 info->groups[i].num_counters);
374 for (j = 0; j < info->groups[i].num_counters; j++)
375 metrics->counters[i][j] = 0.0;
379 static op_metrics_t *
380 _get_op_metrics (metrics_t *metrics, metrics_op_t op)
384 if (op >= metrics->num_op_metrics)
386 metrics->op_metrics = realloc (metrics->op_metrics,
387 (op + 1) * sizeof (op_metrics_t));
388 for (i = metrics->num_op_metrics; i < op + 1; i++)
389 op_metrics_init (metrics->info, &metrics->op_metrics[i], i);
391 metrics->num_op_metrics = op + 1;
394 return &metrics->op_metrics[op];
398 accumulate_program_metrics (metrics_t *metrics, metrics_op_t op,
399 GLuint *result, GLuint size)
401 #define CONSUME(var) \
402 if (p + sizeof(var) > ((unsigned char *) result) + size) \
404 fprintf (stderr, "Unexpected end-of-buffer while " \
405 "parsing results\n"); \
408 (var) = *((typeof(var) *) p); \
411 metrics_info_t *info = metrics->info;
412 op_metrics_t *op_metrics = _get_op_metrics (metrics, op);
413 unsigned char *p = (unsigned char *) result;
415 while (p < ((unsigned char *) result) + size)
417 GLuint group_id, group_index;
418 GLuint counter_id, counter_index;
419 metrics_group_info_t *group;
424 CONSUME (counter_id);
426 for (i = 0; i < info->num_groups; i++) {
427 if (info->groups[i].id == group_id)
431 assert (group_index < info->num_groups);
432 group = &info->groups[group_index];
434 for (i = 0; i < group->num_counters; i++) {
435 if (group->counter_ids[i] == counter_id)
439 assert (counter_index < group->num_counters);
441 switch (group->counter_types[counter_index])
444 uint64_t uint64_value;
446 case GL_UNSIGNED_INT:
447 CONSUME (uint_value);
450 case GL_UNSIGNED_INT64_AMD:
451 CONSUME (uint64_value);
452 value = uint64_value;
454 case GL_PERCENTAGE_AMD:
456 CONSUME (float_value);
460 fprintf (stderr, "fips: Warning: Unknown counter value type (%d)\n",
461 group->counter_types[counter_index]);
466 op_metrics->counters[group_index][counter_index] += value;
471 accumulate_program_time (metrics_t *metrics, metrics_op_t op, unsigned time_ns)
473 op_metrics_t *op_metrics;
475 op_metrics = _get_op_metrics (metrics, op);
477 op_metrics->time_ns += time_ns;
480 typedef struct per_stage_metrics
482 op_metrics_t *metrics;
483 shader_stage_info_t *stage;
486 } per_stage_metrics_t;
489 _is_shader_stage_counter (metrics_info_t *info,
490 unsigned group_index,
491 unsigned counter_index)
493 shader_stage_info_t *stage;
496 for (i = 0; i < info->num_shader_stages; i++) {
497 stage = &info->stages[i];
499 if (stage->active_group_index == group_index &&
500 stage->active_counter_index == counter_index)
505 if (stage->stall_group_index == group_index &&
506 stage->stall_counter_index == counter_index)
516 print_per_stage_metrics (metrics_t *metrics,
517 per_stage_metrics_t *per_stage,
520 metrics_info_t *info = metrics->info;
521 op_metrics_t *op_metrics = per_stage->metrics;
522 metrics_group_info_t *group;
523 const char *op_string;
524 unsigned group_index, counter;
527 /* Don't print anything for stages with no alloted time. */
528 if (per_stage->time_ns == 0.0)
531 op_string = metrics_op_string (op_metrics->op);
533 printf ("%21s", op_string);
535 if (op_metrics->op >= METRICS_OP_SHADER) {
536 printf (" %3d", op_metrics->op - METRICS_OP_SHADER);
542 if (per_stage->stage)
543 printf (" %cS:", per_stage->stage->name[0]);
547 printf ("\t%7.2f ms (%4.1f%%)",
548 per_stage->time_ns / 1e6,
549 per_stage->time_ns / total * 100);
551 if (per_stage->active)
552 printf (", %4.1f%% active", per_stage->active * 100);
556 /* I'm not seeing a lot of value printing the rest of these
557 * performance counters by default yet. Use --verbose to get
563 for (group_index = 0; group_index < info->num_groups; group_index++) {
564 group = &info->groups[group_index];
565 for (counter = 0; counter < group->num_counters; counter++) {
567 /* Don't print this counter value if it's a
568 * per-stage cycle counter, (which we have
569 * already accounted for). */
570 if (_is_shader_stage_counter (info, group_index, counter))
573 value = op_metrics->counters[group_index][counter];
576 printf ("%s: %.2f ", group->counter_names[counter],
584 time_compare(const void *in_a, const void *in_b, void *arg unused)
586 const per_stage_metrics_t *a = in_a;
587 const per_stage_metrics_t *b = in_b;
590 if (a->time_ns < b->time_ns)
592 if (a->time_ns > b->time_ns)
598 print_program_metrics (metrics_t *metrics)
600 metrics_info_t *info = metrics->info;
601 unsigned num_shader_stages = info->num_shader_stages;
602 per_stage_metrics_t *sorted, *per_stage;
603 double total_time, op_cycles;
605 unsigned group_index, counter_index;
606 unsigned i, j, num_sorted;
608 if (! info->have_perfmon &&
609 ! info->printed_missing_perfmon_warning)
612 "Warning: The GL_AMD_performance_monitor extensions is not available.\n"
613 " Some fips features, (such as per-shader-stage timings),\n"
614 " will not be available.\n");
616 info->printed_missing_perfmon_warning = true;
619 /* Make a sorted list of the per-stage operations by time
620 * used, and figure out the total so we can print percentages.
622 if (num_shader_stages)
623 num_sorted = metrics->num_op_metrics * num_shader_stages;
625 num_sorted = metrics->num_op_metrics;
627 sorted = xmalloc (sizeof (*sorted) * num_sorted);
631 for (i = 0; i < metrics->num_op_metrics; i++) {
633 op = &metrics->op_metrics[i];
635 /* Accumulate total time across all ops. */
636 total_time += op->time_ns;
638 /* Also, find total cycles in all stages of this op. */
641 if (num_shader_stages == 0) {
642 per_stage = &sorted[i];
643 per_stage->metrics = op;
644 per_stage->stage = NULL;
645 per_stage->time_ns = op->time_ns;
646 per_stage->active = 0.0;
649 for (j = 0; j < num_shader_stages; j++) {
651 group_index = info->stages[j].active_group_index;
652 counter_index = info->stages[j].active_counter_index;
653 op_cycles += op->counters[group_index][counter_index];
656 group_index = info->stages[j].stall_group_index;
657 counter_index = info->stages[j].stall_counter_index;
658 op_cycles += op->counters[group_index][counter_index];
661 for (j = 0; j < num_shader_stages; j++) {
662 double active_cycles, stall_cycles, stage_cycles;
665 group_index = info->stages[j].active_group_index;
666 counter_index = info->stages[j].active_counter_index;
667 active_cycles = op->counters[group_index][counter_index];
670 group_index = info->stages[j].stall_group_index;
671 counter_index = info->stages[j].stall_counter_index;
672 stall_cycles = op->counters[group_index][counter_index];
674 stage_cycles = active_cycles + stall_cycles;
676 per_stage = &sorted[i * num_shader_stages + j];
677 per_stage->metrics = op;
680 per_stage->stage = &info->stages[j];
681 per_stage->time_ns = op->time_ns * (stage_cycles / op_cycles);
683 /* If we don't have any per-stage cycle counts
684 * for this operation, then use the first
685 * stage as a placeholder for all the time,
686 * but NULL-ify the stage info so that the
687 * report doesn't lie about this time being
688 * from any particular stage. */
689 per_stage->stage = NULL;
691 per_stage->time_ns = op->time_ns;
693 per_stage->time_ns = 0.0;
698 per_stage->active = active_cycles / stage_cycles;
700 per_stage->active = 0.0;
705 qsort_r (sorted, num_sorted, sizeof (*sorted),
706 time_compare, metrics->op_metrics);
708 for (i = 0; i < num_sorted; i++)
709 print_per_stage_metrics (metrics, &sorted[i], total_time);
715 metrics_collect_available (metrics_t *metrics)
717 /* Consume all timer queries that are ready. */
718 timer_query_t *timer = metrics->timer_head;
721 GLuint available, elapsed;
723 glGetQueryObjectuiv (timer->id,
724 GL_QUERY_RESULT_AVAILABLE, &available);
728 glGetQueryObjectuiv (timer->id,
729 GL_QUERY_RESULT, &elapsed);
731 accumulate_program_time (metrics, timer->op, elapsed);
733 metrics->timer_head = timer->next;
734 if (metrics->timer_head == NULL)
735 metrics->timer_tail = NULL;
737 glDeleteQueries (1, &timer->id);
740 timer = metrics->timer_head;
743 if (! metrics->info->have_perfmon)
746 /* And similarly for all performance monitors that are ready. */
747 monitor_t *monitor = metrics->monitor_head;
750 GLuint available, result_size, *result;
753 glGetPerfMonitorCounterDataAMD (monitor->id,
754 GL_PERFMON_RESULT_AVAILABLE_AMD,
755 sizeof (available), &available,
760 glGetPerfMonitorCounterDataAMD (monitor->id,
761 GL_PERFMON_RESULT_SIZE_AMD,
762 sizeof (result_size),
765 result = xmalloc (result_size);
767 glGetPerfMonitorCounterDataAMD (monitor->id,
768 GL_PERFMON_RESULT_AMD,
772 accumulate_program_metrics (metrics, monitor->op, result, result_size);
776 metrics->monitor_head = monitor->next;
777 if (metrics->monitor_head == NULL)
778 metrics->monitor_tail = NULL;
780 glDeletePerfMonitorsAMD (1, &monitor->id);
784 metrics->monitors_in_flight--;
786 monitor = metrics->monitor_head;
791 metrics_end_frame_pre_swap (metrics_t *metrics)
793 GLuint64 swap_end_timestamp, frame_time_ns, latency_ns;
795 /* Don't leave any counters running over the end_frame work we
796 * do here. The counters will be started again at the end of
797 * metrics_end_frame_post_swap. */
799 metrics_counter_stop (metrics);
801 /* Now that an entire frame's worth of content has gone by, we
802 * can be sure that the timer quiery for the previous frame's
805 * Note: The only case in which this query isn't immediately
806 * available would be if there was effectively nothing in this
807 * frame. In that case, triggering a block on this query
808 * result is not a concern (since an empty frame is not
809 * interesting, and all of our counters are stopped anyway).
811 * Accepting this one block is much better than adding a
812 * linked list for these results that would reaslisticly never
813 * have more than one entry anyway.
816 glGetQueryObjectui64v (metrics->swap_end_timestamp_id,
817 GL_QUERY_RESULT, &swap_end_timestamp);
820 /* Subtract previous frame's timestamp to get frame time. */
821 frame_time_ns = swap_end_timestamp - metrics->previous_swap_end_timestamp;
823 latency_ns = swap_end_timestamp - metrics->swap_begin_timestamp;
825 /* We've waited one frame to ensure we have a timestamp
826 * result. So the time we've actually measured here is
827 * for the previous frame. */
828 printf ("frame-time: %d %" PRId64 "\n",
829 frames - 1, frame_time_ns);
831 printf ("frame-latency: %d %" PRId64 "\n",
832 frames - 1, latency_ns);
836 metrics->previous_swap_end_timestamp = swap_end_timestamp;
838 /* Before the actual swap call, we get the current timestamp
839 * value. This is a synchronous get so we can use this as the
840 * baseline for a frame latency measurment. */
842 glGetInteger64v (GL_TIMESTAMP, &metrics->swap_begin_timestamp);
846 metrics_end_frame_post_swap (metrics_t *metrics)
848 static int initialized = 0;
849 static struct timeval tv_start, tv_now;
851 /* Now that the swap command has been queued, we issue an
852 * asynchronous query of the timestamp value. Comparing this
853 * to the synchronous get we just sent in
854 * metrics_end_frame_pre_swap allows us to measure the
855 * per-frame swap latency. */
857 glQueryCounter (metrics->swap_end_timestamp_id, GL_TIMESTAMP);
860 gettimeofday (&tv_start, NULL);
861 if (getenv ("FIPS_VERBOSE"))
866 metrics_collect_available (metrics);
870 if (frames % 15 == 0) {
873 gettimeofday (&tv_now, NULL);
875 fps = (double) frames / (tv_now.tv_sec - tv_start.tv_sec +
876 (tv_now.tv_usec - tv_start.tv_usec) / 1.0e6);
878 printf("FPS: %.3f\n", fps);
880 print_program_metrics (metrics);
883 /* Start the counter up again now that we're done. */
884 metrics_counter_start (metrics);