implement elapsed time tracking for audio

src/platform/audio.zig

@@ -3,6 +3,7 @@ const log = std.log.scoped(.audio);
 const Io = std.Io;
 const Allocator = std.mem.Allocator;
 const assert = std.debug.assert;
+const build_options = @import("build_options");
 
 const sokol = @import("sokol");
 const sapp = sokol.app;
@@ -85,6 +86,10 @@ const ThreadState = struct {
     mutex: std.Io.Mutex,
 
     sounds: Sound.SlotMap,
+    bus_volumes: []f32,
+
+    elapsed_time_ms: ?[]f32 = null,
+    budget_reached_counter: u32 = 0
 };
 
 const State = struct {
@@ -112,6 +117,8 @@ pub const InitOptions = struct {
     max_sounds: usize = 256,
     max_buses: usize = 16,
     max_vorbis_alloc_buffer_size: u32 = 1 * Math.bytes_per_mib,
+
+    track_elapsed_time: bool = build_options.has_imgui
 };
 
 pub fn init(io: Io, gpa: std.mem.Allocator, opts: InitOptions) !void {
@@ -120,6 +127,9 @@ pub fn init(io: Io, gpa: std.mem.Allocator, opts: InitOptions) !void {
     var buses = try std.ArrayList(Bus).initCapacity(gpa, opts.max_buses);
     errdefer buses.deinit(gpa);
 
+    const bus_volumes = try gpa.alloc(f32, opts.max_buses);
+    errdefer gpa.free(bus_volumes);
+
     var buffers = try std.ArrayList(Buffer).initCapacity(gpa, opts.max_buffers);
     errdefer buffers.deinit(gpa);
 
@@ -138,9 +148,9 @@ pub fn init(io: Io, gpa: std.mem.Allocator, opts: InitOptions) !void {
         .thread_state = .{
             .mutex = .init,
             .sounds = .init(sounds),
+            .bus_volumes = bus_volumes,
         }
     };
-    self.running.store(true, .seq_cst);
 
     main_bus = addBus(.{
         .label = "main"
@@ -155,16 +165,30 @@ pub fn init(io: Io, gpa: std.mem.Allocator, opts: InitOptions) !void {
         .sample_rate = g_sample_rate
     });
 
+    if (opts.track_elapsed_time) {
+        const measurements_per_second: usize = @intCast(@divFloor(std.time.ns_per_s, getMaxAudioThreadDuration().nanoseconds));
+        self.thread_state.elapsed_time_ms = try gpa.alloc(f32, 3*measurements_per_second);
+        @memset(self.thread_state.elapsed_time_ms.?, 0);
+    }
+
     log.debug("Init:", .{});
     log.debug("- sample_rate: {}", .{saudio.sampleRate()});
     log.debug("- channels: {}", .{saudio.channels()});
     log.debug("- buffer_frames: {}", .{saudio.bufferFrames()});
+    log.debug("- max callback duration: {f}", .{getMaxAudioThreadDuration()});
+
+    self.running.store(true, .seq_cst);
 }
 
 pub fn deinit(gpa: std.mem.Allocator) void {
     var self = &g_state;
 
-    self.running.store(false, .seq_cst);
+    {
+        self.thread_state.mutex.lock(self.io) catch @panic("Failed to lock audio mutex");
+        defer self.thread_state.mutex.unlock(self.io);
+
+        self.running.store(false, .seq_cst);
+    }
 
     saudio.shutdown();
 
@@ -175,6 +199,10 @@ pub fn deinit(gpa: std.mem.Allocator) void {
 
     self.buses.deinit(gpa);
     gpa.free(self.thread_state.sounds.slots.allocatedSlice());
+    gpa.free(self.thread_state.bus_volumes);
+    if (self.thread_state.elapsed_time_ms) |elapsed_time_ms| {
+        gpa.free(elapsed_time_ms);
+    }
     gpa.free(self.vorbis_alloc_buffer);
 }
 
@@ -420,17 +448,51 @@ pub fn getBus(id: BusId) ?*Bus {
 pub fn showDebug() void {
     const self = &g_state;
 
-    if (ImGUI.beginWindow(.{
+    const sounds = &self.thread_state.sounds;
-        .name = "audio",
+    const buses = &self.buses;
-        .size = .init(200, 200)
+    const buffers = &self.buffers;
-    })) {
-        defer ImGUI.endWindow();
 
-        const sounds = &self.thread_state.sounds;
+    _ = ImGUI.beginTabBar("audio tab bar");
-        const buses = &self.buses;
+    defer ImGUI.endTabBar();
 
+    if (ImGUI.beginTabItem("General")) {
+        defer ImGUI.endTabItem();
+
+        ImGUI.text("Buffers: {}/{}", .{buffers.items.len, buffers.capacity});
+        ImGUI.text("Buses: {}/{}", .{buses.items.len, buses.capacity});
         ImGUI.text("Sounds: {}/{}", .{sounds.count(), sounds.slots.capacity});
 
+        if (self.thread_state.elapsed_time_ms) |elapsed_time_ms| {
+            ImGUI.separator();
+
+            ImGUI.plotLines(.{
+                .label = "Elapsed (ms)",
+                .values = elapsed_time_ms,
+                .ex = .{
+                    .scale_max = getMaxAudioThreadDurationMs()
+                }
+            });
+
+            var min_elapsed = elapsed_time_ms[0];
+            var max_elapsed = elapsed_time_ms[0];
+            var sum_elapsed = elapsed_time_ms[0];
+            for (elapsed_time_ms[1..]) |duration_ms| {
+                min_elapsed = @min(min_elapsed, duration_ms);
+                max_elapsed = @max(max_elapsed, duration_ms);
+                sum_elapsed += duration_ms;
+            }
+            const avg_elapsed = sum_elapsed / @as(f32, @floatFromInt(elapsed_time_ms.len));
+            ImGUI.text("Min/Max/Avg: {:.3}ms/{:.3}ms/{:.3}ms{s}", .{
+                min_elapsed, max_elapsed, avg_elapsed,
+                if (max_elapsed > getMaxAudioThreadDurationMs()) " !!!" else ""
+            });
+        }
+
+        ImGUI.separator();
+        ImGUI.text("Budget reached counter: {}", .{self.thread_state.budget_reached_counter});
+    }
+    if (ImGUI.beginTabItem("Buses")) {
+        defer ImGUI.endTabItem();
         if(ImGUI.beginTable("buses", 3, 0)) {
             defer ImGUI.endTable();
 
@@ -466,34 +528,54 @@ pub fn showDebug() void {
     }
 }
 
+fn getMaxAudioThreadDuration() Io.Duration {
+    const margin = 0.05;
+    return Io.Duration{
+        .nanoseconds = @divFloor((@as(i64, @intFromFloat(@as(f64, @floatFromInt(std.time.ns_per_s)) * (1 - margin)))) * @as(i64, saudio.bufferFrames()), saudio.sampleRate())
+    };
+}
+
+fn getMaxAudioThreadDurationMs() f32 {
+    return @floatCast(@as(f64, @floatFromInt(getMaxAudioThreadDuration().nanoseconds)) / std.time.ns_per_ms);
+}
+
 fn sokolStream(output_buffer: [*c]f32, num_frames: u32, num_channels: u32) !void {
     const self = &g_state;
 
+    const started_at = Io.Clock.awake.now(self.io);
+
+    var zone = tracy.initZone(@src(), .{});
+    defer zone.deinit();
+
+    const mutex = &self.thread_state.mutex;
+    const sounds = &self.thread_state.sounds;
+    const buses = self.buses.items;
+    const bus_volumes = self.thread_state.bus_volumes;
+
+    try mutex.lock(self.io);
+    defer mutex.unlock(self.io);
+
     if (!self.running.load(.seq_cst)) {
         return;
     }
 
-    const mutex = &self.thread_state.mutex;
-    const sounds = &self.thread_state.sounds;
-    const buses = self.buses;
-
-    try mutex.lock(self.io);
-    defer mutex.unlock(self.io);
-
     assert(num_channels == 2);
     @memset(output_buffer[0..(num_frames*2)], 0);
 
+    for (0..buses.len) |i| {
+        bus_volumes[i] = busMultipliedVolume(.{ .index = @intCast(i) });
+    }
+
     var sound_iter = sounds.iterator();
     while (sound_iter.next()) |sound_id| {
         const sound = sounds.getAssumeExists(sound_id);
         const buffer = &self.buffers.items[sound.buffer.index];
 
         const bus_id = sound.bus;
-        const bus = buses.items[bus_id.index];
+        const bus = buses[bus_id.index];
         _ = bus; // autofix
-        const bus_volume = busMultipliedVolume(bus_id);
 
-        const volume = sound.volume * bus_volume;
+        const volume = sound.volume * bus_volumes[bus_id.index];
 
         const left_channel = buffer.samples.left;
         const right_channel = buffer.samples.right orelse buffer.samples.left;
@@ -523,6 +605,16 @@ fn sokolStream(output_buffer: [*c]f32, num_frames: u32, num_channels: u32) !void
             sounds.removeAssumeExists(sound_id);
         }
     }
+
+    const duration = started_at.durationTo(Io.Clock.awake.now(self.io));
+    if (self.thread_state.elapsed_time_ms) |elapsed_time_ms| {
+        @memmove(elapsed_time_ms[1..elapsed_time_ms.len], elapsed_time_ms[0..(elapsed_time_ms.len-1)]);
+        elapsed_time_ms[0] = @floatCast(@as(f64, @floatFromInt(duration.nanoseconds)) / std.time.ns_per_ms);
+    }
+
+    if (duration.nanoseconds > getMaxAudioThreadDuration().nanoseconds) {
+        self.thread_state.budget_reached_counter += 1;
+    }
 }
 
 fn sokolStreamCallback(buffer: [*c]f32, num_frames_i32: i32, num_channels: i32) callconv(.c) void {

src/platform/file_watcher.zig

@@ -288,7 +288,7 @@ fn nextEvents(self: *FileWatcher) !?*File {
 }
 
 pub fn next(self: *FileWatcher, io: Io) !?[]const u8 {
-    const now = Io.Clock.real.now(io);
+    const now = Io.Clock.awake.now(io);
 
     var queue_overflow = false;
     while (true) {

src/platform/imgui.zig

@@ -559,3 +559,36 @@ pub fn tableHeadersRow() void {
 
     ig.igTableHeadersRow();
 }
+
+const PlotLinesOptions = struct {
+    label: [*c]const u8,
+    values: []f32,
+    ex: ?struct {
+        graph_width: f32 = 0,
+        graph_height: f32 = 0,
+        scale_min: f32 = 0,
+        scale_max: f32 = 1,
+        stride: u32 = 4,
+    } = null
+};
+
+pub fn plotLines(opts: PlotLinesOptions) void {
+    if (isDisabled()) {
+        return;
+    }
+
+    if (opts.ex) |ex| {
+        ig.igPlotLinesEx(
+            opts.label,
+            opts.values.ptr, @intCast(opts.values.len),
+            0,
+            null,
+            ex.scale_min,
+            ex.scale_max,
+            .{ .x = ex.graph_width, .y = ex.graph_height },
+            @intCast(ex.stride)
+        );
+    } else {
+        ig.igPlotLines(opts.label, opts.values.ptr, @intCast(opts.values.len));
+    }
+}

src/platform/root.zig

@@ -140,8 +140,25 @@ fn PlatformType(App: type) type {
                 }
 
                 Gfx.flush(.{});
-                Gfx.showDebug();
+                if (ImGUI.beginWindow(.{
-                Audio.showDebug();
+                    .name = "Platform",
+                    .size = .init(300, 400)
+                })) {
+                    defer ImGUI.endWindow();
+
+                    _ = ImGUI.beginTabBar("platform tab bar");
+                    defer ImGUI.endTabBar();
+
+                    if (ImGUI.beginTabItem("Graphics")) {
+                        defer ImGUI.endTabItem();
+                        Gfx.showDebug();
+                    }
+
+                    if (ImGUI.beginTabItem("Audio")) {
+                        defer ImGUI.endTabItem();
+                        Audio.showDebug();
+                    }
+                }
 
                 ImGUI.endFrame();
                 Gfx.endFrame();
@@ -607,7 +624,7 @@ pub fn run(App: type, opts: RunOptions) void {
         .last_key_press_is_repeat = false,
         .last_key_pressed = null,
         .frame_arena = .init(gpa),
-        .show_imgui = builtin.mode == .Debug,
+        .show_imgui = false,
         .assets = .init(gpa, io, assets_dir),
         .last_mouse_position = null
     };