Kai investigating better timers:tm:

Ok so this is the kind of problem I like

14 Replies

Kai•10mo ago

Ok so made a bench setup, and I think this is fairly optimal.

Kai•10mo ago

https://i.kaij.tech/file/2023/08/1692619428_grim.png

Kai•10mo ago

I chose a bad rolling average here (10, but the period is 1 so it's now also wobbling) goes around ~16.3 to 16.7 so I think it's pretty good for 60FPS The "real" timings here are between 16ms and 17ms - not much to do there, that's just the resolution

Kai•10mo ago

https://i.kaij.tech/file/2023/08/1692619683_grim.png

Kai•10mo ago

CPU timings for this baseline - as expected this pins the CPU it's on (in green) to 100% (depicted is the idle CPU)

Kai•10mo ago

https://i.kaij.tech/file/2023/08/1692621619_grim.png

Kai•10mo ago

Did this now - CPU usage is minimal (picture follows)

Kai•10mo ago

https://i.kaij.tech/file/2023/08/1692621767_grim.png

Kai•10mo ago

(again idle times, green is the relevant CPU) (also for some reason the viewer has pissed itself with this one) but as you can probably not tell, CPU usage is minimal (< 5%) I feel like dropping a few frames is fine? (I'd consider the 5 peaks you can see as "dropped frames" essentially) Like, if you enable V-Sync this code should never run -> no dropped frames and what I'm about to test, if you actually have performance problems, this code should also never run !! Also - note that this test emulates a single-core system, the process is tied to a specific core, and as this relies on the OS to re-schedule as a little bit later, other processes may contest the one core we use, which then causes these dropped frames. Tested the maxed CPU now, thanks to @khitiara, had to write the results to /dev/null or JIT would be smart. Results look similar to the above, with a few dropped frames. CPU is pinned at nearly 100%, which is expected given the inner loop can't keep up.

Kai•10mo ago

https://i.kaij.tech/file/2023/08/1692635096_grim.png

Kai•10mo ago

^ This can still run at slightly above 60FPS, which is why we still see some drops from other processes contesting the core we use

Kai•10mo ago

https://i.kaij.tech/file/2023/08/1692635432_grim.png

Kai•10mo ago

here is something that can run at 10 or so FPS (not sure if my math is correct) - the limiter is still set to allow up to 60 FPS as you can see, there are no "dropped" frames, I'd attribute any variance to the numbers being random and just general background noise. I'm still not sure the occasional stutter is worth the tradeoff of just pinning a CPU thread, I'm really not sure

// This is an atomic bitflag
// - flush file
// - record cpu

using System.Buffers.Binary;
using System.Diagnostics;
using System.Security.Cryptography;

const uint SECONDS_TO_RUN_TESTS = 30;

Process proc         = Process.GetCurrentProcess();
long    affinityMask = 0b0100;
proc.ProcessorAffinity = (IntPtr)affinityMask;

var cpuThread = new Thread(() => CPUUsageThread());
cpuThread.Start();

var csv_file = "./timings.csv";

var abs_start = Stopwatch.GetTimestamp();

var start_timestamp          = Stopwatch.GetTimestamp();
var target_fps               = 60;
var ms_per_frame_floor_div_2 = (int)Math.Floor(1000.0 / (target_fps * 2));
var ticks_per_frame     = ((double)TimeSpan.TicksPerSecond) / target_fps;
var corrective_tick          = false;

var average_rest_of_time_slice_ticks = TimeSpan.TicksPerMillisecond * 16;
var num_samples                      = 1l;


while (true) {
    var loop_head_timestmap = Stopwatch.GetTimestamp();
    var frame_ticks         = corrective_tick ? (long)Math.Ceiling(ticks_per_frame) : (long)Math.Floor(ticks_per_frame);
    var ticks_left          = frame_ticks - Stopwatch.GetElapsedTime(start_timestamp, loop_head_timestmap).Ticks;
    if (ticks_left <= 0) {
        if (ticks_left < -(ticks_per_frame / 2)) {
            Console.WriteLine($"Can't keep up! - Dropped {(double)ticks_left / (double)-ticks_per_frame}");
        }
        
        corrective_tick = !corrective_tick;
        start_timestamp = loop_head_timestmap;

        DoWork();
        if (Stopwatch.GetElapsedTime(abs_start, loop_head_timestmap).TotalSeconds >= SECONDS_TO_RUN_TESTS) {
            break;
        }
    }
    else if (ticks_left >= average_rest_of_time_slice_ticks) {
        var start_sleep_ts = Stopwatch.GetTimestamp();
        Thread.Sleep(ms_per_frame_floor_div_2);
        var end_sleep_ts                 = Stopwatch.GetTimestamp();
        var new_rest_of_time_slice_ticks = Stopwatch.GetElapsedTime(start_sleep_ts, end_sleep_ts).Ticks;
        average_rest_of_time_slice_ticks =  average_rest_of_time_slice_ticks + (new_rest_of_time_slice_ticks - average_rest_of_time_slice_ticks) / (num_samples + 1);
        num_samples                      += 1;
    }
}

void DoWork() {
    File.AppendAllText(csv_file, $"{DateTimeOffset.UtcNow.ToUnixTimeMilliseconds()}\n");

    double d = 0;
    for (int i = 0; i < 10_000_000; i++) {
        d += Random.Shared.NextDouble();
        d /= 2;
    }

    var bytes = new byte[8];
    BinaryPrimitives.WriteDoubleBigEndian(bytes, d);
    File.WriteAllBytes("/dev/null", bytes);
}

void CPUUsageThread() {
    Process proc         = Process.GetCurrentProcess();
    long    affinityMask = 0b0010;
    proc.ProcessorAffinity = (IntPtr)affinityMask;

    var info = new ProcessStartInfo("mpstat", $"-P \"1,2,3\" -o JSON 1 {SECONDS_TO_RUN_TESTS + 5}"); // 5s run off
    info.RedirectStandardOutput = true;
    var p    = Process.Start(info);
    p!.ProcessorAffinity = ~0b11;
    using var stdout = p.StandardOutput.BaseStream;
    using var file = File.OpenWrite("./CPU.json");
    stdout.CopyTo(file);
}

// This is an atomic bitflag
// - flush file
// - record cpu

using System.Buffers.Binary;
using System.Diagnostics;
using System.Security.Cryptography;

const uint SECONDS_TO_RUN_TESTS = 30;

Process proc         = Process.GetCurrentProcess();
long    affinityMask = 0b0100;
proc.ProcessorAffinity = (IntPtr)affinityMask;

var cpuThread = new Thread(() => CPUUsageThread());
cpuThread.Start();

var csv_file = "./timings.csv";

var abs_start = Stopwatch.GetTimestamp();

var start_timestamp          = Stopwatch.GetTimestamp();
var target_fps               = 60;
var ms_per_frame_floor_div_2 = (int)Math.Floor(1000.0 / (target_fps * 2));
var ticks_per_frame     = ((double)TimeSpan.TicksPerSecond) / target_fps;
var corrective_tick          = false;

var average_rest_of_time_slice_ticks = TimeSpan.TicksPerMillisecond * 16;
var num_samples                      = 1l;


while (true) {
    var loop_head_timestmap = Stopwatch.GetTimestamp();
    var frame_ticks         = corrective_tick ? (long)Math.Ceiling(ticks_per_frame) : (long)Math.Floor(ticks_per_frame);
    var ticks_left          = frame_ticks - Stopwatch.GetElapsedTime(start_timestamp, loop_head_timestmap).Ticks;
    if (ticks_left <= 0) {
        if (ticks_left < -(ticks_per_frame / 2)) {
            Console.WriteLine($"Can't keep up! - Dropped {(double)ticks_left / (double)-ticks_per_frame}");
        }
        
        corrective_tick = !corrective_tick;
        start_timestamp = loop_head_timestmap;

        DoWork();
        if (Stopwatch.GetElapsedTime(abs_start, loop_head_timestmap).TotalSeconds >= SECONDS_TO_RUN_TESTS) {
            break;
        }
    }
    else if (ticks_left >= average_rest_of_time_slice_ticks) {
        var start_sleep_ts = Stopwatch.GetTimestamp();
        Thread.Sleep(ms_per_frame_floor_div_2);
        var end_sleep_ts                 = Stopwatch.GetTimestamp();
        var new_rest_of_time_slice_ticks = Stopwatch.GetElapsedTime(start_sleep_ts, end_sleep_ts).Ticks;
        average_rest_of_time_slice_ticks =  average_rest_of_time_slice_ticks + (new_rest_of_time_slice_ticks - average_rest_of_time_slice_ticks) / (num_samples + 1);
        num_samples                      += 1;
    }
}

void DoWork() {
    File.AppendAllText(csv_file, $"{DateTimeOffset.UtcNow.ToUnixTimeMilliseconds()}\n");

    double d = 0;
    for (int i = 0; i < 10_000_000; i++) {
        d += Random.Shared.NextDouble();
        d /= 2;
    }

    var bytes = new byte[8];
    BinaryPrimitives.WriteDoubleBigEndian(bytes, d);
    File.WriteAllBytes("/dev/null", bytes);
}

void CPUUsageThread() {
    Process proc         = Process.GetCurrentProcess();
    long    affinityMask = 0b0010;
    proc.ProcessorAffinity = (IntPtr)affinityMask;

    var info = new ProcessStartInfo("mpstat", $"-P \"1,2,3\" -o JSON 1 {SECONDS_TO_RUN_TESTS + 5}"); // 5s run off
    info.RedirectStandardOutput = true;
    var p    = Process.Start(info);
    p!.ProcessorAffinity = ~0b11;
    using var stdout = p.StandardOutput.BaseStream;
    using var file = File.OpenWrite("./CPU.json");
    stdout.CopyTo(file);
}

^ this is the entire code I used to make these measurements If someone is interested in viewing the data the way I did, I used https://rerun.io + a small python script (can share that of course) If we want to consider this as an actual replacement, we'd still have to test how this does in a 24h test, as a monotonic counter is involved for estimating the sleep time, which might overflow...

Perksey•10mo ago

oh hello why aren't I in this thread

Gaming

Programming

Kai investigating better timers:tm: