]> git.cworth.org Git - fips/blobdiff - metrics.c
Add per-frame time and latency measurements
[fips] / metrics.c
index 6704572533a41b901fa93cf481d731c23f408707..72f5400fa3c1668f468e286af707cdcd89de5497 100644 (file)
--- a/metrics.c
+++ b/metrics.c
@@ -21,6 +21,8 @@
 
 #define _GNU_SOURCE
 
+#include <inttypes.h>
+
 #include <stdio.h>
 #include <stdlib.h>
 #include <assert.h>
@@ -98,6 +100,11 @@ struct metrics
 
        unsigned num_op_metrics;
        op_metrics_t *op_metrics;
+
+       /* Per-frame time and latency measurement. */
+       GLint64 swap_begin_timestamp;
+       unsigned swap_end_timestamp_id;
+       GLint64 previous_swap_end_timestamp;
 };
 
 metrics_t *
@@ -126,6 +133,11 @@ metrics_create (metrics_info_t *info)
        metrics->num_op_metrics = 0;
        metrics->op_metrics = NULL;
 
+       glGenQueries (1, &metrics->swap_end_timestamp_id);
+
+       /* Get the first frame timestamp started immediately. */
+       glQueryCounter (metrics->swap_end_timestamp_id, GL_TIMESTAMP);
+
        return metrics;
 }
 
@@ -153,22 +165,26 @@ metrics_fini (metrics_t *metrics)
        metrics->timer_head = NULL;
        metrics->timer_tail = NULL;
 
-       if (metrics->monitor_begun_id) {
-               glEndPerfMonitorAMD (metrics->monitor_begun_id);
-               glDeletePerfMonitorsAMD (1, &metrics->monitor_begun_id);
-               metrics->monitor_begun_id = 0;
-       }
+       if (metrics->info->have_perfmon) {
+
+               if (metrics->monitor_begun_id) {
+                       glEndPerfMonitorAMD (metrics->monitor_begun_id);
+                       glDeletePerfMonitorsAMD (1, &metrics->monitor_begun_id);
+                       metrics->monitor_begun_id = 0;
+               }
+
+               for (monitor = metrics->monitor_head;
+                    monitor;
+                    monitor = monitor_next)
+               {
+                       glDeletePerfMonitorsAMD (1, &monitor->id);
+                       monitor_next = monitor->next;
+                       free (monitor);
+               }
+               metrics->monitor_head = NULL;
+               metrics->monitor_tail = NULL;
 
-       for (monitor = metrics->monitor_head;
-            monitor;
-            monitor = monitor_next)
-       {
-               glDeletePerfMonitorsAMD (1, &monitor->id);
-               monitor_next = monitor->next;
-               free (monitor);
        }
-       metrics->monitor_head = NULL;
-       metrics->monitor_tail = NULL;
 
        metrics->monitors_in_flight = 0;
 }
@@ -231,9 +247,18 @@ metrics_counter_start (metrics_t *metrics)
 {
        unsigned i;
 
-       /* Initialize the timer_query and monitor objects */
+       /* Initialize the timer_query object. */
        glGenQueries (1, &metrics->timer_begun_id);
 
+       /* Most everything else in this function is
+        * performance-monitor related. If we don't have that
+        * extension, just start the timer query and be done. */
+       if (! metrics->info->have_perfmon) {
+               glBeginQuery (GL_TIME_ELAPSED, metrics->timer_begun_id);
+               return;
+       }
+
+       /* Initialize the performance-monitor object */
        glGenPerfMonitorsAMD (1, &metrics->monitor_begun_id);
 
        for (i = 0; i < metrics->info->num_groups; i++)
@@ -273,7 +298,9 @@ metrics_counter_stop (metrics_t *metrics)
 
        /* Stop the current timer and monitor. */
        glEndQuery (GL_TIME_ELAPSED);
-       glEndPerfMonitorAMD (metrics->monitor_begun_id);
+
+       if (metrics->info->have_perfmon)
+               glEndPerfMonitorAMD (metrics->monitor_begun_id);
 
        /* Add these IDs to our lists of outstanding queries and
         * monitors so the results can be collected later. */
@@ -291,19 +318,21 @@ metrics_counter_stop (metrics_t *metrics)
                metrics->timer_head = timer;
        }
 
