#define _GNU_SOURCE
+#include <inttypes.h>
+
#include <stdio.h>
#include <stdlib.h>
#include <assert.h>
+#include <time.h>
#include <sys/time.h>
+#include <string.h>
+#include <errno.h>
#include "fips-dispatch-gl.h"
typedef struct op_metrics
{
/* This happens to also be the index into the
- * ctx->op_metrics array currently
+ * metrics->op_metrics array currently
*/
metrics_op_t op;
double time_ns;
struct metrics
{
+ /* Description of all available peformance counters, counter
+ * groups, their names and IDs, etc. */
+ metrics_info_t *info;
+
+ /* The current operation being measured. */
metrics_op_t op;
/* GL_TIME_ELAPSED query for which glEndQuery has not yet
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;
+
+ struct timespec previous_cpu_time_ts;
+ struct timespec cpu_time_ts;
};
metrics_t *
-metrics_create (void)
+metrics_create (metrics_info_t *info)
{
metrics_t *metrics;
metrics = xmalloc (sizeof (metrics_t));
+ metrics->info = info;
+
metrics->op = 0;
metrics->timer_begun_id = 0;
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);
+
+ /* As well as the initial CPU time. */
+ clock_gettime (CLOCK_PROCESS_CPUTIME_ID, &metrics->cpu_time_ts);
+
return 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;
}
}
void
-metrics_counter_start (void)
+metrics_counter_start (metrics_t *metrics)
{
- context_t *ctx = context_get_current ();
- metrics_t *metrics = ctx->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 < ctx->metrics_info.num_groups; i++)
+ for (i = 0; i < metrics->info->num_groups; i++)
{
metrics_group_info_t *group;
int num_counters;
- group = &ctx->metrics_info.groups[i];
+ group = &metrics->info->groups[i];
num_counters = group->num_counters;
if (group->max_active_counters < group->num_counters)
}
void
-metrics_counter_stop (void)
+metrics_counter_stop (metrics_t *metrics)
{
- context_t *ctx = context_get_current ();
- metrics_t *metrics = ctx->metrics;
timer_query_t *timer;
monitor_t *monitor;
/* 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. */
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++;
* available by now.)
*/
if (metrics->monitors_in_flight > MAX_MONITORS_IN_FLIGHT)
- metrics_collect_available ();
+ metrics_collect_available (metrics);
}
void
-metrics_set_current_op (metrics_op_t op)
+metrics_set_current_op (metrics_t *metrics, metrics_op_t op)
{
- context_t *ctx = context_get_current ();
- metrics_t *metrics = ctx->metrics;
-
metrics->op = op;
}
metrics_op_t
-metrics_get_current_op (void)
+metrics_get_current_op (metrics_t *metrics)
{
- context_t *ctx = context_get_current ();
- metrics_t *metrics = ctx->metrics;
-
return metrics->op;
}
static void
-op_metrics_init (context_t *ctx, op_metrics_t *metrics, metrics_op_t op)
+op_metrics_init (metrics_info_t *info, op_metrics_t *metrics, metrics_op_t op)
{
- metrics_info_t *info = &ctx->metrics_info;
unsigned i, j;
metrics->op = op;
}
static op_metrics_t *
-ctx_get_op_metrics (context_t *ctx, metrics_op_t op)
+_get_op_metrics (metrics_t *metrics, metrics_op_t op)
{
- metrics_t *metrics = ctx->metrics;
unsigned i;
if (op >= metrics->num_op_metrics)
metrics->op_metrics = realloc (metrics->op_metrics,
(op + 1) * sizeof (op_metrics_t));
for (i = metrics->num_op_metrics; i < op + 1; i++)
- op_metrics_init (ctx, &metrics->op_metrics[i], i);
+ op_metrics_init (metrics->info, &metrics->op_metrics[i], i);
metrics->num_op_metrics = op + 1;
}
}
static void
-accumulate_program_metrics (metrics_op_t op, GLuint *result, GLuint size)
+accumulate_program_metrics (metrics_t *metrics, metrics_op_t op,
+ GLuint *result, GLuint size)
{
#define CONSUME(var) \
if (p + sizeof(var) > ((unsigned char *) result) + size) \
{ \
fprintf (stderr, "Unexpected end-of-buffer while " \
"parsing results\n"); \
+ value = 0.0; \
break; \
} \
(var) = *((typeof(var) *) p); \
p += sizeof(var);
- context_t *ctx = context_get_current ();
- metrics_info_t *info = &ctx->metrics_info;
- op_metrics_t *metrics = ctx_get_op_metrics (ctx, op);
+ metrics_info_t *info = metrics->info;
+ op_metrics_t *op_metrics = _get_op_metrics (metrics, op);
unsigned char *p = (unsigned char *) result;
while (p < ((unsigned char *) result) + size)
break;
}
- metrics->counters[group_index][counter_index] += value;
+ op_metrics->counters[group_index][counter_index] += value;
}
}
static void
-accumulate_program_time (metrics_op_t op, unsigned time_ns)
+accumulate_program_time (metrics_t *metrics, metrics_op_t op, unsigned time_ns)
{
- context_t *ctx = context_get_current ();
- op_metrics_t *metrics;
+ op_metrics_t *op_metrics;
- metrics = ctx_get_op_metrics (ctx, op);
+ op_metrics = _get_op_metrics (metrics, op);
- metrics->time_ns += time_ns;
+ op_metrics->time_ns += time_ns;
}
typedef struct per_stage_metrics
}
static void
-print_per_stage_metrics (context_t *ctx,
+print_per_stage_metrics (metrics_t *metrics,
per_stage_metrics_t *per_stage,
double total)
{
- metrics_info_t *info = &ctx->metrics_info;
- op_metrics_t *metric = per_stage->metrics;
+ metrics_info_t *info = metrics->info;
+ op_metrics_t *op_metrics = per_stage->metrics;
metrics_group_info_t *group;
const char *op_string;
unsigned group_index, counter;
if (per_stage->time_ns == 0.0)
return;
- op_string = metrics_op_string (metric->op);
+ op_string = metrics_op_string (op_metrics->op);
printf ("%21s", op_string);
- if (metric->op >= METRICS_OP_SHADER) {
- printf (" %3d", metric->op - METRICS_OP_SHADER);
+ if (op_metrics->op >= METRICS_OP_SHADER) {
+ printf (" %3d", op_metrics->op - METRICS_OP_SHADER);
} else {
printf (" ");
if (_is_shader_stage_counter (info, group_index, counter))
continue;
- value = metric->counters[group_index][counter];
+ value = op_metrics->counters[group_index][counter];
if (value == 0.0)
continue;
printf ("%s: %.2f ", group->counter_names[counter],
}
static void
-print_program_metrics (void)
+print_program_metrics (metrics_t *metrics)
{
- context_t *ctx = context_get_current ();
- metrics_t *metrics = ctx->metrics;
- metrics_info_t *info = &ctx->metrics_info;
+ metrics_info_t *info = metrics->info;
unsigned num_shader_stages = info->num_shader_stages;
per_stage_metrics_t *sorted, *per_stage;
double total_time, op_cycles;
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);
/* 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;
time_compare, metrics->op_metrics);
for (i = 0; i < num_sorted; i++)
- print_per_stage_metrics (ctx, &sorted[i], total_time);
+ print_per_stage_metrics (metrics, &sorted[i], total_time);
free (sorted);
}
-/* Called at program exit.
- *
- * This is similar to metrics_info_fini, but only frees any used
- * memory. Notably, it does not call any OpenGL functions, (since the
- * OpenGL context no longer exists at program exit).
- */
-static void
-metrics_exit (void)
-{
- context_t *ctx = context_get_current ();
- metrics_t *metrics = ctx->metrics;
- metrics_info_t *info = &ctx->metrics_info;
- unsigned i, j;
- timer_query_t *timer, *timer_next;
- monitor_t *monitor, *monitor_next;
-
- if (verbose)
- printf ("fips: terminating\n");
-
- if (! info->initialized)
- return;
-
- for (timer = metrics->timer_head;
- timer;
- timer = timer_next)
- {
- timer_next = timer->next;
- free (timer);
- }
-
- for (monitor = metrics->monitor_head;
- monitor;
- monitor = monitor_next)
- {
- monitor_next = monitor->next;
- free (monitor);
- }
-
- for (i = 0; i < info->num_groups; i++) {
- metrics_group_info_t *group = &info->groups[i];
-
- for (j = 0; j < group->num_counters; i++)
- free (group->counter_names[j]);
-
- free (group->counter_types);
- free (group->counter_names);
- free (group->counter_ids);
-
- free (group->name);
- }
-
- free (info->groups);
-
- for (i = 0; i < info->num_shader_stages; i++)
- free (info->stages[i].name);
-
- free (info->stages);
-}
-
void
-metrics_collect_available (void)
+metrics_collect_available (metrics_t *metrics)
{
- context_t *ctx = context_get_current ();
- metrics_t *metrics = ctx->metrics;
-
/* Consume all timer queries that are ready. */
timer_query_t *timer = metrics->timer_head;
glGetQueryObjectuiv (timer->id,
GL_QUERY_RESULT, &elapsed);
- accumulate_program_time (timer->op, elapsed);
+ accumulate_program_time (metrics, timer->op, elapsed);
metrics->timer_head = timer->next;
if (metrics->timer_head == NULL)
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;
result_size, result,
&bytes_written);
- accumulate_program_metrics (monitor->op, result, result_size);
+ accumulate_program_metrics (metrics, monitor->op, result, result_size);
free (result);
}
}
+/* Return the difference from ts0 to ts1 as floating-point seconds. */
+#define TIMESPEC_DIFF(ts0, ts1) (double) (ts1.tv_sec - ts0.tv_sec + \
+ (ts1.tv_nsec - ts0.tv_nsec) / 1e9)
void
-metrics_end_frame (void)
+metrics_end_frame_pre_swap (metrics_t *metrics)
+{
+ GLuint64 swap_end_timestamp, frame_time_ns, latency_ns;
+ double cpu_time;
+
+ /* 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.
+ */
+
+ glGetQueryObjectui64v (metrics->swap_end_timestamp_id,
+ GL_QUERY_RESULT, &swap_end_timestamp);
+
+ if (frames == 0) {
+ /* Print header */
+ printf ("# frame: Frame_Number Frame_Time_milliseconds Frame_latency_milliseconds CPU_load GPU_load\n");
+ } else {
+ /* Subtract previous frame's times to get frame times. */
+ frame_time_ns = swap_end_timestamp - metrics->previous_swap_end_timestamp;
+
+ latency_ns = swap_end_timestamp - metrics->swap_begin_timestamp;
+
+ cpu_time = TIMESPEC_DIFF (metrics->previous_cpu_time_ts, metrics->cpu_time_ts);
+
+ /* 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 %g %g %g %g\n",
+ frames - 1,
+ (double) frame_time_ns / 1e6,
+ (double) latency_ns / 1e6,
+ cpu_time / (frame_time_ns / 1e9),
+ 0.0);
+ }
+
+ metrics->previous_swap_end_timestamp = swap_end_timestamp;
+ metrics->previous_cpu_time_ts = metrics->cpu_time_ts;
+
+ /* 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_post_swap (metrics_t *metrics)
{
static int initialized = 0;
static struct timeval tv_start, tv_now;
+ int err;
+
+ /* 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);
+
+ /* Query the total amount of CPU time spent by this process. */
+ err = clock_gettime (CLOCK_PROCESS_CPUTIME_ID, &metrics->cpu_time_ts);
+ if (err == -1 ) {
+ fprintf (stderr, "Failed to query CPU time with clock_gettime: %s\n",
+ strerror (errno));
+ exit (1);
+ }
if (! initialized) {
gettimeofday (&tv_start, NULL);
- atexit (metrics_exit);
if (getenv ("FIPS_VERBOSE"))
verbose = 1;
initialized = 1;
}
- frames++;
+ metrics_collect_available (metrics);
- metrics_collect_available ();
+ frames++;
if (frames % 15 == 0) {
double fps;
printf("FPS: %.3f\n", fps);
- print_program_metrics ();
+ print_program_metrics (metrics);
}
+
+ /* Start the counter up again now that we're done. */
+ metrics_counter_start (metrics);
}