diff --git a/src/xrt/auxiliary/util/u_frame_times_widget.h b/src/xrt/auxiliary/util/u_frame_times_widget.h new file mode 100644 index 000000000..123e95606 --- /dev/null +++ b/src/xrt/auxiliary/util/u_frame_times_widget.h @@ -0,0 +1,97 @@ +// Copyright 2019, Collabora, Ltd. +// SPDX-License-Identifier: BSL-1.0 +/*! + * @file + * @brief Shared code for visualizing frametimes. + * @author Moses Turner + * @ingroup aux_util + */ + +#pragma once + +#include "xrt/xrt_defines.h" + +#include "os/os_time.h" +#include "util/u_var.h" +#include "util/u_logging.h" +#include "util/u_misc.h" + +#define FPS_WIDGET_NUM_FRAME_TIMES 50 + +struct u_frame_times_widget +{ + //! Current Index for times_ns. + int index; + + //! Timestamps of last-pushed frames. + int64_t times_ns[FPS_WIDGET_NUM_FRAME_TIMES]; + + //! Frametimes between last-pushed frames. + float timings_ms[FPS_WIDGET_NUM_FRAME_TIMES]; + + //! Average FPS of last NUM_FRAME_TIMES pushed frames. + float fps; + + struct u_var_timing *debug_var; +}; + +static inline void +u_frame_times_widget_push_sample(struct u_frame_times_widget *widget, uint64_t new_frame_time) +{ + int last_index = widget->index; + + widget->index++; + widget->index %= FPS_WIDGET_NUM_FRAME_TIMES; + + // update fps only once every FPS_NUM_TIMINGS + if (widget->index == 0) { + float total_s = 0; + + // frame *timings* are durations between *times* + int NUM_FRAME_TIMINGS = FPS_WIDGET_NUM_FRAME_TIMES - 1; + + for (int i = 0; i < NUM_FRAME_TIMINGS; i++) { + uint64_t frametime_ns = widget->times_ns[i + 1] - widget->times_ns[i]; + float frametime_s = frametime_ns * 1.f / 1000.f * 1.f / 1000.f * 1.f / 1000.f; + total_s += frametime_s; + } + float avg_frametime_s = total_s / ((float)NUM_FRAME_TIMINGS); + widget->fps = 1.f / avg_frametime_s; + } + + widget->times_ns[widget->index] = new_frame_time; + + uint64_t diff = widget->times_ns[widget->index] - widget->times_ns[last_index]; + widget->timings_ms[widget->index] = (float)diff * 1.f / 1000.f * 1.f / 1000.f; +} + +static inline void +u_frame_times_widget_init(struct u_frame_times_widget *widget, float target_frame_time_ms, float range) +{ + uint64_t now = os_monotonic_get_ns(); + for (int i = 0; i < FPS_WIDGET_NUM_FRAME_TIMES; i++) { + widget->times_ns[i] = now + i; + } + + struct u_var_timing *ft = U_TYPED_CALLOC(struct u_var_timing); + + + ft->values.data = widget->timings_ms; + ft->values.length = FPS_WIDGET_NUM_FRAME_TIMES; + ft->values.index_ptr = &widget->index; + + + ft->reference_timing = target_frame_time_ms; + ft->range = range; + ft->unit = "ms"; + ft->dynamic_rescale = false; + ft->center_reference_timing = true; + widget->debug_var = ft; +} + +// Call u_var_remove_root first! +static inline void +u_frame_times_widget_teardown(struct u_frame_times_widget *widget) +{ + free(widget->debug_var); +} diff --git a/src/xrt/compositor/main/comp_compositor.c b/src/xrt/compositor/main/comp_compositor.c index 035aa547f..8695e8456 100644 --- a/src/xrt/compositor/main/comp_compositor.c +++ b/src/xrt/compositor/main/comp_compositor.c @@ -213,39 +213,6 @@ compositor_discard_frame(struct xrt_compositor *xc, int64_t frame_id) return XRT_SUCCESS; } -static void -compositor_add_frame_timing(struct comp_compositor *c) -{ - int last_index = c->compositor_frame_times.index; - - c->compositor_frame_times.index++; - c->compositor_frame_times.index %= NUM_FRAME_TIMES; - - // update fps only once every FPS_NUM_TIMINGS - if (c->compositor_frame_times.index == 0) { - float total_s = 0; - - // frame *timings* are durations between *times* - int NUM_FRAME_TIMINGS = NUM_FRAME_TIMES - 1; - - for (int i = 0; i < NUM_FRAME_TIMINGS; i++) { - uint64_t frametime_ns = - c->compositor_frame_times.times_ns[i + 1] - c->compositor_frame_times.times_ns[i]; - float frametime_s = frametime_ns * 1.f / 1000.f * 1.f / 1000.f * 1.f / 1000.f; - total_s += frametime_s; - } - float avg_frametime_s = total_s / ((float)NUM_FRAME_TIMINGS); - c->compositor_frame_times.fps = 1.f / avg_frametime_s; - } - - c->compositor_frame_times.times_ns[c->compositor_frame_times.index] = os_monotonic_get_ns(); - - uint64_t diff = c->compositor_frame_times.times_ns[c->compositor_frame_times.index] - - c->compositor_frame_times.times_ns[last_index]; - c->compositor_frame_times.timings_ms[c->compositor_frame_times.index] = - (float)diff * 1.f / 1000.f * 1.f / 1000.f; -} - static void do_graphics_layers(struct comp_compositor *c) { @@ -376,7 +343,7 @@ compositor_layer_commit(struct xrt_compositor *xc, int64_t frame_id, xrt_graphic comp_renderer_draw(c->r); - compositor_add_frame_timing(c); + u_frame_times_widget_push_sample(&c->compositor_frame_times, os_monotonic_get_ns()); // Record the time of this frame. c->last_frame_time_ns = os_monotonic_get_ns(); @@ -465,9 +432,9 @@ compositor_destroy(struct xrt_compositor *xc) vk->instance = VK_NULL_HANDLE; } - if (c->compositor_frame_times.debug_var) { - free(c->compositor_frame_times.debug_var); - } + u_var_remove_root(c); + + u_frame_times_widget_teardown(&c->compositor_frame_times); comp_base_fini(&c->base); @@ -1311,37 +1278,24 @@ xrt_gfx_provider_create_system(struct xrt_device *xdev, struct xrt_system_compos sys_info->supported_blend_mode_count = (uint8_t)xdev->hmd->blend_mode_count; u_var_add_root(c, "Compositor", true); - u_var_add_ro_f32(c, &c->compositor_frame_times.fps, "FPS (Compositor)"); - u_var_add_bool(c, &c->debug.atw_off, "Debug: ATW OFF"); - - struct u_var_timing *ft = U_TYPED_CALLOC(struct u_var_timing); float target_frame_time_ms = ns_to_ms(c->settings.nominal_frame_interval_ns); + u_frame_times_widget_init(&c->compositor_frame_times, target_frame_time_ms, 10.f); + + u_var_add_ro_f32(c, &c->compositor_frame_times.fps, "FPS (Compositor)"); + u_var_add_bool(c, &c->debug.atw_off, "Debug: ATW OFF"); + u_var_add_f32_timing(c, c->compositor_frame_times.debug_var, "Frame Times (Compositor)"); + + //! @todo: Query all supported refresh rates of the current mode sys_info->num_refresh_rates = 1; sys_info->refresh_rates[0] = 1. / time_ns_to_s(c->settings.nominal_frame_interval_ns); - uint64_t now = os_monotonic_get_ns(); - for (int i = 0; i < NUM_FRAME_TIMES; i++) { - c->compositor_frame_times.times_ns[i] = now + i; - } - ft->values.data = c->compositor_frame_times.timings_ms; - ft->values.length = NUM_FRAME_TIMES; - ft->values.index_ptr = &c->compositor_frame_times.index; - ft->reference_timing = target_frame_time_ms; - ft->range = 10.f; - ft->unit = "ms"; - ft->dynamic_rescale = false; - ft->center_reference_timing = true; - - u_var_add_f32_timing(c, ft, "Frame Times (Compositor)"); comp_renderer_add_debug_vars(c->r); - c->compositor_frame_times.debug_var = ft; - c->state = COMP_STATE_READY; comp_base_init(&c->base); diff --git a/src/xrt/compositor/main/comp_compositor.h b/src/xrt/compositor/main/comp_compositor.h index 0e02d26fb..d1d096b2c 100644 --- a/src/xrt/compositor/main/comp_compositor.h +++ b/src/xrt/compositor/main/comp_compositor.h @@ -16,6 +16,7 @@ #include "util/u_threading.h" #include "util/u_index_fifo.h" #include "util/u_logging.h" +#include "util/u_frame_times_widget.h" #include "util/comp_base.h" #include "util/comp_sync.h" @@ -33,7 +34,6 @@ extern "C" { #endif -#define NUM_FRAME_TIMES 50 #define COMP_MAX_LAYERS 16 /* @@ -115,22 +115,7 @@ struct comp_compositor int64_t last_end; } app_profiling; - struct - { - //! Current Index for times_ns. - int index; - - //! Timestamps of last-rendered (immersive) frames. - int64_t times_ns[NUM_FRAME_TIMES]; - - //! Frametimes between last-rendered (immersive) frames. - float timings_ms[NUM_FRAME_TIMES]; - - //! Average FPS of last NUM_FRAME_TIMES rendered frames. - float fps; - - struct u_var_timing *debug_var; - } compositor_frame_times; + struct u_frame_times_widget compositor_frame_times; struct { diff --git a/src/xrt/compositor/main/comp_renderer.c b/src/xrt/compositor/main/comp_renderer.c index e3cfa15f9..6eedd0c42 100644 --- a/src/xrt/compositor/main/comp_renderer.c +++ b/src/xrt/compositor/main/comp_renderer.c @@ -27,6 +27,7 @@ #include "util/u_sink.h" #include "util/u_var.h" #include "util/u_frame.h" +#include "util/u_frame_times_widget.h" #include "main/comp_layer_renderer.h" @@ -66,6 +67,13 @@ struct comp_renderer { // Hint: enable/disable is in c->mirroring_to_debug_gui. It's there because comp_renderer is just a // forward decl to comp_compositor.c + + struct u_frame_times_widget push_frame_times; + + float target_frame_time_ms; + uint64_t last_push_ts_ns; + int push_every_frame_out_of_X; + struct u_sink_debug debug_sink; VkExtent2D image_extent; uint64_t sequence; @@ -776,6 +784,9 @@ renderer_destroy(struct comp_renderer *r) } comp_layer_renderer_destroy(&(r->lr)); + + u_var_remove_root(r); + u_frame_times_widget_teardown(&r->mirror_to_debug_gui.push_frame_times); } static VkImageView @@ -1265,10 +1276,44 @@ comp_renderer_set_equirect2_layer(struct comp_renderer *r, } #endif +static void +mirror_to_debug_gui_fixup_ui_state(struct comp_renderer *r) +{ + // One out of every zero frames is not what we want! + // Also one out of every negative two frames, etc. is nonsensical + if (r->mirror_to_debug_gui.push_every_frame_out_of_X < 1) { + r->mirror_to_debug_gui.push_every_frame_out_of_X = 1; + } + + r->mirror_to_debug_gui.target_frame_time_ms = (double)r->mirror_to_debug_gui.push_every_frame_out_of_X * + (double)r->c->settings.nominal_frame_interval_ns / + (double)U_TIME_1MS_IN_NS; + + r->mirror_to_debug_gui.push_frame_times.debug_var->reference_timing = + r->mirror_to_debug_gui.target_frame_time_ms; + r->mirror_to_debug_gui.push_frame_times.debug_var->range = r->mirror_to_debug_gui.target_frame_time_ms; +} + static bool can_mirror_to_debug_gui(struct comp_renderer *r) { - return r->c->mirroring_to_debug_gui && u_sink_debug_is_active(&r->mirror_to_debug_gui.debug_sink); + if (!r->c->mirroring_to_debug_gui || !u_sink_debug_is_active(&r->mirror_to_debug_gui.debug_sink)) { + return false; + } + + uint64_t now = r->c->frame.rendering.predicted_display_time_ns; + + double diff_s = (double)(now - r->mirror_to_debug_gui.last_push_ts_ns) / (double)U_TIME_1MS_IN_NS; + + // Completely unscientific - lower values probably works fine too. + // I figure we don't have very many 500Hz displays and this woorks great for 120-144hz + double slop_ms = 2; + + if (diff_s < r->mirror_to_debug_gui.target_frame_time_ms - slop_ms) { + return false; + } + r->mirror_to_debug_gui.last_push_ts_ns = now; + return true; } static void @@ -1287,28 +1332,6 @@ mirror_to_debug_gui_do_blit(struct comp_renderer *r) VkImage copy_from = r->lr->framebuffers[0].image; -#if 0 - bool fast = r->c->base.slot.one_projection_layer_fast_path; - - - if (fast) { - switch (layer->data.type) { - case XRT_LAYER_STEREO_PROJECTION: { - copy_from = layer->sc_array[0]->vkic.images[layer->data.stereo.l.sub.image_index].handle; - } break; - case XRT_LAYER_STEREO_PROJECTION_DEPTH: { - copy_from = layer->sc_array[0]->vkic.images[layer->data.stereo_depth.l.sub.image_index].handle; - } break; - default: assert(false); - } - } else { - - - } -#endif - - - VkImageSubresourceRange first_color_level_subresource_range = { .aspectMask = VK_IMAGE_ASPECT_COLOR_BIT, .baseMipLevel = 0, @@ -1410,6 +1433,9 @@ mirror_to_debug_gui_do_blit(struct comp_renderer *r) struct xrt_frame *frame = &wrap->base_frame; wrap = NULL; u_sink_debug_push_frame(&r->mirror_to_debug_gui.debug_sink, frame); + u_frame_times_widget_push_sample(&r->mirror_to_debug_gui.push_frame_times, + r->c->frame.rendering.predicted_display_time_ns); + xrt_frame_reference(&frame, NULL); } @@ -1464,6 +1490,7 @@ comp_renderer_draw(struct comp_renderer *r) // Clear the frame. c->frame.rendering.id = -1; + mirror_to_debug_gui_fixup_ui_state(r); if (can_mirror_to_debug_gui(r)) { mirror_to_debug_gui_do_blit(r); } @@ -1541,7 +1568,19 @@ comp_renderer_destroy(struct comp_renderer **ptr_r) void comp_renderer_add_debug_vars(struct comp_renderer *r) { - // 1.2 % 2.3; - u_var_add_bool(r->c, &r->c->mirroring_to_debug_gui, "Display left eye to GUI (slow)"); - u_var_add_sink_debug(r->c, &r->mirror_to_debug_gui.debug_sink, "Left view!"); + r->mirror_to_debug_gui.push_every_frame_out_of_X = 2; + + u_frame_times_widget_init(&r->mirror_to_debug_gui.push_frame_times, 0.f, 0.f); + mirror_to_debug_gui_fixup_ui_state(r); + + u_var_add_root(r, "Readback", true); + + u_var_add_bool(r, &r->c->mirroring_to_debug_gui, "Readback left eye to debug GUI"); + u_var_add_i32(r, &r->mirror_to_debug_gui.push_every_frame_out_of_X, "Push 1 frame out of every X frames"); + + u_var_add_ro_f32(r, &r->mirror_to_debug_gui.push_frame_times.fps, "FPS (Readback)"); + u_var_add_f32_timing(r, r->mirror_to_debug_gui.push_frame_times.debug_var, "Frame Times (Readback)"); + + + u_var_add_sink_debug(r, &r->mirror_to_debug_gui.debug_sink, "Left view!"); }