From d5d6bf63f4a55d524aa578bf8f5b0aff29226388 Mon Sep 17 00:00:00 2001 From: Gilles Schintgen Date: Sat, 30 Mar 2024 20:26:36 +0000 Subject: [PATCH 1/5] Fix frametiming for kmsgrab and x11grab This commit computes the time of the next screen capture based on the current frame's theoretical time point instead of the actual capture time. This should be slightly more precise and lead to better frame timing. --- src/platform/linux/kmsgrab.cpp | 10 ++++++++-- src/platform/linux/x11grab.cpp | 10 ++++++++-- 2 files changed, 16 insertions(+), 4 deletions(-) diff --git a/src/platform/linux/kmsgrab.cpp b/src/platform/linux/kmsgrab.cpp index e553f0beb9f..3b3bd2260f3 100644 --- a/src/platform/linux/kmsgrab.cpp +++ b/src/platform/linux/kmsgrab.cpp @@ -1203,7 +1203,10 @@ namespace platf { std::this_thread::sleep_for(1ns); now = std::chrono::steady_clock::now(); } - next_frame = now + delay; + next_frame += delay; + if (next_frame < now) { // some major slowdown happened; we couldn't keep up + next_frame = now + delay; + } std::shared_ptr img_out; auto status = snapshot(pull_free_image_cb, img_out, 1000ms, *cursor); @@ -1422,7 +1425,10 @@ namespace platf { std::this_thread::sleep_for(1ns); now = std::chrono::steady_clock::now(); } - next_frame = now + delay; + next_frame += delay; + if (next_frame < now) { // some major slowdown happened; we couldn't keep up + next_frame = now + delay; + } std::shared_ptr img_out; auto status = snapshot(pull_free_image_cb, img_out, 1000ms, *cursor); diff --git a/src/platform/linux/x11grab.cpp b/src/platform/linux/x11grab.cpp index 0a639b9cc2b..6e9a3041b0f 100644 --- a/src/platform/linux/x11grab.cpp +++ b/src/platform/linux/x11grab.cpp @@ -491,7 +491,10 @@ namespace platf { std::this_thread::sleep_for(1ns); now = std::chrono::steady_clock::now(); } - next_frame = now + delay; + next_frame += delay; + if (next_frame < now) { // some major slowdown happened; we couldn't keep up + next_frame = now + delay; + } std::shared_ptr img_out; auto status = snapshot(pull_free_image_cb, img_out, 1000ms, *cursor); @@ -632,7 +635,10 @@ namespace platf { std::this_thread::sleep_for(1ns); now = std::chrono::steady_clock::now(); } - next_frame = now + delay; + next_frame += delay; + if (next_frame < now) { // some major slowdown happened; we couldn't keep up + next_frame = now + delay; + } std::shared_ptr img_out; auto status = snapshot(pull_free_image_cb, img_out, 1000ms, *cursor); From e696a7bac8138a6932ea3115ee9987a4967ca977 Mon Sep 17 00:00:00 2001 From: Gilles Schintgen Date: Mon, 1 Apr 2024 23:19:59 +0200 Subject: [PATCH 2/5] Fix frametiming for NvFCB (Linux) --- src/platform/linux/cuda.cpp | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/platform/linux/cuda.cpp b/src/platform/linux/cuda.cpp index 33c939243f2..d620158c02c 100644 --- a/src/platform/linux/cuda.cpp +++ b/src/platform/linux/cuda.cpp @@ -809,7 +809,10 @@ namespace cuda { std::this_thread::sleep_for(1ns); now = std::chrono::steady_clock::now(); } - next_frame = now + delay; + next_frame += delay; + if (next_frame < now) { // some major slowdown happened; we couldn't keep up + next_frame = now + delay; + } std::shared_ptr img_out; auto status = snapshot(pull_free_image_cb, img_out, 150ms, *cursor); From d11cc145d2d6650fbce58ee9d8f3fbd084fc8447 Mon Sep 17 00:00:00 2001 From: Gilles Schintgen Date: Fri, 5 Apr 2024 00:01:59 +0200 Subject: [PATCH 3/5] kmsgrab: add sleep overshoot debugging --- src/platform/common.h | 5 +++++ src/platform/linux/kmsgrab.cpp | 13 +++++++++++++ 2 files changed, 18 insertions(+) diff --git a/src/platform/common.h b/src/platform/common.h index 7a4102ad5ba..eef900bf84f 100644 --- a/src/platform/common.h +++ b/src/platform/common.h @@ -11,6 +11,7 @@ #include #include "src/logging.h" +#include "src/stat_trackers.h" #include "src/thread_safe.h" #include "src/utility.h" #include "src/video_colorspace.h" @@ -499,6 +500,10 @@ namespace platf { int env_width, env_height; int width, height; + + protected: + // collect capture timing data (at loglevel debug) + stat_trackers::min_max_avg_tracker sleep_overshoot_tracker; }; class mic_t { diff --git a/src/platform/linux/kmsgrab.cpp b/src/platform/linux/kmsgrab.cpp index 3b3bd2260f3..8d7cee085bf 100644 --- a/src/platform/linux/kmsgrab.cpp +++ b/src/platform/linux/kmsgrab.cpp @@ -1415,6 +1415,8 @@ namespace platf { capture(const push_captured_image_cb_t &push_captured_image_cb, const pull_free_image_cb_t &pull_free_image_cb, bool *cursor) { auto next_frame = std::chrono::steady_clock::now(); + sleep_overshoot_tracker.reset(); + while (true) { auto now = std::chrono::steady_clock::now(); @@ -1425,6 +1427,17 @@ namespace platf { std::this_thread::sleep_for(1ns); now = std::chrono::steady_clock::now(); } + + if (config::sunshine.min_log_level <= 1) { + // Print sleep overshoot stats to debug log every 20 seconds + auto print_info = [&](double min_overshoot, double max_overshoot, double avg_overshoot) { + auto f = stat_trackers::one_digit_after_decimal(); + BOOST_LOG(debug) << "Sleep overshoot (min/max/avg): " << f % min_overshoot << "ms/" << f % max_overshoot << "ms/" << f % avg_overshoot << "ms"; + }; + std::chrono::nanoseconds overshoot_ns = std::chrono::steady_clock::now() - next_frame; + sleep_overshoot_tracker.collect_and_callback_on_interval(overshoot_ns.count() / 1000000., print_info, 20s); + } + next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up next_frame = now + delay; From 9a1d365a9cb6ebd643daa80b80884d52f5bd8fac Mon Sep 17 00:00:00 2001 From: Gilles Schintgen Date: Fri, 5 Apr 2024 00:19:46 +0200 Subject: [PATCH 4/5] Linux: simplify sleep before next frame snapshot Before this commit kmsgrab, x11grab, cuda used a "busy" wait that did not in fact keep the thread busy since it called `sleep_for()`. The whole waiting period is now slept for at once. Wlgrab used a true busy wait for a third of the waiting time. This entailed a rather high CPU usage. The watiting method has been aligned to the simplified method of the other Linux capture backends. (Benchmark data can be found in the discussion of PR #2333.) --- src/platform/linux/cuda.cpp | 6 +----- src/platform/linux/kmsgrab.cpp | 12 ++---------- src/platform/linux/wlgrab.cpp | 16 ++++++++-------- src/platform/linux/x11grab.cpp | 12 ++---------- 4 files changed, 13 insertions(+), 33 deletions(-) diff --git a/src/platform/linux/cuda.cpp b/src/platform/linux/cuda.cpp index d620158c02c..01441a326a0 100644 --- a/src/platform/linux/cuda.cpp +++ b/src/platform/linux/cuda.cpp @@ -803,11 +803,7 @@ namespace cuda { while (true) { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { - std::this_thread::sleep_for((next_frame - now) / 3 * 2); - } - while (next_frame > now) { - std::this_thread::sleep_for(1ns); - now = std::chrono::steady_clock::now(); + std::this_thread::sleep_for(next_frame - now); } next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up diff --git a/src/platform/linux/kmsgrab.cpp b/src/platform/linux/kmsgrab.cpp index 8d7cee085bf..13a60527d22 100644 --- a/src/platform/linux/kmsgrab.cpp +++ b/src/platform/linux/kmsgrab.cpp @@ -1197,11 +1197,7 @@ namespace platf { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { - std::this_thread::sleep_for((next_frame - now) / 3 * 2); - } - while (next_frame > now) { - std::this_thread::sleep_for(1ns); - now = std::chrono::steady_clock::now(); + std::this_thread::sleep_for(next_frame - now); } next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up @@ -1421,11 +1417,7 @@ namespace platf { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { - std::this_thread::sleep_for((next_frame - now) / 3 * 2); - } - while (next_frame > now) { - std::this_thread::sleep_for(1ns); - now = std::chrono::steady_clock::now(); + std::this_thread::sleep_for(next_frame - now); } if (config::sunshine.min_log_level <= 1) { diff --git a/src/platform/linux/wlgrab.cpp b/src/platform/linux/wlgrab.cpp index 2ea15359fc3..4a95d778c83 100644 --- a/src/platform/linux/wlgrab.cpp +++ b/src/platform/linux/wlgrab.cpp @@ -133,12 +133,12 @@ namespace wl { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { - std::this_thread::sleep_for((next_frame - now) / 3 * 2); + std::this_thread::sleep_for(next_frame - now); } - while (next_frame > now) { - now = std::chrono::steady_clock::now(); + next_frame += delay; + if (next_frame < now) { // some major slowdown happened; we couldn't keep up + next_frame = now + delay; } - next_frame = now + delay; std::shared_ptr img_out; auto status = snapshot(pull_free_image_cb, img_out, 1000ms, *cursor); @@ -263,12 +263,12 @@ namespace wl { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { - std::this_thread::sleep_for((next_frame - now) / 3 * 2); + std::this_thread::sleep_for(next_frame - now); } - while (next_frame > now) { - now = std::chrono::steady_clock::now(); + next_frame += delay; + if (next_frame < now) { // some major slowdown happened; we couldn't keep up + next_frame = now + delay; } - next_frame = now + delay; std::shared_ptr img_out; auto status = snapshot(pull_free_image_cb, img_out, 1000ms, *cursor); diff --git a/src/platform/linux/x11grab.cpp b/src/platform/linux/x11grab.cpp index 6e9a3041b0f..811ffe9e5bc 100644 --- a/src/platform/linux/x11grab.cpp +++ b/src/platform/linux/x11grab.cpp @@ -485,11 +485,7 @@ namespace platf { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { - std::this_thread::sleep_for((next_frame - now) / 3 * 2); - } - while (next_frame > now) { - std::this_thread::sleep_for(1ns); - now = std::chrono::steady_clock::now(); + std::this_thread::sleep_for(next_frame - now); } next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up @@ -629,11 +625,7 @@ namespace platf { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { - std::this_thread::sleep_for((next_frame - now) / 3 * 2); - } - while (next_frame > now) { - std::this_thread::sleep_for(1ns); - now = std::chrono::steady_clock::now(); + std::this_thread::sleep_for(next_frame - now); } next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up From 5737f0d3d50f99dbeaf39ee44643755492ce6b35 Mon Sep 17 00:00:00 2001 From: Gilles Schintgen Date: Fri, 5 Apr 2024 10:39:31 +0200 Subject: [PATCH 5/5] Capture/Linux: add sleep overshoot logging Logging code for sleep overshoot analysis has been added to all Linux capture backends. Duplicated code has been moved out to common platform code. --- src/platform/common.h | 15 +++++++++++++++ src/platform/linux/cuda.cpp | 6 ++++++ src/platform/linux/kmsgrab.cpp | 19 +++++++++---------- src/platform/linux/wlgrab.cpp | 12 ++++++++++++ src/platform/linux/x11grab.cpp | 12 ++++++++++++ src/platform/windows/display_base.cpp | 14 +++----------- 6 files changed, 57 insertions(+), 21 deletions(-) diff --git a/src/platform/common.h b/src/platform/common.h index eef900bf84f..007f7ece61b 100644 --- a/src/platform/common.h +++ b/src/platform/common.h @@ -10,6 +10,7 @@ #include #include +#include "src/config.h" #include "src/logging.h" #include "src/stat_trackers.h" #include "src/thread_safe.h" @@ -20,6 +21,8 @@ extern "C" { #include } +using namespace std::literals; + struct sockaddr; struct AVFrame; struct AVBufferRef; @@ -504,6 +507,18 @@ namespace platf { protected: // collect capture timing data (at loglevel debug) stat_trackers::min_max_avg_tracker sleep_overshoot_tracker; + void + log_sleep_overshoot(std::chrono::nanoseconds overshoot_ns) { + if (config::sunshine.min_log_level <= 1) { + // Print sleep overshoot stats to debug log every 20 seconds + auto print_info = [&](double min_overshoot, double max_overshoot, double avg_overshoot) { + auto f = stat_trackers::one_digit_after_decimal(); + BOOST_LOG(debug) << "Sleep overshoot (min/max/avg): " << f % min_overshoot << "ms/" << f % max_overshoot << "ms/" << f % avg_overshoot << "ms"; + }; + // std::chrono::nanoseconds overshoot_ns = std::chrono::steady_clock::now() - next_frame; + sleep_overshoot_tracker.collect_and_callback_on_interval(overshoot_ns.count() / 1000000., print_info, 20s); + } + } }; class mic_t { diff --git a/src/platform/linux/cuda.cpp b/src/platform/linux/cuda.cpp index 01441a326a0..ee535d21d2a 100644 --- a/src/platform/linux/cuda.cpp +++ b/src/platform/linux/cuda.cpp @@ -800,11 +800,17 @@ namespace cuda { handle.reset(); }); + sleep_overshoot_tracker.reset(); + while (true) { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { std::this_thread::sleep_for(next_frame - now); } + now = std::chrono::steady_clock::now(); + std::chrono::nanoseconds overshoot_ns = now - next_frame; + log_sleep_overshoot(overshoot_ns); + next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up next_frame = now + delay; diff --git a/src/platform/linux/kmsgrab.cpp b/src/platform/linux/kmsgrab.cpp index 13a60527d22..30a2470f2d3 100644 --- a/src/platform/linux/kmsgrab.cpp +++ b/src/platform/linux/kmsgrab.cpp @@ -1193,12 +1193,18 @@ namespace platf { capture(const push_captured_image_cb_t &push_captured_image_cb, const pull_free_image_cb_t &pull_free_image_cb, bool *cursor) override { auto next_frame = std::chrono::steady_clock::now(); + sleep_overshoot_tracker.reset(); + while (true) { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { std::this_thread::sleep_for(next_frame - now); } + now = std::chrono::steady_clock::now(); + std::chrono::nanoseconds overshoot_ns = now - next_frame; + log_sleep_overshoot(overshoot_ns); + next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up next_frame = now + delay; @@ -1419,16 +1425,9 @@ namespace platf { if (next_frame > now) { std::this_thread::sleep_for(next_frame - now); } - - if (config::sunshine.min_log_level <= 1) { - // Print sleep overshoot stats to debug log every 20 seconds - auto print_info = [&](double min_overshoot, double max_overshoot, double avg_overshoot) { - auto f = stat_trackers::one_digit_after_decimal(); - BOOST_LOG(debug) << "Sleep overshoot (min/max/avg): " << f % min_overshoot << "ms/" << f % max_overshoot << "ms/" << f % avg_overshoot << "ms"; - }; - std::chrono::nanoseconds overshoot_ns = std::chrono::steady_clock::now() - next_frame; - sleep_overshoot_tracker.collect_and_callback_on_interval(overshoot_ns.count() / 1000000., print_info, 20s); - } + now = std::chrono::steady_clock::now(); + std::chrono::nanoseconds overshoot_ns = now - next_frame; + log_sleep_overshoot(overshoot_ns); next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up diff --git a/src/platform/linux/wlgrab.cpp b/src/platform/linux/wlgrab.cpp index 4a95d778c83..a6ac4adbb96 100644 --- a/src/platform/linux/wlgrab.cpp +++ b/src/platform/linux/wlgrab.cpp @@ -129,12 +129,18 @@ namespace wl { capture(const push_captured_image_cb_t &push_captured_image_cb, const pull_free_image_cb_t &pull_free_image_cb, bool *cursor) override { auto next_frame = std::chrono::steady_clock::now(); + sleep_overshoot_tracker.reset(); + while (true) { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { std::this_thread::sleep_for(next_frame - now); } + now = std::chrono::steady_clock::now(); + std::chrono::nanoseconds overshoot_ns = now - next_frame; + log_sleep_overshoot(overshoot_ns); + next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up next_frame = now + delay; @@ -259,12 +265,18 @@ namespace wl { capture(const push_captured_image_cb_t &push_captured_image_cb, const pull_free_image_cb_t &pull_free_image_cb, bool *cursor) override { auto next_frame = std::chrono::steady_clock::now(); + sleep_overshoot_tracker.reset(); + while (true) { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { std::this_thread::sleep_for(next_frame - now); } + now = std::chrono::steady_clock::now(); + std::chrono::nanoseconds overshoot_ns = now - next_frame; + log_sleep_overshoot(overshoot_ns); + next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up next_frame = now + delay; diff --git a/src/platform/linux/x11grab.cpp b/src/platform/linux/x11grab.cpp index 811ffe9e5bc..0d4c3d38c30 100644 --- a/src/platform/linux/x11grab.cpp +++ b/src/platform/linux/x11grab.cpp @@ -481,12 +481,18 @@ namespace platf { capture(const push_captured_image_cb_t &push_captured_image_cb, const pull_free_image_cb_t &pull_free_image_cb, bool *cursor) override { auto next_frame = std::chrono::steady_clock::now(); + sleep_overshoot_tracker.reset(); + while (true) { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { std::this_thread::sleep_for(next_frame - now); } + now = std::chrono::steady_clock::now(); + std::chrono::nanoseconds overshoot_ns = now - next_frame; + log_sleep_overshoot(overshoot_ns); + next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up next_frame = now + delay; @@ -621,12 +627,18 @@ namespace platf { capture(const push_captured_image_cb_t &push_captured_image_cb, const pull_free_image_cb_t &pull_free_image_cb, bool *cursor) override { auto next_frame = std::chrono::steady_clock::now(); + sleep_overshoot_tracker.reset(); + while (true) { auto now = std::chrono::steady_clock::now(); if (next_frame > now) { std::this_thread::sleep_for(next_frame - now); } + now = std::chrono::steady_clock::now(); + std::chrono::nanoseconds overshoot_ns = now - next_frame; + log_sleep_overshoot(overshoot_ns); + next_frame += delay; if (next_frame < now) { // some major slowdown happened; we couldn't keep up next_frame = now + delay; diff --git a/src/platform/windows/display_base.cpp b/src/platform/windows/display_base.cpp index b258690e10e..227efe7628f 100644 --- a/src/platform/windows/display_base.cpp +++ b/src/platform/windows/display_base.cpp @@ -154,7 +154,7 @@ namespace platf::dxgi { SetThreadExecutionState(ES_CONTINUOUS); }); - stat_trackers::min_max_avg_tracker sleep_overshoot_tracker; + sleep_overshoot_tracker.reset(); while (true) { // This will return false if the HDR state changes or for any number of other @@ -184,16 +184,8 @@ namespace platf::dxgi { } else { high_precision_sleep(sleep_period); - - if (config::sunshine.min_log_level <= 1) { - // Print sleep overshoot stats to debug log every 20 seconds - auto print_info = [&](double min_overshoot, double max_overshoot, double avg_overshoot) { - auto f = stat_trackers::one_digit_after_decimal(); - BOOST_LOG(debug) << "Sleep overshoot (min/max/avg): " << f % min_overshoot << "ms/" << f % max_overshoot << "ms/" << f % avg_overshoot << "ms"; - }; - std::chrono::nanoseconds overshoot_ns = std::chrono::steady_clock::now() - sleep_target; - sleep_overshoot_tracker.collect_and_callback_on_interval(overshoot_ns.count() / 1000000., print_info, 20s); - } + std::chrono::nanoseconds overshoot_ns = std::chrono::steady_clock::now() - sleep_target; + log_sleep_overshoot(overshoot_ns); status = snapshot(pull_free_image_cb, img_out, 0ms, *cursor);