-       /* Create a new performance-monitor query */
-       monitor = xmalloc (sizeof (monitor_t));
+       if (metrics->info->have_perfmon) {
+               /* Create a new performance-monitor query */
+               monitor = xmalloc (sizeof (monitor_t));
 
-       monitor->op = metrics->op;
-       monitor->id = metrics->monitor_begun_id;
-       monitor->next = NULL;
+               monitor->op = metrics->op;
+               monitor->id = metrics->monitor_begun_id;
+               monitor->next = NULL;
 
-       if (metrics->monitor_tail) {
-               metrics->monitor_tail->next = monitor;
-               metrics->monitor_tail = monitor;
-       } else {
-               metrics->monitor_tail = monitor;
-               metrics->monitor_head = monitor;
+               if (metrics->monitor_tail) {
+                       metrics->monitor_tail->next = monitor;
+                       metrics->monitor_tail = monitor;
+               } else {
+                       metrics->monitor_tail = monitor;
+                       metrics->monitor_head = monitor;
+               }
        }
 
        metrics->monitors_in_flight++;
@@ -576,10 +605,24 @@ print_program_metrics (metrics_t *metrics)
        unsigned group_index, counter_index;
        unsigned i, j, num_sorted;
 
+       if (! info->have_perfmon &&
+           ! info->printed_missing_perfmon_warning)
+       {
+               fprintf (stderr,
+                        "Warning: The GL_AMD_performance_monitor extensions is not available.\n"
+                        "         Some fips features, (such as per-shader-stage timings),\n"
+                        "         will not be available.\n");
+
+               info->printed_missing_perfmon_warning = true;
+       }
+
        /* Make a sorted list of the per-stage operations by time
         * used, and figure out the total so we can print percentages.
         */
-       num_sorted = metrics->num_op_metrics * num_shader_stages;
+       if (num_shader_stages)
+               num_sorted = metrics->num_op_metrics * num_shader_stages;
+       else
+               num_sorted = metrics->num_op_metrics;
 
        sorted = xmalloc (sizeof (*sorted) * num_sorted);
 
@@ -595,6 +638,14 @@ print_program_metrics (metrics_t *metrics)
                /* Also, find total cycles in all stages of this op. */
                op_cycles = 0.0;
 
+               if (num_shader_stages == 0) {
+                       per_stage = &sorted[i];
+                       per_stage->metrics = op;
+                       per_stage->stage = NULL;
+                       per_stage->time_ns = op->time_ns;
+                       per_stage->active = 0.0;
+               }
+
                for (j = 0; j < num_shader_stages; j++) {
                        /* Active cycles */
                        group_index = info->stages[j].active_group_index;
@@ -689,6 +740,9 @@ metrics_collect_available (metrics_t *metrics)
                timer = metrics->timer_head;
        }
 
+       if (! metrics->info->have_perfmon)
+               return;
+
        /* And similarly for all performance monitors that are ready. */
        monitor_t *monitor = metrics->monitor_head;
 
@@ -733,13 +787,71 @@ metrics_collect_available (metrics_t *metrics)
        }
 }
 
+void
+metrics_end_frame_pre_swap (metrics_t *metrics)
+{
+       GLint64 swap_end_timestamp, frame_time_ns, latency_ns;
+
+       /* Don't leave any counters running over the end_frame work we
+        * do here. The counters will be started again at the end of
+        * metrics_end_frame_post_swap.  */
+
+       metrics_counter_stop (metrics);
+
+       /* Now that an entire frame's worth of content has gone by, we
+        * can be sure that the timer quiery for the previous frame's
+        * swap is available.
+        *
+        * Note: The only case in which this query isn't immediately
+        * available would be if there was effectively nothing in this
+        * frame. In that case, triggering a block on this query
+        * result is not a concern (since an empty frame is not
+        * interesting, and all of our counters are stopped anyway).
+        *
+        * Accepting this one block is much better than adding a
+        * linked list for these results that would reaslisticly never
+        * have more than one entry anyway.
+        */
+
+       glGetQueryObjecti64v (metrics->swap_end_timestamp_id,
+                             GL_QUERY_RESULT, &swap_end_timestamp);
+
+       if (frames > 0) {
+               /* Subtract previous frame's timestamp to get frame time. */
+               frame_time_ns = swap_end_timestamp - metrics->previous_swap_end_timestamp;
+
+               latency_ns = swap_end_timestamp - metrics->swap_begin_timestamp;
+
+               /* We've waited one frame to ensure we have a timestamp
+                * result. So the time we've actually measured here is
+                * for the previous frame. */
+               printf ("Frame %d: %.2f ms (latency: %.2f ms)\n",
+                       frames - 1, frame_time_ns / 1e6, latency_ns / 1e6);
+       }
+
+       metrics->previous_swap_end_timestamp = swap_end_timestamp;
+
+       /* Before the actual swap call, we get the current timestamp
+        * value. This is a synchronous get so we can use this as the
+        * baseline for a frame latency measurment. */
+
+       glGetInteger64v (GL_TIMESTAMP, &metrics->swap_begin_timestamp);
+}
 
 void
-metrics_end_frame (metrics_t *metrics)
+metrics_end_frame_post_swap (metrics_t *metrics)
 {
        static int initialized = 0;
        static struct timeval tv_start, tv_now;
 
+       /* Now that the swap command has been queued, we issue an
+        * asynchronous query of the timestamp value. Comparing this
+        * to the synchronous get we just sent in
+        * metrics_end_frame_pre_swap allows us to measure the
+        * per-frame swap latency. */
+
+       glQueryCounter (metrics->swap_end_timestamp_id, GL_TIMESTAMP);
+
        if (! initialized) {
                gettimeofday (&tv_start, NULL);
                if (getenv ("FIPS_VERBOSE"))
@@ -747,10 +859,10 @@ metrics_end_frame (metrics_t *metrics)
                initialized = 1;
        }
 
-       frames++;
-
        metrics_collect_available (metrics);
 
+       frames++;
+
        if (frames % 15 == 0) {
                double fps;
 
@@ -763,4 +875,7 @@ metrics_end_frame (metrics_t *metrics)
 
                print_program_metrics (metrics);
        }
+
+       /* Start the counter up again now that we're done. */
+       metrics_counter_start (metrics);
 }