backend: log more timing info

Signed-off-by: Yuxuan Shui <yshuiv7@gmail.com>
This commit is contained in:
Yuxuan Shui 2023-06-14 00:22:54 +01:00
parent 037fd4c07b
commit 9956844647
No known key found for this signature in database
GPG Key ID: D3A4405BE6CC17F4
1 changed files with 19 additions and 9 deletions

View File

@ -1,5 +1,6 @@
// SPDX-License-Identifier: MPL-2.0
// Copyright (c) Yuxuan Shui <yshuiv7@gmail.com>
#include <inttypes.h>
#include <xcb/sync.h>
#include <xcb/xcb.h>
@ -82,6 +83,9 @@ void handle_device_reset(session_t *ps) {
/// paint all windows
void paint_all_new(session_t *ps, struct managed_win *t) {
struct timespec now = get_time_timespec();
auto paint_all_start_us =
(uint64_t)now.tv_sec * 1000000UL + (uint64_t)now.tv_nsec / 1000;
if (ps->backend_data->ops->device_status &&
ps->backend_data->ops->device_status(ps->backend_data) != DEVICE_STATUS_NORMAL) {
return handle_device_reset(ps);
@ -96,6 +100,12 @@ void paint_all_new(session_t *ps, struct managed_win *t) {
ps->xsync_exists = false;
}
}
now = get_time_timespec();
auto after_sync_fence_us =
(uint64_t)now.tv_sec * 1000000UL + (uint64_t)now.tv_nsec / 1000;
log_trace("Time spent on sync fence: %" PRIu64 " us",
after_sync_fence_us - paint_all_start_us);
// All painting will be limited to the damage, if _some_ of
// the paints bleed out of the damage region, it will destroy
// part of the image we want to reuse
@ -176,17 +186,17 @@ void paint_all_new(session_t *ps, struct managed_win *t) {
region_t reg_shadow_clip;
pixman_region32_init(&reg_shadow_clip);
struct timespec now;
clock_gettime(CLOCK_MONOTONIC, &now);
auto now_us = (uint64_t)(now.tv_sec * 1000000 + now.tv_nsec / 1000);
now = get_time_timespec();
auto after_damage_us = (uint64_t)now.tv_sec * 1000000UL + (uint64_t)now.tv_nsec / 1000;
log_trace("Getting damage took %" PRIu64 " us", after_damage_us - after_sync_fence_us);
if (ps->next_render > 0) {
log_trace("Render schedule deviation: %ld us (%s) %ld %ld",
labs((int64_t)now_us - (int64_t)ps->next_render),
now_us < ps->next_render ? "early" : "late", now_us,
ps->next_render);
log_trace("Render schedule deviation: %ld us (%s) %" PRIu64 " %ld",
labs((long)after_damage_us - (long)ps->next_render),
after_damage_us < ps->next_render ? "early" : "late",
after_damage_us, ps->next_render);
ps->last_schedule_delay = 0;
if (now_us > ps->next_render) {
ps->last_schedule_delay = now_us - ps->next_render;
if (after_damage_us > ps->next_render) {
ps->last_schedule_delay = after_damage_us - ps->next_render;
}
}
ps->did_render = true;