diff --git a/build/app.zig b/build/app.zig index db6510c1e..c34866f03 100644 --- a/build/app.zig +++ b/build/app.zig @@ -567,6 +567,7 @@ pub fn construct(b: *std.Build, target: std.Build.ResolvedTarget, optimize: std. // The profiler's lookback: 30 seconds of windows a reader can sum over, and the frames // that went over budget. .{ "fizzy-profile-lookback-tests", "core/profile/Lookback.zig" }, + .{ "fizzy-profile-causes-tests", "core/profile/FrameCauses.zig" }, // The login-shell PATH cache: it owns its string whatever allocator the first caller // passed, and threads that ask at once resolve once. The shell spawn itself is not run. .{ "fizzy-shell-env-tests", "core/shell_env.zig" }, diff --git a/core/profile.zig b/core/profile.zig index 078357bf4..e005e3d16 100644 --- a/core/profile.zig +++ b/core/profile.zig @@ -27,6 +27,9 @@ const perf = @import("gfx/perf.zig"); /// What the profiler keeps past its half-second window: 30 seconds of windows, and the frames /// over budget (`lookback`). pub const Lookback = @import("profile/Lookback.zig"); +/// Why each frame happened: its events, the `dvui.refresh` calls before it by place, or something +/// else (a timer, an animation), kept while the profiler records (`frameCauses`). +pub const FrameCauses = @import("profile/FrameCauses.zig"); /// Bumped whenever `Profiler`'s layout changes. Part of the key the host publishes it under /// (`publish_key`), so a plugin built against another layout finds none and records nothing: the @@ -351,10 +354,42 @@ var is_host = false; /// nobody profiles. Published beside the profiler under a key of its own, so the profiler's /// layout, and the plugins built against it, are untouched. var host_lookback: ?*Lookback = null; +/// The host's frame causes, made like `host_lookback`, and started over each time the profiler +/// starts recording, so they say what happened while someone looked. +var host_causes: ?*FrameCauses = null; +var was_active = false; const publish_id: dvui.Id = @enumFromInt(0x6669_7a7a_7970_7266); // "fizzyprf" const publish_key = std.fmt.comptimePrint("_profiler{d}", .{abi}); const lookback_key = std.fmt.comptimePrint("_profiler_lookback{d}", .{Lookback.abi}); +const causes_key = std.fmt.comptimePrint("_profiler_causes{d}", .{FrameCauses.abi}); +const phases_key = std.fmt.comptimePrint("_profiler_phases{d}", .{Phases.abi}); + +/// The moments the app's start took, stamped by the app as it reaches them (`phase`): process +/// entry, the window, the plugins, the window shown, the first frame; and, for an instance a +/// restart started beside the old one, the handover's. Measured by the app itself, on every +/// platform, rather than from outside. Published beside the profiler under its own key. +pub const Phases = struct { + pub const abi: u32 = 1; + pub const max = 16; + /// Each phase's name: a string that lives as long as the process (a literal). + names: [max][]const u8 = undefined, + at_ns: [max]i128 = undefined, + len: usize = 0, + + /// Milliseconds from the first phase to phase `i`. + pub fn ms(self: *const Phases, i: usize) f64 { + return @as(f64, @floatFromInt(self.at_ns[i] - self.at_ns[0])) / std.time.ns_per_ms; + } + + /// As ZON: each phase and when it came, in milliseconds from the first. + pub fn write(self: *const Phases, w: *std.Io.Writer, indent: []const u8) std.Io.Writer.Error!void { + try w.writeAll(".{\n"); + for (0..self.len) |i| try w.print("{s} .{{ .phase = \"{s}\", .ms = {d:.1} }},\n", .{ indent, self.names[i], self.ms(i) }); + try w.print("{s}}}", .{indent}); + } +}; +var host_phases: Phases = .{}; /// The profiler to record into: the host's own in the host, the one it published in a plugin. /// Null when there is none, or it was built with another layout. @@ -378,6 +413,91 @@ pub fn lookback() ?*Lookback { return @ptrFromInt(addr); } +/// Why the frames since the profiler started recording happened, from any image. Null until it +/// has recorded a frame. +pub fn frameCauses() ?*FrameCauses { + if (is_host) return host_causes; + if (dvui.current_window == null) return null; + const addr = dvui.dataGet(null, publish_id, causes_key, usize) orelse return null; + return @ptrFromInt(addr); +} + +/// Whether frame causes are being recorded: the host's profiler is. The app turns dvui's refresh +/// records on while it is (`dvui.debug.logRefresh`) and hands each to `noteRefresh` (`interceptLog`). +pub fn recordingCauses() bool { + return host_causes != null and host_profiler.active; +} + +/// A `dvui.refresh` from `file`:`line`, from any thread: counted toward the next frame's cause +/// while the profiler records. +pub fn noteRefresh(file: []const u8, line: u32, from_thread: bool) void { + if (!recordingCauses()) return; + host_causes.?.noteRefresh(file, line, from_thread); +} + +/// For the app's `std.Options.logFn`, first thing: dvui's refresh records (`{s}:{d} refresh`, +/// logged at debug while `dvui.debug.logRefresh` is on) are counted as frame causes. True when the +/// call was one of dvui's refresh-debugging lines, which the app then drops unless it is also +/// logging refreshes itself. Matched by format at compile time, so every other log call costs +/// nothing here; a test holds dvui to the formats (`fizzy-integration-tests`). +pub fn interceptLog(comptime level: std.log.Level, comptime scope: @EnumLiteral(), comptime format: []const u8, args: anytype) bool { + if (comptime level != .debug or scope != .dvui) return false; + if (comptime std.mem.eql(u8, format, "{s}:{d} refresh {?x}")) { + noteRefresh(args[0], @intCast(args[1]), false); + return true; + } + if (comptime std.mem.eql(u8, format, "{s}:{d} refreshBackend {?x}")) { + noteRefresh(args[0], @intCast(args[1]), true); + return true; + } + // Logged with the refresh records, at every frame's start. + return comptime std.mem.eql(u8, format, "Window.begin frame_time_ns {d}"); +} + +/// A plugin dylib's log line (`Host.logLine`), from its own dvui: its refresh records reach the +/// host as text, `: refresh ` or `refreshBackend`, and are counted like the host's +/// (`interceptLog`). True when the line was one, which the host then drops. Read only while +/// recording; a plugin's release build compiles the records out, so only its Debug builds name +/// their places. +pub fn interceptPluginLine(level: std.log.Level, message: []const u8) bool { + if (level != .debug or !recordingCauses()) return false; + const at = std.mem.indexOf(u8, message, " refresh") orelse return false; + const loc = message[0..at]; + const colon = std.mem.lastIndexOfScalar(u8, loc, ':') orelse return false; + const line = std.fmt.parseInt(u32, loc[colon + 1 ..], 10) catch return false; + noteRefresh(loc[0..colon], line, std.mem.startsWith(u8, message[at..], " refreshBackend")); + return true; +} + +/// The events this frame has to handle, less the one dvui adds to every frame (the pointer's +/// `position`, so hover follows it): it causes nothing. +fn causingEvents() usize { + var n: usize = 0; + for (dvui.events()) |e| { + if (e.evt == .mouse and e.evt.mouse.action == .position) continue; + n += 1; + } + return n; +} + +/// Host only: the app's start has reached `name` (a string literal). The first call is time zero. +/// Past `Phases.max`, not kept. `io` reads the clock: the process's own before the backend has +/// set `dvui.io` (at the top of `main`), which the clock otherwise goes through. +pub fn phase(io: std.Io, name: []const u8) void { + if (host_phases.len == Phases.max) return; + host_phases.names[host_phases.len] = name; + host_phases.at_ns[host_phases.len] = std.Io.Clock.boot.now(io).nanoseconds; + host_phases.len += 1; +} + +/// The app's start, from any image. +pub fn phases() ?*const Phases { + if (is_host) return &host_phases; + if (dvui.current_window == null) return null; + const addr = dvui.dataGet(null, publish_id, phases_key, usize) orelse return null; + return @ptrFromInt(addr); +} + /// Host only: the profiler the window shows and controls. pub fn host() *Profiler { return &host_profiler; @@ -393,6 +513,15 @@ pub fn hostFrameBegin(prev_submit_ns: ?u64) void { dvui.dataSet(null, publish_id, publish_key, @as(usize, @intFromPtr(&host_profiler))); if (host_lookback == null and host_profiler.active) host_lookback = Lookback.create(std.heap.page_allocator, max_entries) catch null; if (host_lookback) |lb| dvui.dataSet(null, publish_id, lookback_key, @as(usize, @intFromPtr(lb))); + dvui.dataSet(null, publish_id, phases_key, @as(usize, @intFromPtr(&host_phases))); + const active = host_profiler.active; + if (host_causes == null and active) host_causes = std.heap.page_allocator.create(FrameCauses) catch null; + if (host_causes) |c| { + if (active and !was_active) c.* = .{}; + if (active) c.frameBegin(causingEvents()); + dvui.dataSet(null, publish_id, causes_key, @as(usize, @intFromPtr(c))); + } + was_active = active; } /// Host only, at the end of every frame. @@ -453,6 +582,11 @@ pub const ReportOptions = struct { /// Also the newest this many frames that went over budget (`Lookback.budget_ns`), each with /// its costliest scopes. hitches: usize = 0, + /// Also why the frames happened (`FrameCauses`), with at most this many of the places that + /// asked for them; 0 leaves it out. + causes: usize = 8, + /// Also the app's start (`Phases`): when it reached each phase. + startup: bool = false, }; /// Each entry's own time in a frame whose times (`ns`, indexed as `Profiler.slice`) are given: @@ -515,6 +649,16 @@ pub fn report(p: *const Profiler, w: *std.Io.Writer, opts: ReportOptions) std.Io if (opts.over_ms > 0) try writeOver(p, lb, w, opts); if (opts.hitches > 0) try writeHitches(p, lb, w, opts); } + if (opts.startup) if (phases()) |ph| { + try w.writeAll(" .startup = "); + try ph.write(w, " "); + try w.writeAll(",\n"); + }; + if (opts.causes > 0) if (frameCauses()) |c| { + try w.writeAll(" .causes = "); + try c.write(w, " ", opts.causes); + try w.writeAll(",\n"); + }; try w.writeAll("}\n"); } diff --git a/core/profile/FrameCauses.zig b/core/profile/FrameCauses.zig new file mode 100644 index 000000000..4533702a0 --- /dev/null +++ b/core/profile/FrameCauses.zig @@ -0,0 +1,167 @@ +//! Why each frame happened, kept while the profiler records (`core.profile`): fizzy draws only +//! when something asks, so the two frame-loop bugs are a frame that never comes (work waiting for +//! the next unrelated event) and frames that never stop (something asking for another every frame). +//! A profile shows where a frame's time goes; this says who asked for it. +//! +//! A frame is put down to its events (input, a window event), else to the `dvui.refresh` calls +//! since the last one, by the file and line that asked (from dvui's own refresh records, which +//! the app's log function hands to `noteRefresh`), else to something else: a timer or an animation +//! coming due. Refreshes are counted by place; the places are kept, the frames as counts. +//! +//! Its own allocation, published beside the profiler under its own key (as `Lookback`), so the +//! profiler's layout, and its `abi`, are untouched. std-only. `noteRefresh` may be called from +//! any thread (a worker waking the app), under a spin lock held for a few instructions. +const FrameCauses = @This(); + +const std = @import("std"); + +pub const abi: u32 = 1; +/// The places that asked for frames, kept by count. One past it counts as `other_places`. +pub const places_kept = 32; +const file_len = 64; + +lock: std.atomic.Value(bool) = .init(false), +/// Frames recorded, and what each was put down to. +frames: u32 = 0, +by_events: u32 = 0, +by_refresh: u32 = 0, +by_other: u32 = 0, +/// Refreshes since the last frame began: they caused the next one. +pending: u32 = 0, +places: [places_kept]Place = undefined, +places_len: usize = 0, +/// Refreshes from places past `places_kept`. +other_places: u32 = 0, + +pub const Place = struct { + /// The asking file's path, its tail when longer than `file_len`: a dylib's strings go with it + /// when it unloads, so it is copied. + file_buf: [file_len]u8, + file_len: u8, + line: u32, + count: u32, + /// Asked from a thread other than the UI's (`dvui.refresh` with a window, through the backend). + from_thread: bool, + + pub fn file(self: *const Place) []const u8 { + return self.file_buf[0..self.file_len]; + } +}; + +fn acquire(self: *FrameCauses) void { + while (self.lock.cmpxchgWeak(false, true, .acquire, .monotonic) != null) std.atomic.spinLoopHint(); +} + +fn release(self: *FrameCauses) void { + self.lock.store(false, .release); +} + +/// Start over: counts from now. +pub fn reset(self: *FrameCauses) void { + self.acquire(); + defer self.release(); + self.frames = 0; + self.by_events = 0; + self.by_refresh = 0; + self.by_other = 0; + self.pending = 0; + self.places_len = 0; + self.other_places = 0; +} + +/// A `dvui.refresh` from `file`:`line`. Any thread. +pub fn noteRefresh(self: *FrameCauses, file: []const u8, line: u32, from_thread: bool) void { + self.acquire(); + defer self.release(); + self.pending +|= 1; + const tail = file[file.len - @min(file.len, file_len) ..]; + for (self.places[0..self.places_len]) |*p| { + if (p.line == line and p.from_thread == from_thread and std.mem.eql(u8, p.file(), tail)) { + p.count +|= 1; + return; + } + } + if (self.places_len == places_kept) { + self.other_places +|= 1; + return; + } + var p: Place = .{ .file_buf = undefined, .file_len = @intCast(tail.len), .line = line, .count = 1, .from_thread = from_thread }; + @memcpy(p.file_buf[0..tail.len], tail); + self.places[self.places_len] = p; + self.places_len += 1; +} + +/// A frame begins, with `events` events to handle. On the UI thread. +pub fn frameBegin(self: *FrameCauses, events: usize) void { + self.acquire(); + defer self.release(); + self.frames +|= 1; + if (events > 0) { + self.by_events +|= 1; + } else if (self.pending > 0) { + self.by_refresh +|= 1; + } else self.by_other +|= 1; + self.pending = 0; +} + +/// As ZON: what the frames since the last `reset` were put down to, and the places that asked +/// for frames, most first (at most `top`). +pub fn write(self: *FrameCauses, w: *std.Io.Writer, indent: []const u8, top: usize) std.Io.Writer.Error!void { + self.acquire(); + defer self.release(); + try w.print(".{{\n{s} .frames = {d}, .by_events = {d}, .by_refresh = {d}, .by_other = {d},\n", .{ indent, self.frames, self.by_events, self.by_refresh, self.by_other }); + var order: [places_kept]u8 = undefined; + for (0..self.places_len) |i| order[i] = @intCast(i); + const Ctx = struct { + places: []const Place, + fn more(ctx: @This(), a: u8, b: u8) bool { + return ctx.places[a].count > ctx.places[b].count; + } + }; + std.mem.sort(u8, order[0..self.places_len], Ctx{ .places = self.places[0..self.places_len] }, Ctx.more); + try w.print("{s} .refreshed_from = .{{\n", .{indent}); + for (order[0..@min(top, self.places_len)]) |i| { + const p = &self.places[i]; + try w.print("{s} .{{ .place = \"{s}:{d}\", .count = {d}{s} }},\n", .{ indent, p.file(), p.line, p.count, if (p.from_thread) ", .from_thread = true" else "" }); + } + try w.print("{s} }},\n", .{indent}); + if (self.other_places > 0) try w.print("{s} .from_other_places = {d},\n", .{ indent, self.other_places }); + try w.print("{s}}}", .{indent}); +} + +test "a frame is put down to its events, else the refreshes before it, else something else" { + var c: FrameCauses = .{}; + c.frameBegin(2); + c.noteRefresh("src/editor/Editor.zig", 120, false); + c.noteRefresh("src/editor/Editor.zig", 120, false); + c.noteRefresh("plugins/text/src/Doc.zig", 9, true); + c.frameBegin(0); + c.frameBegin(0); + try std.testing.expectEqual(@as(u32, 3), c.frames); + try std.testing.expectEqual(@as(u32, 1), c.by_events); + try std.testing.expectEqual(@as(u32, 1), c.by_refresh); + try std.testing.expectEqual(@as(u32, 1), c.by_other); + + var out: std.Io.Writer.Allocating = .init(std.testing.allocator); + defer out.deinit(); + try c.write(&out.writer, "", 8); + const text = out.written(); + // The busiest place first. + const editor = std.mem.indexOf(u8, text, "src/editor/Editor.zig:120\", .count = 2").?; + const doc = std.mem.indexOf(u8, text, "plugins/text/src/Doc.zig:9\", .count = 1, .from_thread = true").?; + try std.testing.expect(editor < doc); + + c.reset(); + try std.testing.expectEqual(@as(u32, 0), c.frames); + try std.testing.expectEqual(@as(usize, 0), c.places_len); +} + +test "a long path keeps its tail, and places past the kept ones are counted together" { + var c: FrameCauses = .{}; + const long = "/a/very/long/path/that/goes/on/and/on/and/on/past/sixty/four/bytes/src/Thing.zig"; + c.noteRefresh(long, 1, false); + try std.testing.expect(std.mem.endsWith(u8, c.places[0].file(), "src/Thing.zig")); + for (0..places_kept + 3) |i| c.noteRefresh("x.zig", @intCast(i + 2), false); + try std.testing.expectEqual(@as(usize, places_kept), c.places_len); + try std.testing.expectEqual(@as(u32, 4), c.other_places); +} diff --git a/src/Entry.zig b/src/Entry.zig index 0be79507d..ba736cfbe 100644 --- a/src/Entry.zig +++ b/src/Entry.zig @@ -143,6 +143,8 @@ pub const dvui_app: dvui.App = .{ }; pub fn main(main_init: std.process.Init) !u8 { + // Time zero for the app's start (`core.profile.phase`). + fizzy.core.profile.phase(main_init.io, "main"); crash.init(.{ .app = AppInfo.current.name, .version = AppInfo.current.version, .sdk = sdk_version }); std.log.info("{s} version {s} ({s})", .{ AppInfo.current.display_name, AppInfo.current.version, @tagName(@import("builtin").mode) }); @@ -229,6 +231,7 @@ pub fn main(main_init: std.process.Init) !u8 { }.f, }); try singleton.earlyStartup(appAllocator(), main_init); + fizzy.core.profile.phase(main_init.io, if (restart.startedByHandover()) "lock deferred (handover)" else "lock"); // Both read relative to where fizzy was launched, before `AppInit` moves to its own directory. Editor.Demo.readEnvTape(appAllocator(), main_init.io); @@ -250,6 +253,10 @@ pub fn main(main_init: std.process.Init) !u8 { pub const panic = if (crash.supported) std.debug.FullPanic(crash.panic) else dvui.App.panic; pub const std_options: std.Options = .{ .logFn = logFn, + // dvui's refresh records are debug lines, which a release build would compile out; they are + // what the profiler puts frames down to (`core.profile.interceptLog`). dvui's other debug lines + // are dropped in `logFn` outside Debug, as they were before. + .log_scope_levels = &.{.{ .scope = .dvui, .level = .debug }}, // In every build mode, not only the safe ones: a release crash is the one worth a report. .enable_segfault_handler = crash.supported, }; @@ -267,6 +274,9 @@ const sdk_version = std.fmt.comptimePrint("{f} ({x})", .{ // web) and also into `fizzy.OutputLog`, so fizzy's "Output" bottom panel can show it — except // while `FIZZY_LOG_REFRESH` is on, see `refresh_log_active`. fn logFn(comptime level: std.log.Level, comptime scope: @EnumLiteral(), comptime format: []const u8, args: anytype) void { + // A refresh record, counted as a frame's cause; printed only for `FIZZY_LOG_REFRESH`. + if (fizzy.core.profile.interceptLog(level, scope, format, args) and !refresh_log_active) return; + if (comptime scope == .dvui and level == .debug and @import("builtin").mode != .Debug) return; if (!refresh_log_active) fizzy.OutputLog.append(level, scope, format, args); dvui.App.logFn(level, scope, format, args); } @@ -300,6 +310,7 @@ var refresh_log_active = false; // Runs before the first frame, after backend and dvui.Window.init() pub fn AppInit(win: *dvui.Window) !void { + fizzy.core.profile.phase(dvui.io, "window"); // Snapshot the platform from DVUI's keybind selection. On native this is a // no-op; on wasm it tells `fizzy.core.platform.isMacOS()` what browser we're in. fizzy.core.platform.cacheFromWindow(win); @@ -351,6 +362,7 @@ pub fn AppInit(win: *dvui.Window) !void { const editor_ptr = try allocator.create(Editor); fizzy.setInstances(app_ptr, editor_ptr); editor_ptr.* = Editor.init(app_ptr) catch unreachable; + fizzy.core.profile.phase(dvui.io, "editor"); // Workbench fizzy-owned state: wire before plugin `register`. workbench.runtime.setWorkbench(&fizzy.editor().workbench); @@ -359,6 +371,7 @@ pub fn AppInit(win: *dvui.Window) !void { // workbench-api service whose `ctx` is this pointer). This loads the built-in plugins, // including pixi as a generic dylib that owns its own state + atlas packer. fizzy.editor().postInit() catch unreachable; + fizzy.core.profile.phase(dvui.io, "plugins"); // Whether dvui went quiet at the end of each frame, for the `automation` service's `settled`. if (comptime @hasDecl(dvui.backend, "frame_ended_hook")) dvui.backend.frame_ended_hook = frameEnded; @@ -398,10 +411,29 @@ pub fn AppInit(win: *dvui.Window) !void { // Started by a restart's handover: up and hidden, the session read. The old instance goes // now, and this window shows over its own at the same place (`restart`); the lock follows // once the old one lets go of it (`Editor.tick`). - if (restart.startedByHandover()) restart.signalReady(dvui.io); + if (restart.startedByHandover()) { + restart.signalReady(dvui.io); + fizzy.core.profile.phase(dvui.io, "handover ready"); + } // Chrome and geometry are settled — reveal the window (created hidden). fizzy.backend.showWindow(win); + fizzy.core.profile.phase(dvui.io, "shown"); +} + +/// The first frame has ended: the app is up. Says how long that took, once. +var first_frame_done = false; +fn noteFirstFrame() void { + if (first_frame_done) return; + first_frame_done = true; + fizzy.core.profile.phase(dvui.io, "first frame"); + const ph = fizzy.core.profile.phases() orelse return; + std.log.info("startup: up {d:.0} ms after main (window shown at {d:.0} ms)", .{ ph.ms(ph.len - 1), shownMs(ph) }); +} + +fn shownMs(ph: *const fizzy.core.profile.Phases) f64 { + for (0..ph.len) |i| if (std.mem.eql(u8, ph.names[i], "shown")) return ph.ms(i); + return 0; } // Run as app is shutting down before dvui.Window.deinit() @@ -431,8 +463,12 @@ pub fn AppDeinit(_: *dvui.Window) void { pub fn AppFrame() !dvui.App.Result { fizzy.core.hitch.frameBegin(); defer fizzy.core.hitch.frameEnd(); + // dvui's refresh records, while someone reads them: the profiler, as frame causes, or a + // `FIZZY_LOG_REFRESH` run. + _ = dvui.debug.logRefresh(refresh_log_active or fizzy.core.profile.recordingCauses()); fizzy.core.profile.hostFrameBegin(lastSubmitNs()); defer fizzy.core.profile.hostFrameEnd(); + defer noteFirstFrame(); singleton.drainPending(); // Once, or — while a demo is seeking — again and again unseen until it lands (`frames`). const player = &fizzy.editor().demo.player; diff --git a/src/editor/Editor.zig b/src/editor/Editor.zig index 1426aefef..55697d49e 100644 --- a/src/editor/Editor.zig +++ b/src/editor/Editor.zig @@ -2326,6 +2326,8 @@ fn fizzyAskCommandArguments(ctx: *anyopaque, command_id: []const u8) bool { fn fizzyLogLine(ctx: *anyopaque, level: std.log.Level, scope: []const u8, message: []const u8) void { _ = ctx; + // A plugin's dvui refresh record, counted as a frame cause while the profiler records. + if (fizzy.core.profile.interceptPluginLine(level, message)) return; fizzy.OutputLog.appendLine(level, scope, message); } @@ -2619,6 +2621,10 @@ fn wakeEventLoop() void { fn fizzyRefresh(ctx: *anyopaque) void { _ = ctx; + // A plugin asking for a frame, which goes past `dvui.refresh` and so past its records: counted + // as a frame cause here. Which plugin asked, `Host.refresh` does not say (a source location + // through it would move the SDK's boundary). + fizzy.core.profile.noteRefresh("Host.refresh (a plugin)", 0, false); // Safe from any thread (see `SDLBackend.refresh`'s doc comment) — a single call reliably // wakes the blocked event loop and produces exactly one composited frame; see // `render_bridge.refresh`'s doc comment for how that was verified. @@ -5095,8 +5101,10 @@ fn syncExecutableWatcher(editor: *Editor) void { fn driveHandover(editor: *Editor) void { // The new instance's side: the lock, once the old instance has let go of it. if (restart.startedByHandover()) { - if (restart.pollReleased(dvui.io, editor.app.gpa)) + if (restart.pollReleased(dvui.io, editor.app.gpa)) { @import("app").single_instance.acquireLock(editor.app.gpa, &.{}) catch |err| dvui.log.warn("restart: could not take the single-instance lock: {t}", .{err}); + fizzy.core.profile.phase(dvui.io, "handover lock"); + } return; } if (restart.canHandOver()) {