lib/coz/src/runtime.zig
daab053ee43316e1809a84551d573ddd1e5bf3d2
1 const std = @import("std");
2 const sys = @import("sys");
3
4 const abi = @import("abi.zig");
5 const debug_info = @import("debug.zig");
6 const delay = @import("delay.zig");
7 const experiment = @import("experiment.zig");
8 const profile = @import("profile.zig");
9 const profiler = @import("profiler.zig");
10 const sampler = @import("sampler.zig");
11 const signals = @import("signals.zig");
12 const source_map = @import("map.zig");
13 const thread = @import("thread.zig");
14
15 const perf = sys.perf;
16 const timer = sys.timer;
17
18 const CounterKind = abi.CounterKind;
19 const Counter = abi.Counter;
20 const ExperimentStepOptions = profiler.ExperimentStepOptions;
21 const ExperimentStepResult = profiler.ExperimentStepResult;
22 const Profiler = profiler.Profiler;
23
24 const ActiveProfiler = struct {
25 allocator: std.mem.Allocator,
26 instance: *Profiler,
27 };
28
29 pub const RuntimeOptions = struct {
30 sampler_options: sampler.Options = .{},
31 install_signal_handler: bool = true,
32 start_current_thread: bool = true,
33 profile_writer: ?*std.Io.Writer = null,
34 start_experiment_worker: bool = false,
35 experiment_step_options: ExperimentStepOptions = .{},
36 experiment_duration_ns: ?u64 = null,
37 source_scope: debug_info.Scope = .{},
38 resolve_sample_locations: bool = false,
39 };
40
41 pub const Runtime = struct {
42 allocator: ?std.mem.Allocator = null,
43 profiler: Profiler = .{},
44 profile_writer: ?*std.Io.Writer = null,
45 profile_writer_mutex: std.atomic.Mutex = .unlocked,
46 source_scope: debug_info.Scope = .{},
47 resolve_sample_locations: bool = false,
48 runtime_start_ns: u64 = 0,
49 sampling_handler: ?signals.Installed = null,
50 sample_thread: ?*thread.Thread = null,
51 experiment_worker: ?sys.thread.JoinHandle = null,
52 experiment_worker_running: std.atomic.Value(bool) = .init(false),
53 experiment_worker_error: ?anyerror = null,
54 experiment_worker_options: ExperimentStepOptions = .{},
55 profiler_installed: bool = false,
56 current_thread_started: bool = false,
57
58 pub fn start(self: *Runtime, allocator: std.mem.Allocator, options: RuntimeOptions) !void {
59 if (self.profiler_installed) return error.RuntimeAlreadyStarted;
60
61 self.allocator = allocator;
62 self.runtime_start_ns = timestampNs();
63 errdefer self.shutdown();
64
65 installProfiler(allocator, &self.profiler);
66 self.profiler_installed = true;
67
68 if (options.install_signal_handler) {
69 self.sampling_handler = installSamplingHandler();
70 }
71
72 if (options.start_current_thread) {
73 current_thread = try thread.Thread.openAndStartCurrent(options.sampler_options);
74 self.sample_thread = ¤t_thread;
75 self.current_thread_started = true;
76 }
77
78 self.source_scope = options.source_scope;
79 self.resolve_sample_locations = options.resolve_sample_locations;
80 if (options.experiment_duration_ns) |duration_ns| {
81 self.profiler.experiment_duration_ns = duration_ns;
82 }
83
84 if (options.profile_writer) |writer| {
85 try self.profiler.writeStartup(writer, self.runtime_start_ns);
86 self.profile_writer = writer;
87 }
88
89 if (options.start_experiment_worker) {
90 if (self.profile_writer == null) return error.ProfileWriterUnavailable;
91 try self.startExperimentWorker(options.experiment_step_options);
92 }
93 }
94
95 pub fn startIfAvailable(self: *Runtime, allocator: std.mem.Allocator, options: RuntimeOptions) !bool {
96 self.start(allocator, options) catch |err| {
97 if (runtimeUnavailable(err)) return false;
98 return err;
99 };
100 return true;
101 }
102
103 pub fn runExperimentStep(self: *Runtime, options: ExperimentStepOptions) !ExperimentStepResult {
104 return self.runExperimentStepWithWait(options, waitNs, true);
105 }
106
107 fn runExperimentStepWithWait(
108 self: *Runtime,
109 options: ExperimentStepOptions,
110 wait_fn: sampler.WaitFn,
111 drain_current_thread: bool,
112 ) !ExperimentStepResult {
113 const allocator = self.allocator orelse return error.RuntimeNotStarted;
114 const writer = self.profile_writer orelse return error.ProfileWriterUnavailable;
115
116 if (drain_current_thread and self.current_thread_started) {
117 _ = try current_thread.processDefault(&self.profiler, waitNs);
118 }
119
120 lockMutex(&self.profile_writer_mutex);
121 defer self.profile_writer_mutex.unlock();
122
123 const result = try self.profiler.runExperimentStep(allocator, writer, options, wait_fn);
124 if (result.emitted) try writer.flush();
125 return result;
126 }
127
128 pub fn stop(self: *Runtime) !void {
129 var first_error: ?anyerror = null;
130 var loss_counter: profile.LossCounter = .unsupported;
131 var terminal_status: profile.TerminalStatus = .not_started;
132
133 self.stopExperimentWorker() catch |err| rememberRuntimeError(&first_error, err);
134
135 if (self.current_thread_started) {
136 var stopped = true;
137 current_thread.sampler.stop() catch |err| {
138 stopped = false;
139 rememberRuntimeError(&first_error, err);
140 };
141 var drained = true;
142 _ = current_thread.drainDefault(&self.profiler) catch |err| failed: {
143 drained = false;
144 rememberRuntimeError(&first_error, err);
145 break :failed 0;
146 };
147 terminal_status = if (!drained)
148 .drain_failed
149 else if (!stopped)
150 .stop_failed
151 else
152 .complete;
153 loss_counter = profileLossCounter(current_thread.sampler.readLossCounter());
154 current_thread.close();
155 current_thread = .{};
156 self.sample_thread = null;
157 self.current_thread_started = false;
158 }
159
160 if (self.sampling_handler) |*handler| {
161 handler.restore();
162 self.sampling_handler = null;
163 }
164
165 if (self.profiler_installed) {
166 uninstallProfiler(&self.profiler);
167 self.profiler_installed = false;
168 }
169
170 if (self.profile_writer) |writer| {
171 if (self.allocator) |allocator| {
172 lockMutex(&self.profile_writer_mutex);
173 defer self.profile_writer_mutex.unlock();
174 self.profiler.writeRuntimeAndSamples(
175 allocator,
176 writer,
177 elapsedSinceNs(self.runtime_start_ns),
178 loss_counter,
179 terminal_status,
180 ) catch |err| rememberRuntimeError(&first_error, err);
181 writer.flush() catch |err| rememberRuntimeError(&first_error, err);
182 }
183 self.profile_writer = null;
184 }
185
186 if (self.allocator) |allocator| {
187 self.profiler.deinit(allocator);
188 self.allocator = null;
189 }
190
191 self.runtime_start_ns = 0;
192 self.source_scope = .{};
193 self.resolve_sample_locations = false;
194
195 if (first_error) |err| return err;
196 }
197
198 pub fn shutdown(self: *Runtime) void {
199 self.stop() catch {};
200 }
201
202 fn startExperimentWorker(self: *Runtime, options: ExperimentStepOptions) !void {
203 if (self.experiment_worker != null) return error.ExperimentWorkerAlreadyStarted;
204
205 self.experiment_worker_options = options;
206 self.experiment_worker_error = null;
207 self.experiment_worker_running.store(true, .release);
208 errdefer self.experiment_worker_running.store(false, .release);
209 self.experiment_worker = try sys.thread.spawn(experimentWorkerMain, .{self});
210 }
211
212 fn stopExperimentWorker(self: *Runtime) !void {
213 if (self.experiment_worker) |worker| {
214 self.experiment_worker_running.store(false, .release);
215 worker.join();
216 self.experiment_worker = null;
217 } else {
218 self.experiment_worker_running.store(false, .release);
219 }
220
221 if (self.experiment_worker_error) |err| {
222 self.experiment_worker_error = null;
223 return err;
224 }
225 }
226
227 fn runExperimentWorkerStepWithWait(
228 self: *Runtime,
229 prng: *std.Random.DefaultPrng,
230 wait_fn: sampler.WaitFn,
231 ) !ExperimentStepResult {
232 var options = self.experiment_worker_options;
233 options.running = &self.experiment_worker_running;
234 if (options.fixed_speedup_percent == null) {
235 const draw_value = prng.random().intRangeAtMost(u64, 0, experiment.Draw.maxDraw());
236 options.draw = try experiment.Draw.init(draw_value);
237 }
238 return self.runExperimentStepWithWait(options, wait_fn, false);
239 }
240
241 fn drainSampleThread(self: *Runtime) !usize {
242 if (!self.resolve_sample_locations) return 0;
243 const allocator = self.allocator orelse return 0;
244 const sample_thread = self.sample_thread orelse return 0;
245 return sample_thread.drainResolvedDefault(&self.profiler, allocator, self.source_scope);
246 }
247 };
248
249 pub fn runtimeUnavailable(err: anyerror) bool {
250 return sampler.unavailable(err);
251 }
252
253 pub fn profilerPresent() bool {
254 return activeProfilerPresent();
255 }
256
257 pub fn installSamplingHandler() signals.Installed {
258 return signals.installSampleHandler(sampleSignalHandler);
259 }
260
261 pub fn installProfiler(allocator: std.mem.Allocator, instance: *Profiler) void {
262 lockActiveProfiler();
263 defer active_profiler_mutex.unlock();
264 active_profiler = .{
265 .allocator = allocator,
266 .instance = instance,
267 };
268 _ = active_profiler_generation.fetchAdd(1, .release);
269 active_profiler_signal.store(@intFromPtr(instance), .release);
270 }
271
272 pub fn uninstallProfiler(instance: *Profiler) void {
273 lockActiveProfiler();
274 defer active_profiler_mutex.unlock();
275 if (active_profiler) |active| {
276 if (active.instance == instance) {
277 active_profiler_signal.store(0, .release);
278 _ = active_profiler_generation.fetchAdd(1, .release);
279 active_profiler = null;
280 }
281 }
282 }
283
284 pub inline fn progress(comptime src: std.builtin.SourceLocation) void {
285 progressNamed(std.fmt.comptimePrint("{s}:{d}", .{ src.file, src.line }));
286 }
287
288 pub inline fn progressNamed(comptime name: []const u8) void {
289 increment(.throughput, name);
290 }
291
292 pub inline fn begin(comptime name: []const u8) void {
293 increment(.begin, name);
294 }
295
296 pub inline fn end(comptime name: []const u8) void {
297 increment(.end, name);
298 }
299
300 pub fn Scope(comptime name: []const u8) type {
301 return struct {
302 pub inline fn init() @This() {
303 begin(name);
304 return .{};
305 }
306
307 pub inline fn end(_: @This()) void {
308 module.end(name);
309 }
310 };
311 }
312
313 pub inline fn scope(comptime name: []const u8) Scope(name) {
314 return Scope(name).init();
315 }
316
317 pub inline fn preBlock() void {
318 _ = activePreBlock();
319 }
320
321 pub inline fn catchUp() void {
322 _ = activeCatchUp();
323 }
324
325 pub inline fn postBlock(skip_delays: bool) void {
326 _ = activePostBlock(skip_delays);
327 }
328
329 const module = @This();
330
331 inline fn increment(comptime kind: CounterKind, comptime name: []const u8) void {
332 if (counterFor(kind, name)) |counter| {
333 _ = @atomicRmw(usize, &counter.count, .Add, 1, .monotonic);
334 checkDelaysAtProgressPoint();
335 }
336 }
337
338 fn counterFor(comptime kind: CounterKind, comptime name: []const u8) ?*Counter {
339 comptime validateName(name);
340
341 return activeCounter(kind, name);
342 }
343
344 /// The counter one marker resolved for one installed profiler, keyed by the
345 /// marker's kind and name. A slot whose generation equals
346 /// `active_profiler_generation` holds a counter of the installed profiler, so
347 /// after its first event under a profiler a marker finds its counter with
348 /// three loads and no lock or hash. Generation zero marks a marker that has
349 /// not resolved.
350 const CounterSlot = struct {
351 kind: CounterKind,
352 name: []const u8,
353 generation: std.atomic.Value(u64) = .init(0),
354 counter: std.atomic.Value(?*Counter) = .init(null),
355 };
356
357 /// Returns the slot of one (kind, name) marker. The storage type captures the
358 /// key, so each pair gets its own slot and every site of one pair shares it.
359 fn counterSlot(comptime kind: CounterKind, comptime name: []const u8) *CounterSlot {
360 const Storage = struct {
361 var slot: CounterSlot = .{ .kind = kind, .name = name };
362 };
363 return &Storage.slot;
364 }
365
366 fn activeCounter(comptime kind: CounterKind, comptime name: []const u8) ?*Counter {
367 if (active_profiler_signal.load(.acquire) == 0) return null;
368 const slot = counterSlot(kind, name);
369 const generation = active_profiler_generation.load(.acquire);
370 if (slot.generation.load(.acquire) == generation) return slot.counter.load(.monotonic);
371 return resolveCounter(slot);
372 }
373
374 /// Resolves a marker's counter in the installed profiler's registry and
375 /// records it in the marker's slot, counter first and generation last. Every
376 /// marker shares this path, so a marker site compiles to its slot check.
377 /// Install and uninstall change the generation under the same lock, so the
378 /// recorded generation is the one the counter belongs to.
379 fn resolveCounter(slot: *CounterSlot) ?*Counter {
380 lockActiveProfiler();
381 defer active_profiler_mutex.unlock();
382
383 const active = active_profiler orelse return null;
384 const instance = active.instance;
385 const resolved = instance.getCounter(active.allocator, slot.kind, slot.name) catch return null;
386 slot.counter.store(resolved, .monotonic);
387 slot.generation.store(active_profiler_generation.load(.monotonic), .release);
388 return resolved;
389 }
390
391 fn activeProfilerPresent() bool {
392 if (active_profiler_signal.load(.acquire) == 0) return false;
393 lockActiveProfiler();
394 defer active_profiler_mutex.unlock();
395 return active_profiler != null;
396 }
397
398 fn activePreBlock() bool {
399 const instance = activeProfilerInstance() orelse return false;
400 instance.preBlock(¤t_thread.delay_state);
401 return true;
402 }
403
404 fn activeCatchUp() bool {
405 const instance = activeProfilerInstance() orelse return false;
406 _ = instance.catchUp(¤t_thread.delay_state, waitNs);
407 return true;
408 }
409
410 fn activePostBlock(skip_delays: bool) bool {
411 const instance = activeProfilerInstance() orelse return false;
412 instance.postBlock(¤t_thread.delay_state, skip_delays);
413 return true;
414 }
415
416 fn activeProfilerInstance() ?*Profiler {
417 if (active_profiler_signal.load(.acquire) == 0) return null;
418 lockActiveProfiler();
419 defer active_profiler_mutex.unlock();
420 const active = active_profiler orelse return null;
421 return active.instance;
422 }
423
424 fn activeProfilerForSignal() ?*Profiler {
425 const address = active_profiler_signal.load(.acquire);
426 if (address == 0) return null;
427 return @ptrFromInt(address);
428 }
429
430 fn sampleSignalHandler(_: signals.Signal, _: *const signals.SignalInfo, _: ?*anyopaque) callconv(.c) void {
431 const instance = activeProfilerForSignal() orelse return;
432 _ = current_thread.processDefault(instance, waitNs) catch {};
433 }
434
435 fn lockActiveProfiler() void {
436 lockMutex(&active_profiler_mutex);
437 }
438
439 fn lockMutex(mutex: *std.atomic.Mutex) void {
440 while (!mutex.tryLock()) std.atomic.spinLoopHint();
441 }
442
443 fn validateName(comptime name: []const u8) void {
444 if (std.mem.indexOfScalar(u8, name, 0) != null) {
445 @compileError("coz progress point names must not contain NUL bytes");
446 }
447 }
448
449 /// Applies pending delays at a marker. The installed profiler is read without
450 /// the lock, as the sampling signal handler reads it: `activeProfilerInstance`
451 /// returns the instance after unlocking, so the lock gave the call no
452 /// lifetime guarantee.
453 inline fn checkDelaysAtProgressPoint() void {
454 const instance = activeProfilerForSignal() orelse return;
455 _ = instance.catchUp(¤t_thread.delay_state, waitNs);
456 }
457
458 fn waitNs(ns: u64) u64 {
459 const start = sys.time.nanoTimestamp();
460 sys.time.sleepNanoseconds(ns);
461 const finish = sys.time.nanoTimestamp();
462 if (finish <= start) return 0;
463 const elapsed = finish - start;
464 if (elapsed > std.math.maxInt(u64)) return std.math.maxInt(u64);
465 return @intCast(elapsed);
466 }
467
468 fn timestampNs() u64 {
469 const now = sys.time.nanoTimestamp();
470 if (now <= 0) return 0;
471 if (now > std.math.maxInt(u64)) return std.math.maxInt(u64);
472 return @intCast(now);
473 }
474
475 fn elapsedSinceNs(start_ns: u64) u64 {
476 return timestampNs() -| start_ns;
477 }
478
479 fn rememberRuntimeError(first_error: *?anyerror, err: anyerror) void {
480 if (first_error.* == null) first_error.* = err;
481 }
482
483 fn profileLossCounter(counter: sampler.LossCounter) profile.LossCounter {
484 return switch (counter) {
485 .available => |value| .{ .available = value },
486 .unsupported => .unsupported,
487 .read_failed => .read_failed,
488 };
489 }
490
491 fn experimentWorkerMain(runtime: *Runtime) void {
492 experiment_worker_runtime = runtime;
493 defer experiment_worker_runtime = null;
494
495 var prng = std.Random.DefaultPrng.init(experimentWorkerSeed(runtime));
496 while (runtime.experiment_worker_running.load(.acquire)) {
497 _ = runtime.drainSampleThread() catch |err| {
498 runtime.experiment_worker_error = err;
499 runtime.experiment_worker_running.store(false, .release);
500 break;
501 };
502 _ = runtime.runExperimentWorkerStepWithWait(&prng, experimentWorkerWait) catch |err| {
503 runtime.experiment_worker_error = err;
504 runtime.experiment_worker_running.store(false, .release);
505 break;
506 };
507 _ = waitWhileRunning(&runtime.experiment_worker_running, experiment.experiment_cool_off_time_ns, experimentWorkerWait);
508 }
509 }
510
511 fn experimentWorkerWait(ns: u64) u64 {
512 const elapsed_ns = waitNs(ns);
513 if (experiment_worker_runtime) |runtime| {
514 _ = runtime.drainSampleThread() catch |err| {
515 runtime.experiment_worker_error = err;
516 runtime.experiment_worker_running.store(false, .release);
517 };
518 }
519 return elapsed_ns;
520 }
521
522 fn waitWhileRunning(running: *std.atomic.Value(bool), duration_ns: u64, wait_fn: sampler.WaitFn) u64 {
523 var elapsed_ns: u64 = 0;
524 while (elapsed_ns < duration_ns and running.load(.acquire)) {
525 const remaining_ns = duration_ns - elapsed_ns;
526 const interval_ns = @min(remaining_ns, experiment.experiment_cool_off_time_ns);
527 const waited_ns = wait_fn(interval_ns);
528 elapsed_ns +|= if (waited_ns == 0 and interval_ns != 0) interval_ns else waited_ns;
529 }
530 return elapsed_ns;
531 }
532
533 fn experimentWorkerSeed(self: *Runtime) u64 {
534 const address_seed: u64 = @truncate(@intFromPtr(self));
535 const seed = timestampNs() ^ address_seed;
536 return if (seed == 0) 1 else seed;
537 }
538
539 var active_profiler_mutex: std.atomic.Mutex = .unlocked;
540 var active_profiler: ?ActiveProfiler = null;
541 var active_profiler_signal: std.atomic.Value(usize) = .init(0);
542 /// Counts installs and uninstalls, starting above the zero that marks an
543 /// unresolved counter slot. A profiler installed at a released profiler's
544 /// address still gets a new generation, so no slot resolves to the released
545 /// profiler's counters.
546 var active_profiler_generation: std.atomic.Value(u64) = .init(1);
547 threadlocal var current_thread: thread.Thread = .{};
548 threadlocal var experiment_worker_runtime: ?*Runtime = null;
549 var runtime_experiment_counter: ?*Counter = null;
550
551 fn runtimeProgressWait(ns: u64) u64 {
552 if (runtime_experiment_counter) |counter| {
553 _ = @atomicRmw(usize, &counter.count, .Add, 6, .monotonic);
554 }
555 return ns;
556 }
557
558 test "compile-time progress and latency counters increment Coz counters" {
559 var local_profiler: Profiler = .{};
560 installProfiler(std.testing.allocator, &local_profiler);
561 defer {
562 uninstallProfiler(&local_profiler);
563 local_profiler.deinit(std.testing.allocator);
564 }
565
566 progressNamed("coz.test.progress");
567 begin("coz.test.latency");
568 end("coz.test.latency");
569
570 const throughput = try local_profiler.registry.getThroughputPoint(std.testing.allocator, "coz.test.progress");
571 const latency = try local_profiler.registry.getLatencyPoint(std.testing.allocator, "coz.test.latency");
572
573 try std.testing.expectEqual(@as(usize, 1), throughput.getCount());
574 try std.testing.expectEqual(@as(usize, 1), latency.getBeginCount());
575 try std.testing.expectEqual(@as(usize, 1), latency.getEndCount());
576 }
577
578 test "each marker kind and name owns one counter slot" {
579 const first = counterSlot(.throughput, "coz.test.slot.first");
580 try std.testing.expect(first == counterSlot(.throughput, "coz.test.slot.first"));
581 try std.testing.expect(first != counterSlot(.throughput, "coz.test.slot.second"));
582 try std.testing.expect(first != counterSlot(.begin, "coz.test.slot.first"));
583 try std.testing.expectEqual(CounterKind.throughput, first.kind);
584 try std.testing.expectEqualStrings("coz.test.slot.first", first.name);
585 }
586
587 test "a profiler reinstalled at a released address resolves fresh counters" {
588 const allocator = std.testing.allocator;
589 const name = "coz.test.reinstall";
590 var local_profiler: Profiler = .{};
591 for (0..2) |_| {
592 local_profiler = .{};
593 installProfiler(allocator, &local_profiler);
594 defer {
595 uninstallProfiler(&local_profiler);
596 local_profiler.deinit(allocator);
597 }
598
599 progressNamed(name);
600 begin(name);
601 const throughput = try local_profiler.registry.getThroughputPoint(allocator, name);
602 const latency = try local_profiler.registry.getLatencyPoint(allocator, name);
603 try std.testing.expectEqual(@as(usize, 1), throughput.getCount());
604 try std.testing.expectEqual(@as(usize, 1), latency.getBeginCount());
605 try std.testing.expectEqual(@as(usize, 0), latency.getEndCount());
606 }
607 }
608
609 test "default progress name uses the callsite source location" {
610 var local_profiler: Profiler = .{};
611 installProfiler(std.testing.allocator, &local_profiler);
612 defer {
613 uninstallProfiler(&local_profiler);
614 local_profiler.deinit(std.testing.allocator);
615 }
616
617 const expected = comptime std.fmt.comptimePrint("{s}:{d}", .{ @src().file, @src().line + 1 });
618 progress(@src());
619
620 const throughput = try local_profiler.registry.getThroughputPoint(std.testing.allocator, expected);
621 try std.testing.expectEqual(@as(usize, 1), throughput.getCount());
622 }
623
624 test "scope pairs begin and end counters" {
625 var local_profiler: Profiler = .{};
626 installProfiler(std.testing.allocator, &local_profiler);
627 defer {
628 uninstallProfiler(&local_profiler);
629 local_profiler.deinit(std.testing.allocator);
630 }
631
632 const latency_point = try local_profiler.registry.getLatencyPoint(std.testing.allocator, "coz.test.latency");
633
634 {
635 const latency = scope("coz.test.latency");
636 defer latency.end();
637 try std.testing.expectEqual(@as(usize, 1), latency_point.getBeginCount());
638 try std.testing.expectEqual(@as(usize, 0), latency_point.getEndCount());
639 }
640
641 try std.testing.expectEqual(@as(usize, 1), latency_point.getBeginCount());
642 try std.testing.expectEqual(@as(usize, 1), latency_point.getEndCount());
643 }
644
645 test "markers and blocking hooks are inert without installed profiler" {
646 current_thread = .{};
647 defer current_thread = .{};
648
649 try std.testing.expect(!profilerPresent());
650 progressNamed("coz.inert.progress");
651 begin("coz.inert.latency");
652 end("coz.inert.latency");
653 preBlock();
654 catchUp();
655 postBlock(true);
656
657 try std.testing.expectEqual(@as(u64, 0), current_thread.delay_state.localDelay());
658 try std.testing.expect(!current_thread.delay_state.checkInUse());
659 }
660
661 test "installed profiler receives marker counters" {
662 var local_profiler: Profiler = .{};
663 installProfiler(std.testing.allocator, &local_profiler);
664 defer {
665 uninstallProfiler(&local_profiler);
666 local_profiler.deinit(std.testing.allocator);
667 }
668
669 try std.testing.expect(profilerPresent());
670
671 progressNamed("coz.local.progress");
672 begin("coz.local.latency");
673 end("coz.local.latency");
674
675 const throughput = try local_profiler.registry.getThroughputPoint(std.testing.allocator, "coz.local.progress");
676 const latency = try local_profiler.registry.getLatencyPoint(std.testing.allocator, "coz.local.latency");
677
678 try std.testing.expectEqual(@as(usize, 1), throughput.getCount());
679 try std.testing.expectEqual(@as(usize, 1), latency.getBeginCount());
680 try std.testing.expectEqual(@as(usize, 1), latency.getEndCount());
681 }
682
683 test "installed profiler is visible to sampling signal handler without lock" {
684 var local_profiler: Profiler = .{};
685
686 try std.testing.expect(activeProfilerForSignal() == null);
687 installProfiler(std.testing.allocator, &local_profiler);
688 defer {
689 uninstallProfiler(&local_profiler);
690 local_profiler.deinit(std.testing.allocator);
691 }
692
693 try std.testing.expectEqual(&local_profiler, activeProfilerForSignal().?);
694 }
695
696 test "sampling signal handler processes current thread state" {
697 var local_profiler: Profiler = .{};
698 current_thread = .{};
699 installProfiler(std.testing.allocator, &local_profiler);
700 defer {
701 uninstallProfiler(&local_profiler);
702 local_profiler.deinit(std.testing.allocator);
703 current_thread = .{};
704 }
705
706 local_profiler.delays.global_delay_ns.store(33, .monotonic);
707
708 var info: signals.SignalInfo = undefined;
709 sampleSignalHandler(timer.sample_signal, &info, null);
710
711 try std.testing.expectEqual(@as(u64, 33), current_thread.delay_state.localDelay());
712 try std.testing.expect(!current_thread.delay_state.checkInUse());
713 }
714
715 test "runtime installs profiler lifecycle without sampling resources" {
716 var runtime: Runtime = .{};
717
718 try runtime.start(std.testing.allocator, .{
719 .install_signal_handler = false,
720 .start_current_thread = false,
721 });
722
723 try std.testing.expectEqual(&runtime.profiler, activeProfilerForSignal().?);
724
725 progressNamed("coz.runtime.progress");
726 const throughput = try runtime.profiler.registry.getThroughputPoint(std.testing.allocator, "coz.runtime.progress");
727 try std.testing.expectEqual(@as(usize, 1), throughput.getCount());
728
729 runtime.shutdown();
730 runtime.shutdown();
731
732 try std.testing.expect(activeProfilerForSignal() == null);
733 }
734
735 test "runtime optional start reports profiler availability" {
736 var runtime: Runtime = .{};
737
738 const available = try runtime.startIfAvailable(std.testing.allocator, .{
739 .install_signal_handler = false,
740 .start_current_thread = false,
741 });
742 defer runtime.shutdown();
743
744 try std.testing.expect(available);
745 try std.testing.expect(profilerPresent());
746 try std.testing.expectEqual(&runtime.profiler, activeProfilerForSignal().?);
747 }
748
749 test "runtime writes profile events to supplied writer" {
750 var runtime: Runtime = .{};
751 var buffer: [1024]u8 = undefined;
752 var writer = std.Io.Writer.fixed(&buffer);
753
754 try runtime.start(std.testing.allocator, .{
755 .install_signal_handler = false,
756 .start_current_thread = false,
757 .profile_writer = &writer,
758 });
759
760 var sample_thread: delay.ThreadState = .{};
761 _ = try runtime.profiler.addSourceRange(std.testing.allocator, "/tmp/runtime.zig", 9, try source_map.Interval.init(100, 110));
762 _ = runtime.profiler.observeSample(&sample_thread, .{ .ip = 105 });
763
764 try runtime.stop();
765 try runtime.stop();
766
767 var lines = std.mem.splitScalar(u8, writer.buffered(), '\n');
768
769 var startup = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
770 defer startup.deinit(std.testing.allocator);
771 switch (startup.event) {
772 .startup => |event| try std.testing.expect(event.timestamp_ns != 0),
773 else => try std.testing.expect(false),
774 }
775
776 var runtime_event = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
777 defer runtime_event.deinit(std.testing.allocator);
778 switch (runtime_event.event) {
779 .runtime => {},
780 else => try std.testing.expect(false),
781 }
782
783 var sampling = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
784 defer sampling.deinit(std.testing.allocator);
785 switch (sampling.event) {
786 .sampling => |event| {
787 try std.testing.expectEqual(@as(u64, 0), event.record_count);
788 try std.testing.expect(event.loss_counter == .unsupported);
789 try std.testing.expectEqual(profile.TerminalStatus.not_started, event.terminal_status);
790 },
791 else => try std.testing.expect(false),
792 }
793
794 var sample = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
795 defer sample.deinit(std.testing.allocator);
796 switch (sample.event) {
797 .sample => |event| {
798 try std.testing.expectEqualStrings("/tmp/runtime.zig", event.location.file);
799 try std.testing.expectEqual(@as(u64, 9), event.location.line);
800 try std.testing.expectEqual(@as(u64, 1), event.count);
801 },
802 else => try std.testing.expect(false),
803 }
804
805 try std.testing.expectEqualStrings("", lines.next().?);
806 try std.testing.expect(lines.next() == null);
807 try std.testing.expect(!runtime.profiler_installed);
808 try std.testing.expect(runtime.profile_writer == null);
809 }
810
811 test "runtime experiment step writes profile events" {
812 var runtime: Runtime = .{};
813 var buffer: [4096]u8 = undefined;
814 var writer = std.Io.Writer.fixed(&buffer);
815
816 try runtime.start(std.testing.allocator, .{
817 .install_signal_handler = false,
818 .start_current_thread = false,
819 .profile_writer = &writer,
820 });
821 defer runtime.shutdown();
822
823 const counter = try runtime.profiler.getCounter(std.testing.allocator, .throughput, "runtime.items");
824 const selected = try runtime.profiler.addSourceRange(std.testing.allocator, "/tmp/runtime-step.zig", 11, try source_map.Interval.init(100, 110));
825 var sample_thread: delay.ThreadState = .{};
826 _ = runtime.profiler.observeSample(&sample_thread, .{ .ip = 105 });
827 runtime_experiment_counter = counter;
828 defer runtime_experiment_counter = null;
829
830 const result = try runtime.runExperimentStepWithWait(
831 .{ .draw = try experiment.Draw.init(12) },
832 runtimeProgressWait,
833 true,
834 );
835
836 try std.testing.expectEqual(selected, result.selected.?);
837 try std.testing.expect(result.emitted);
838
839 var lines = std.mem.splitScalar(u8, writer.buffered(), '\n');
840
841 var startup = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
842 defer startup.deinit(std.testing.allocator);
843 switch (startup.event) {
844 .startup => |event| try std.testing.expect(event.timestamp_ns != 0),
845 else => try std.testing.expect(false),
846 }
847
848 var experiment_event = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
849 defer experiment_event.deinit(std.testing.allocator);
850 switch (experiment_event.event) {
851 .experiment => |event| {
852 try std.testing.expectEqualStrings("/tmp/runtime-step.zig", event.selected.file);
853 try std.testing.expectEqual(@as(u64, 11), event.selected.line);
854 try std.testing.expectApproxEqAbs(@as(f64, 0.25), event.virtual_speedup, 0.0000001);
855 try std.testing.expectEqual(@as(u64, 500_000_000), event.duration_ns);
856 try std.testing.expectEqual(@as(u64, 0), event.selected_samples);
857 },
858 else => try std.testing.expect(false),
859 }
860
861 var throughput = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
862 defer throughput.deinit(std.testing.allocator);
863 switch (throughput.event) {
864 .throughput => |event| {
865 try std.testing.expectEqualStrings("runtime.items", event.name);
866 try std.testing.expectEqual(@as(u64, 6), event.delta);
867 },
868 else => try std.testing.expect(false),
869 }
870
871 try std.testing.expectEqualStrings("", lines.next().?);
872 try std.testing.expect(lines.next() == null);
873
874 try runtime.stop();
875 }
876
877 test "runtime experiment worker step writes profile events" {
878 var runtime: Runtime = .{};
879 var buffer: [4096]u8 = undefined;
880 var writer = std.Io.Writer.fixed(&buffer);
881
882 try runtime.start(std.testing.allocator, .{
883 .install_signal_handler = false,
884 .start_current_thread = false,
885 .profile_writer = &writer,
886 });
887 defer runtime.shutdown();
888
889 runtime.profiler.experiment_duration_ns = experiment.experiment_cool_off_time_ns * 2;
890 runtime.experiment_worker_options = .{ .fixed_speedup_percent = 25 };
891 runtime.experiment_worker_running.store(true, .release);
892 defer runtime.experiment_worker_running.store(false, .release);
893
894 const counter = try runtime.profiler.getCounter(std.testing.allocator, .throughput, "runtime.worker.items");
895 const selected = try runtime.profiler.addSourceRange(std.testing.allocator, "/tmp/runtime-worker.zig", 17, try source_map.Interval.init(100, 110));
896 var sample_thread: delay.ThreadState = .{};
897 _ = runtime.profiler.observeSample(&sample_thread, .{ .ip = 105 });
898 runtime_experiment_counter = counter;
899 defer runtime_experiment_counter = null;
900
901 var prng = std.Random.DefaultPrng.init(1234);
902 const result = try runtime.runExperimentWorkerStepWithWait(&prng, runtimeProgressWait);
903
904 try std.testing.expectEqual(selected, result.selected.?);
905 try std.testing.expect(result.emitted);
906
907 var lines = std.mem.splitScalar(u8, writer.buffered(), '\n');
908 _ = lines.next().?;
909
910 var experiment_event = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
911 defer experiment_event.deinit(std.testing.allocator);
912 switch (experiment_event.event) {
913 .experiment => |event| {
914 try std.testing.expectEqualStrings("/tmp/runtime-worker.zig", event.selected.file);
915 try std.testing.expectEqual(@as(u64, 17), event.selected.line);
916 try std.testing.expectApproxEqAbs(@as(f64, 0.25), event.virtual_speedup, 0.0000001);
917 try std.testing.expectEqual(experiment.experiment_cool_off_time_ns * 2, event.duration_ns);
918 },
919 else => try std.testing.expect(false),
920 }
921
922 var throughput = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
923 defer throughput.deinit(std.testing.allocator);
924 switch (throughput.event) {
925 .throughput => |event| {
926 try std.testing.expectEqualStrings("runtime.worker.items", event.name);
927 try std.testing.expectEqual(@as(u64, 12), event.delta);
928 },
929 else => try std.testing.expect(false),
930 }
931 }
932
933 test "runtime experiment step requires a started writer" {
934 var runtime: Runtime = .{};
935
936 try std.testing.expectError(error.RuntimeNotStarted, runtime.runExperimentStep(.{}));
937
938 try runtime.start(std.testing.allocator, .{
939 .install_signal_handler = false,
940 .start_current_thread = false,
941 });
942 defer runtime.shutdown();
943
944 try std.testing.expectError(error.ProfileWriterUnavailable, runtime.runExperimentStep(.{}));
945 }
946
947 test "runtime experiment worker requires a profile writer" {
948 var runtime: Runtime = .{};
949
950 try std.testing.expectError(error.ProfileWriterUnavailable, runtime.start(std.testing.allocator, .{
951 .install_signal_handler = false,
952 .start_current_thread = false,
953 .start_experiment_worker = true,
954 }));
955
956 try std.testing.expect(!runtime.profiler_installed);
957 try std.testing.expect(activeProfilerForSignal() == null);
958 }
959
960 test "runtime starts and stops experiment worker" {
961 var runtime: Runtime = .{};
962 var buffer: [1024]u8 = undefined;
963 var writer = std.Io.Writer.fixed(&buffer);
964
965 try runtime.start(std.testing.allocator, .{
966 .install_signal_handler = false,
967 .start_current_thread = false,
968 .profile_writer = &writer,
969 .start_experiment_worker = true,
970 });
971
972 try std.testing.expect(runtime.experiment_worker != null);
973 try std.testing.expect(runtime.experiment_worker_running.load(.acquire));
974
975 try runtime.stop();
976
977 try std.testing.expect(runtime.experiment_worker == null);
978 try std.testing.expect(!runtime.experiment_worker_running.load(.acquire));
979 try std.testing.expect(!runtime.profiler_installed);
980 }
981
982 test "runtime optional start preserves configuration errors" {
983 var runtime: Runtime = .{};
984
985 try std.testing.expectError(error.InvalidSamplePeriod, runtime.startIfAvailable(std.testing.allocator, .{
986 .install_signal_handler = false,
987 .sampler_options = .{ .sample_period_ns = 0 },
988 }));
989
990 try std.testing.expect(!profilerPresent());
991 try std.testing.expect(activeProfilerForSignal() == null);
992 }
993
994 test "runtime unavailable classifies host sampling failures only" {
995 try std.testing.expect(runtimeUnavailable(error.UnsupportedPlatform));
996 try std.testing.expect(runtimeUnavailable(error.PermissionDenied));
997 try std.testing.expect(runtimeUnavailable(error.DeviceBusy));
998 try std.testing.expect(runtimeUnavailable(error.ProcessResources));
999 try std.testing.expect(runtimeUnavailable(error.EventRequiresUnsupportedCpuFeature));
1000 try std.testing.expect(runtimeUnavailable(error.TooManyBreakpoints));
1001 try std.testing.expect(runtimeUnavailable(error.SampleStackNotSupported));
1002 try std.testing.expect(runtimeUnavailable(error.EventNotSupported));
1003 try std.testing.expect(runtimeUnavailable(error.SampleMaxStackOverflow));
1004 try std.testing.expect(runtimeUnavailable(error.ProcessNotFound));
1005 try std.testing.expect(runtimeUnavailable(error.SystemResources));
1006 try std.testing.expect(runtimeUnavailable(error.TooBig));
1007 try std.testing.expect(!runtimeUnavailable(error.InvalidSamplePeriod));
1008 try std.testing.expect(!runtimeUnavailable(error.RuntimeAlreadyStarted));
1009 }
1010
1011 test "runtime starts and stops current thread sampler" {
1012 var runtime: Runtime = .{};
1013 var buffer: [2048]u8 = undefined;
1014 var writer = std.Io.Writer.fixed(&buffer);
1015
1016 runtime.start(std.testing.allocator, .{
1017 .sampler_options = .{
1018 .sample_period_ns = std.time.ns_per_s * 60,
1019 .sample_batch_size = 1,
1020 },
1021 .profile_writer = &writer,
1022 }) catch |err| {
1023 if (runtimeUnavailable(err)) return error.SkipZigTest;
1024 return err;
1025 };
1026
1027 try std.testing.expectEqual(&runtime.profiler, activeProfilerForSignal().?);
1028 try std.testing.expect(current_thread.sampler.event.fd != perf.invalid_fd);
1029 try std.testing.expect(current_thread.sampler.wake_timer.id != timer.invalid_timer_id);
1030
1031 try runtime.stop();
1032 var lines = std.mem.splitScalar(u8, writer.buffered(), '\n');
1033 _ = lines.next().?;
1034 _ = lines.next().?;
1035 var sampling = try profile.parseJsonLine(std.testing.allocator, lines.next().?);
1036 defer sampling.deinit(std.testing.allocator);
1037 const sampling_event = switch (sampling.event) {
1038 .sampling => |event| event,
1039 else => return error.WrongEvent,
1040 };
1041
1042 try std.testing.expect(activeProfilerForSignal() == null);
1043 try std.testing.expectEqual(perf.invalid_fd, current_thread.sampler.event.fd);
1044 try std.testing.expectEqual(timer.invalid_timer_id, current_thread.sampler.wake_timer.id);
1045 try std.testing.expectEqual(profile.TerminalStatus.complete, sampling_event.terminal_status);
1046 }
1047
1048 test "installed profiler receives blocking hooks" {
1049 var local_profiler: Profiler = .{};
1050 current_thread = .{};
1051 installProfiler(std.testing.allocator, &local_profiler);
1052 defer {
1053 uninstallProfiler(&local_profiler);
1054 local_profiler.deinit(std.testing.allocator);
1055 current_thread = .{};
1056 }
1057
1058 local_profiler.delays.startExperiment(0);
1059
1060 preBlock();
1061 local_profiler.delays.global_delay_ns.store(40, .monotonic);
1062 catchUp();
1063 postBlock(true);
1064
1065 try std.testing.expectEqual(@as(u64, 40), current_thread.delay_state.localDelay());
1066 }