X-Git-Url: https://git.cworth.org/git?a=blobdiff_plain;f=metrics.c;h=ad7ea3a330cc27b6354e13a8070209b0b406bd13;hb=refs%2Fheads%2Fframe-timings;hp=1c8a973aec28e7cc23400270b298f693d1232993;hpb=85faadffd4f13cefceec2c3166b3e1596d4bfd35;p=fips diff --git a/metrics.c b/metrics.c index 1c8a973..ad7ea3a 100644 --- a/metrics.c +++ b/metrics.c @@ -74,6 +74,9 @@ typedef struct op_metrics struct metrics { + /* Flag to indicate first frame is being processed. */ + bool first_frame; + /* Description of all available peformance counters, counter * groups, their names and IDs, etc. */ metrics_info_t *info; @@ -113,6 +116,28 @@ struct metrics struct timespec cpu_time_ts; }; +/* Return (a - b) while accounting for the fact that between a and b, + * the counter may have wrapped around (with a maximum number of bits + * in the counter of GL_QUERY_COUNTER_BITS). */ +static uint64_t +subtract_timestamp (uint64_t a, uint64_t b) +{ + GLint timestamp_bits; + + glGetQueryiv (GL_TIMESTAMP, GL_QUERY_COUNTER_BITS, ×tamp_bits); + + /* Note: "<<" isn't defined for the number of bits in the + * type, and the compiler will punish you. + */ + if (timestamp_bits == 64) + return a - b; + + if (b > a) + return (1ull << timestamp_bits) + a - b; + else + return a - b; +} + metrics_t * metrics_create (metrics_info_t *info) { @@ -122,6 +147,8 @@ metrics_create (metrics_info_t *info) metrics->info = info; + metrics->first_frame = true; + metrics->op = 0; metrics->timer_begun_id = 0; @@ -144,6 +171,9 @@ metrics_create (metrics_info_t *info) /* 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; } @@ -155,7 +185,6 @@ metrics_fini (metrics_t *metrics) /* Discard and cleanup any outstanding queries. */ if (metrics->timer_begun_id) { - glEndQuery (GL_TIME_ELAPSED); glDeleteQueries (1, &metrics->timer_begun_id); metrics->timer_begun_id = 0; } @@ -174,7 +203,6 @@ metrics_fini (metrics_t *metrics) 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; } @@ -530,6 +558,7 @@ print_per_stage_metrics (metrics_t *metrics, const char *op_string; unsigned group_index, counter; double value; + int program_name_length = 0; /* Don't print anything for stages with no alloted time. */ if (per_stage->time_ns == 0.0) @@ -537,13 +566,29 @@ print_per_stage_metrics (metrics_t *metrics, op_string = metrics_op_string (op_metrics->op); - printf ("%21s", op_string); - if (op_metrics->op >= METRICS_OP_SHADER) { - printf (" %3d", op_metrics->op - METRICS_OP_SHADER); - } else { - printf (" "); + int program = op_metrics->op - METRICS_OP_SHADER; + glGetObjectLabel (GL_PROGRAM, program, 0, + &program_name_length, NULL); + if (program_name_length) { + char *program_name; + + program_name = malloc(program_name_length + 1); + if (program_name == 0) { + fprintf (stderr, "Out of memory.\n"); + exit (1); + } + glGetObjectLabel (GL_PROGRAM, program, + program_name_length + 1, + NULL, program_name); + printf ("%21s ", program_name); + } else { + printf ("%21s %3d", op_string, program); + } + } + else { + printf ("%21s ", op_string); } if (per_stage->stage) @@ -794,9 +839,9 @@ metrics_collect_available (metrics_t *metrics) } } -/* 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) +/* Subtract timespec values: Return (a - b) in seconds as a double. */ +#define SUBTRACT_TIMESPEC(a, b) (double) (a.tv_sec - b.tv_sec + \ + (a.tv_nsec - b.tv_nsec) / 1e9) void metrics_end_frame_pre_swap (metrics_t *metrics) @@ -827,17 +872,22 @@ metrics_end_frame_pre_swap (metrics_t *metrics) glGetQueryObjectui64v (metrics->swap_end_timestamp_id, GL_QUERY_RESULT, &swap_end_timestamp); - - if (frames == 0) { + + if (metrics->first_frame) { /* Print header */ printf ("# frame: Frame_Number Frame_Time_milliseconds Frame_latency_milliseconds CPU_load GPU_load\n"); + + metrics->first_frame = false; } else { /* Subtract previous frame's times to get frame times. */ - frame_time_ns = swap_end_timestamp - metrics->previous_swap_end_timestamp; + frame_time_ns = subtract_timestamp (swap_end_timestamp, + metrics->previous_swap_end_timestamp); - latency_ns = swap_end_timestamp - metrics->swap_begin_timestamp; + latency_ns = subtract_timestamp (swap_end_timestamp, + metrics->swap_begin_timestamp); - cpu_time = TIMESPEC_DIFF (metrics->previous_cpu_time_ts, metrics->cpu_time_ts); + cpu_time = SUBTRACT_TIMESPEC (metrics->cpu_time_ts, + metrics->previous_cpu_time_ts); /* We've waited one frame to ensure we have a timestamp * result. So the time we've actually measured here is @@ -894,7 +944,7 @@ metrics_end_frame_post_swap (metrics_t *metrics) frames++; - if (frames % 15 == 0) { + if (frames) { double fps; gettimeofday (&tv_now, NULL);