lib/tracy/src/lock.zig
daab053ee43316e1809a84551d573ddd1e5bf3d2
1 const std = @import("std");
2 const pretty_json = @import("pretty").json;
3 const capture_mod = @import("capture.zig");
4 const report = @import("report.zig");
5 const event = @import("event.zig");
6 const record_mod = @import("record.zig");
7 const transport = @import("transport.zig");
8
9 pub const schema = "tracy.locks/v0";
10 pub const CaptureIntegrity = capture_mod.Integrity;
11
12 pub const Mode = enum {
13 all,
14 lock,
15 shared,
16
17 pub fn fromName(text: []const u8) ?Mode {
18 if (std.mem.eql(u8, text, "all")) return .all;
19 if (std.mem.eql(u8, text, "lock")) return .lock;
20 if (std.mem.eql(u8, text, "shared")) return .shared;
21 return null;
22 }
23
24 fn tag(self: Mode) []const u8 {
25 return switch (self) {
26 .all => "all",
27 .lock => "lock",
28 .shared => "shared",
29 };
30 }
31 };
32
33 pub const Kind = enum {
34 all,
35 wait,
36 hold,
37
38 pub fn fromName(text: []const u8) ?Kind {
39 if (std.mem.eql(u8, text, "all")) return .all;
40 if (std.mem.eql(u8, text, "wait")) return .wait;
41 if (std.mem.eql(u8, text, "hold")) return .hold;
42 return null;
43 }
44
45 fn tag(self: Kind) []const u8 {
46 return switch (self) {
47 .all => "all",
48 .wait => "wait",
49 .hold => "hold",
50 };
51 }
52 };
53
54 pub const Sort = enum {
55 wait,
56 wait_tail,
57 hold,
58 hold_tail,
59 contention,
60 count,
61 name,
62 last,
63
64 pub fn fromName(text: []const u8) ?Sort {
65 if (std.mem.eql(u8, text, "wait")) return .wait;
66 if (std.mem.eql(u8, text, "wait-tail")) return .wait_tail;
67 if (std.mem.eql(u8, text, "hold")) return .hold;
68 if (std.mem.eql(u8, text, "hold-tail")) return .hold_tail;
69 if (std.mem.eql(u8, text, "contention")) return .contention;
70 if (std.mem.eql(u8, text, "count")) return .count;
71 if (std.mem.eql(u8, text, "name")) return .name;
72 if (std.mem.eql(u8, text, "last")) return .last;
73 return null;
74 }
75
76 fn tag(self: Sort) []const u8 {
77 return switch (self) {
78 .wait => "wait",
79 .wait_tail => "wait-tail",
80 .hold => "hold",
81 .hold_tail => "hold-tail",
82 .contention => "contention",
83 .count => "count",
84 .name => "name",
85 .last => "last",
86 };
87 }
88 };
89
90 pub const Options = struct {
91 top: usize = 20,
92 occurrences: usize = 40,
93 sort: Sort = .wait,
94 kind: Kind = .all,
95 mode: Mode = .all,
96 min_wait_ns: u64 = 0,
97 min_hold_ns: u64 = 0,
98 lock: ?u64 = null,
99 thread: ?u64 = null,
100 since_ns: ?u64 = null,
101 until_ns: ?u64 = null,
102 match: ?[]const u8 = null,
103 ignore_case: bool = false,
104 };
105
106 pub const Counters = struct {
107 events: u64 = 0,
108 announces: u64 = 0,
109 terminates: u64 = 0,
110 names: u64 = 0,
111 marks: u64 = 0,
112 waits: u64 = 0,
113 obtains: u64 = 0,
114 releases: u64 = 0,
115 shared_waits: u64 = 0,
116 shared_obtains: u64 = 0,
117 shared_releases: u64 = 0,
118 completed_waits: u64 = 0,
119 completed_holds: u64 = 0,
120 wait_samples: u64 = 0,
121 hold_samples: u64 = 0,
122 duplicate_waits: u64 = 0,
123 duplicate_obtains: u64 = 0,
124 timestamp_regressions: u64 = 0,
125 unmatched_releases: u64 = 0,
126 };
127
128 const SlotKey = struct {
129 lock: u64,
130 thread: u64,
131 shared: bool,
132 };
133
134 const WaitRecord = struct {
135 start_ns: u64,
136 };
137
138 const HoldRecord = struct {
139 start_ns: u64,
140 };
141
142 const Entry = struct {
143 kind: Kind,
144 lock: u64,
145 thread: u64,
146 shared: bool,
147 start_ns: u64,
148 end_ns: u64,
149 duration_ns: u64,
150 valid_time: bool = true,
151 };
152
153 const DurationSample = struct {
154 lock: u64,
155 duration_ns: u64,
156 };
157
158 const LockState = struct {
159 id: u64,
160 mode: Mode = .lock,
161 name: ?[]u8 = null,
162 file: ?[]u8 = null,
163 function: ?[]u8 = null,
164 line: u32 = 0,
165 column: u32 = 0,
166 announce_ns: u64 = 0,
167 terminate_ns: u64 = 0,
168 last_event_ns: u64 = 0,
169 mark_count: u64 = 0,
170 last_mark_file: ?[]u8 = null,
171 last_mark_function: ?[]u8 = null,
172 last_mark_line: u32 = 0,
173 threads: std.AutoHashMapUnmanaged(u64, void) = .{},
174
175 fn deinit(self: *LockState, allocator: std.mem.Allocator) void {
176 if (self.name) |name| allocator.free(name);
177 if (self.file) |file| allocator.free(file);
178 if (self.function) |function| allocator.free(function);
179 if (self.last_mark_file) |file| allocator.free(file);
180 if (self.last_mark_function) |function| allocator.free(function);
181 self.threads.deinit(allocator);
182 self.* = undefined;
183 }
184
185 fn displayName(self: LockState) []const u8 {
186 return self.name orelse "<lock>";
187 }
188 };
189
190 const Row = struct {
191 id: u64,
192 name: []const u8,
193 mode: Mode,
194 file: ?[]const u8,
195 function: ?[]const u8,
196 line: u32,
197 column: u32,
198 announce_ns: u64,
199 terminate_ns: u64,
200 last_event_ns: u64,
201 mark_count: u64,
202 last_mark_file: ?[]const u8,
203 last_mark_function: ?[]const u8,
204 last_mark_line: u32,
205 thread_count: u64,
206 wait_count: u64 = 0,
207 hold_count: u64 = 0,
208 total_wait_ns: u64 = 0,
209 wait_mean_ns: u64 = 0,
210 wait_min_ns: u64 = 0,
211 wait_p50_ns: u64 = 0,
212 wait_p90_ns: u64 = 0,
213 wait_p99_ns: u64 = 0,
214 max_wait_ns: u64 = 0,
215 total_hold_ns: u64 = 0,
216 hold_mean_ns: u64 = 0,
217 hold_min_ns: u64 = 0,
218 hold_p50_ns: u64 = 0,
219 hold_p90_ns: u64 = 0,
220 hold_p99_ns: u64 = 0,
221 max_hold_ns: u64 = 0,
222
223 fn eventCount(self: Row) u64 {
224 return self.wait_count + self.hold_count;
225 }
226 };
227
228 pub const Summary = Row;
229
230 pub const Analyzer = struct {
231 allocator: std.mem.Allocator,
232 capture: capture_mod.Tracker = .{},
233 locks: std.AutoHashMapUnmanaged(u64, LockState) = .{},
234 pending_waits: std.AutoHashMapUnmanaged(SlotKey, WaitRecord) = .{},
235 pending_holds: std.AutoHashMapUnmanaged(SlotKey, HoldRecord) = .{},
236 entries: std.ArrayListUnmanaged(Entry) = .empty,
237 counters: Counters = .{},
238 start_ns: ?u64 = null,
239 end_ns: ?u64 = null,
240
241 pub fn init(allocator: std.mem.Allocator) Analyzer {
242 return .{ .allocator = allocator };
243 }
244
245 pub fn deinit(self: *Analyzer) void {
246 var lock_iter = self.locks.valueIterator();
247 while (lock_iter.next()) |lock| lock.deinit(self.allocator);
248 self.locks.deinit(self.allocator);
249 self.pending_waits.deinit(self.allocator);
250 self.pending_holds.deinit(self.allocator);
251 self.entries.deinit(self.allocator);
252 self.* = undefined;
253 }
254
255 pub fn ingestJsonlBytes(self: *Analyzer, bytes: []const u8) !void {
256 var lines = std.mem.splitScalar(u8, bytes, '\n');
257 while (lines.next()) |line| try self.ingestJsonLine(line);
258 }
259
260 pub fn ingestJsonLine(self: *Analyzer, line: []const u8) !void {
261 const text = std.mem.trim(u8, line, " \t\r\n");
262 if (text.len == 0) return;
263 var parsed = try record_mod.parseLine(self.allocator, text);
264 defer parsed.deinit();
265 switch (parsed) {
266 .event => |value| try self.ingest(value),
267 .flight => |report_value| self.recordFlightReport(report_value),
268 }
269 }
270
271 pub fn ingest(self: *Analyzer, parsed: event.Parsed) !void {
272 self.capture.record(parsed);
273 self.counters.events += 1;
274 if (self.start_ns == null and parsed.time_ns != 0) self.start_ns = parsed.time_ns;
275 if (parsed.time_ns != 0) self.end_ns = parsed.time_ns;
276 switch (parsed.kind) {
277 .start => {
278 if (parsed.time_ns != 0) self.start_ns = parsed.time_ns;
279 },
280 .stop => {
281 if (parsed.time_ns != 0) self.end_ns = parsed.time_ns;
282 },
283 .lock_announce => try self.recordAnnounce(parsed),
284 .lock_terminate => try self.recordTerminate(parsed),
285 .lock_name => try self.recordName(parsed),
286 .lock_mark => try self.recordMark(parsed),
287 .lock_wait => try self.recordWait(parsed, false),
288 .lock_obtain => try self.recordObtain(parsed, false),
289 .lock_release => try self.recordRelease(parsed, false),
290 .lock_shared_wait => try self.recordWait(parsed, true),
291 .lock_shared_obtain => try self.recordObtain(parsed, true),
292 .lock_shared_release => try self.recordRelease(parsed, true),
293 else => {},
294 }
295 }
296
297 pub fn durationNs(self: Analyzer) u64 {
298 const start_ns = self.start_ns orelse return 0;
299 const end_ns = self.end_ns orelse return 0;
300 if (end_ns <= start_ns) return 0;
301 return end_ns - start_ns;
302 }
303
304 pub fn captureIntegrity(self: Analyzer) CaptureIntegrity {
305 return self.capture.integrity(0);
306 }
307
308 pub fn durationEvidence(self: Analyzer) []const u8 {
309 if (!std.mem.eql(u8, self.captureIntegrity().status, "complete")) return "partial";
310 if (self.counters.timestamp_regressions != 0) return "partial";
311 if (self.counters.duplicate_waits != 0) return "partial";
312 if (self.counters.duplicate_obtains != 0) return "partial";
313 if (self.counters.unmatched_releases != 0) return "partial";
314 if (self.pending_waits.count() != 0) return "partial";
315 if (self.pending_holds.count() != 0) return "partial";
316 return "complete";
317 }
318
319 pub fn recordFlightReport(self: *Analyzer, report_value: transport.Report) void {
320 self.capture.recordFlightReport(report_value);
321 }
322
323 pub fn collectRows(
324 self: *Analyzer,
325 allocator: std.mem.Allocator,
326 options: Options,
327 ) !std.ArrayListUnmanaged(Row) {
328 var rows: std.ArrayListUnmanaged(Row) = .empty;
329 errdefer rows.deinit(allocator);
330 var row_index: std.AutoHashMapUnmanaged(u64, usize) = .{};
331 defer row_index.deinit(allocator);
332 var wait_samples: std.ArrayListUnmanaged(DurationSample) = .empty;
333 defer wait_samples.deinit(allocator);
334 var hold_samples: std.ArrayListUnmanaged(DurationSample) = .empty;
335 defer hold_samples.deinit(allocator);
336 for (self.entries.items) |entry| {
337 if (!self.entryMatches(entry, options)) continue;
338 if (!entry.valid_time) continue;
339 const row_pos = try self.rowForEntry(allocator, &rows, &row_index, entry.lock);
340 if (entry.kind == .wait) {
341 rows.items[row_pos].wait_count += 1;
342 rows.items[row_pos].total_wait_ns +|= entry.duration_ns;
343 rows.items[row_pos].max_wait_ns = @max(
344 rows.items[row_pos].max_wait_ns,
345 entry.duration_ns,
346 );
347 try wait_samples.append(allocator, .{
348 .lock = entry.lock,
349 .duration_ns = entry.duration_ns,
350 });
351 } else if (entry.kind == .hold) {
352 rows.items[row_pos].hold_count += 1;
353 rows.items[row_pos].total_hold_ns +|= entry.duration_ns;
354 rows.items[row_pos].max_hold_ns = @max(
355 rows.items[row_pos].max_hold_ns,
356 entry.duration_ns,
357 );
358 try hold_samples.append(allocator, .{
359 .lock = entry.lock,
360 .duration_ns = entry.duration_ns,
361 });
362 }
363 rows.items[row_pos].last_event_ns = @max(
364 rows.items[row_pos].last_event_ns,
365 entry.end_ns,
366 );
367 }
368 applyDurationDistributions(rows.items, &row_index, wait_samples.items, .wait);
369 applyDurationDistributions(rows.items, &row_index, hold_samples.items, .hold);
370 sortRows(rows.items, options.sort);
371 if (rows.items.len > options.top) rows.shrinkRetainingCapacity(options.top);
372 return rows;
373 }
374
375 pub fn collectOccurrences(
376 self: *Analyzer,
377 allocator: std.mem.Allocator,
378 options: Options,
379 ) !std.ArrayListUnmanaged(Entry) {
380 var rows: std.ArrayListUnmanaged(Entry) = .empty;
381 errdefer rows.deinit(allocator);
382 for (self.entries.items) |entry| {
383 if (!self.entryMatches(entry, options)) continue;
384 try rows.append(allocator, entry);
385 }
386 std.mem.sort(Entry, rows.items, {}, entryDurationGreaterThan);
387 if (rows.items.len > options.occurrences) {
388 rows.shrinkRetainingCapacity(options.occurrences);
389 }
390 return rows;
391 }
392
393 fn recordAnnounce(self: *Analyzer, parsed: event.Parsed) !void {
394 if (parsed.id == 0) return;
395 const lock = try self.ensureLock(parsed.id);
396 lock.mode = parseMode(parsed.lock_kind);
397 lock.announce_ns = parsed.time_ns;
398 lock.last_event_ns = parsed.time_ns;
399 try replaceOptional(self.allocator, &lock.name, parsed.name);
400 try replaceOptional(self.allocator, &lock.file, parsed.file);
401 try replaceOptional(self.allocator, &lock.function, parsed.function);
402 lock.line = parsed.line;
403 lock.column = parsed.column;
404 self.counters.announces += 1;
405 }
406
407 fn recordTerminate(self: *Analyzer, parsed: event.Parsed) !void {
408 if (parsed.id == 0) return;
409 const lock = try self.ensureLock(parsed.id);
410 lock.terminate_ns = parsed.time_ns;
411 lock.last_event_ns = parsed.time_ns;
412 self.counters.terminates += 1;
413 }
414
415 fn recordName(self: *Analyzer, parsed: event.Parsed) !void {
416 if (parsed.id == 0) return;
417 const name = parsed.name orelse return;
418 const lock = try self.ensureLock(parsed.id);
419 try replaceOptional(self.allocator, &lock.name, name);
420 lock.last_event_ns = parsed.time_ns;
421 self.counters.names += 1;
422 }
423
424 fn recordMark(self: *Analyzer, parsed: event.Parsed) !void {
425 if (parsed.id == 0) return;
426 const lock = try self.ensureLock(parsed.id);
427 lock.mark_count += 1;
428 lock.last_event_ns = parsed.time_ns;
429 lock.last_mark_line = parsed.line;
430 try replaceOptional(self.allocator, &lock.last_mark_file, parsed.file);
431 try replaceOptional(self.allocator, &lock.last_mark_function, parsed.function);
432 try self.recordThread(lock, parsed.thread);
433 self.counters.marks += 1;
434 }
435
436 fn recordWait(self: *Analyzer, parsed: event.Parsed, shared: bool) !void {
437 if (parsed.id == 0) return;
438 const lock = try self.ensureLock(parsed.id);
439 if (shared) {
440 lock.mode = .shared;
441 self.counters.shared_waits += 1;
442 } else {
443 self.counters.waits += 1;
444 }
445 lock.last_event_ns = parsed.time_ns;
446 try self.recordThread(lock, parsed.thread);
447 const key = SlotKey{ .lock = parsed.id, .thread = parsed.thread, .shared = shared };
448 if (self.pending_waits.contains(key)) {
449 self.counters.duplicate_waits +|= 1;
450 return;
451 }
452 try self.pending_waits.put(self.allocator, key, .{ .start_ns = parsed.time_ns });
453 }
454
455 fn recordObtain(self: *Analyzer, parsed: event.Parsed, shared: bool) !void {
456 if (parsed.id == 0) return;
457 const lock = try self.ensureLock(parsed.id);
458 if (shared) {
459 lock.mode = .shared;
460 self.counters.shared_obtains += 1;
461 } else {
462 self.counters.obtains += 1;
463 }
464 lock.last_event_ns = parsed.time_ns;
465 try self.recordThread(lock, parsed.thread);
466 const key = SlotKey{ .lock = parsed.id, .thread = parsed.thread, .shared = shared };
467 if (self.pending_waits.fetchRemove(key)) |removed| {
468 try self.recordCompleted(
469 .wait,
470 parsed.id,
471 parsed.thread,
472 shared,
473 removed.value.start_ns,
474 parsed.time_ns,
475 );
476 }
477 if (self.pending_holds.contains(key)) {
478 self.counters.duplicate_obtains +|= 1;
479 return;
480 }
481 try self.pending_holds.put(self.allocator, key, .{ .start_ns = parsed.time_ns });
482 }
483
484 fn recordRelease(self: *Analyzer, parsed: event.Parsed, shared: bool) !void {
485 if (parsed.id == 0) return;
486 const lock = try self.ensureLock(parsed.id);
487 if (shared) {
488 lock.mode = .shared;
489 self.counters.shared_releases += 1;
490 } else {
491 self.counters.releases += 1;
492 }
493 lock.last_event_ns = parsed.time_ns;
494 try self.recordThread(lock, parsed.thread);
495 const key = SlotKey{ .lock = parsed.id, .thread = parsed.thread, .shared = shared };
496 if (self.pending_holds.fetchRemove(key)) |removed| {
497 try self.recordCompleted(
498 .hold,
499 parsed.id,
500 parsed.thread,
501 shared,
502 removed.value.start_ns,
503 parsed.time_ns,
504 );
505 } else {
506 self.counters.unmatched_releases +|= 1;
507 }
508 }
509
510 fn recordCompleted(
511 self: *Analyzer,
512 kind: Kind,
513 lock: u64,
514 thread: u64,
515 shared: bool,
516 start_ns: u64,
517 end_ns: u64,
518 ) !void {
519 const valid_time = end_ns >= start_ns;
520 try self.recordEntry(.{
521 .kind = kind,
522 .lock = lock,
523 .thread = thread,
524 .shared = shared,
525 .start_ns = start_ns,
526 .end_ns = end_ns,
527 .duration_ns = duration(start_ns, end_ns),
528 .valid_time = valid_time,
529 });
530 switch (kind) {
531 .wait => {
532 self.counters.completed_waits +|= 1;
533 if (valid_time) self.counters.wait_samples +|= 1;
534 },
535 .hold => {
536 self.counters.completed_holds +|= 1;
537 if (valid_time) self.counters.hold_samples +|= 1;
538 },
539 .all => unreachable,
540 }
541 if (!valid_time) self.counters.timestamp_regressions +|= 1;
542 }
543
544 fn recordEntry(self: *Analyzer, entry: Entry) !void {
545 try self.entries.append(self.allocator, entry);
546 }
547
548 fn ensureLock(self: *Analyzer, id: u64) !*LockState {
549 const entry = try self.locks.getOrPut(self.allocator, id);
550 if (!entry.found_existing) {
551 entry.value_ptr.* = .{ .id = id };
552 }
553 return entry.value_ptr;
554 }
555
556 fn recordThread(self: *Analyzer, lock: *LockState, thread: u64) !void {
557 try lock.threads.put(self.allocator, thread, {});
558 }
559
560 fn entryMatches(self: *Analyzer, entry: Entry, options: Options) bool {
561 if (options.kind != .all and entry.kind != options.kind) return false;
562 if (options.mode != .all and entryMode(entry) != options.mode) return false;
563 if (options.lock) |lock_id| {
564 if (entry.lock != lock_id) return false;
565 }
566 if (options.thread) |thread| {
567 if (entry.thread != thread) return false;
568 }
569 if (entry.kind == .wait and entry.duration_ns < options.min_wait_ns) return false;
570 if (entry.kind == .hold and entry.duration_ns < options.min_hold_ns) return false;
571 if (options.since_ns) |since_ns| {
572 if (entry.end_ns < since_ns) return false;
573 }
574 if (options.until_ns) |until_ns| {
575 if (entry.start_ns > until_ns) return false;
576 }
577 if (options.match) |needle| {
578 const lock = self.locks.get(entry.lock) orelse return false;
579 if (!lockContains(lock, needle, options.ignore_case)) return false;
580 }
581 return true;
582 }
583
584 fn rowForEntry(
585 self: *Analyzer,
586 allocator: std.mem.Allocator,
587 rows: *std.ArrayListUnmanaged(Row),
588 row_index: *std.AutoHashMapUnmanaged(u64, usize),
589 lock_id: u64,
590 ) !usize {
591 if (row_index.get(lock_id)) |index| return index;
592 const lock = self.locks.get(lock_id) orelse LockState{ .id = lock_id };
593 const index = rows.items.len;
594 try rows.append(allocator, .{
595 .id = lock_id,
596 .name = lock.displayName(),
597 .mode = lock.mode,
598 .file = lock.file,
599 .function = lock.function,
600 .line = lock.line,
601 .column = lock.column,
602 .announce_ns = lock.announce_ns,
603 .terminate_ns = lock.terminate_ns,
604 .last_event_ns = lock.last_event_ns,
605 .mark_count = lock.mark_count,
606 .last_mark_file = lock.last_mark_file,
607 .last_mark_function = lock.last_mark_function,
608 .last_mark_line = lock.last_mark_line,
609 .thread_count = lock.threads.count(),
610 });
611 try row_index.put(allocator, lock_id, index);
612 return index;
613 }
614 };
615
616 pub fn writeTextFromJsonlPath(
617 allocator: std.mem.Allocator,
618 path: []const u8,
619 writer: *std.Io.Writer,
620 options: Options,
621 ) !void {
622 return report.writeFromJsonlPath(Analyzer, writeText, allocator, path, writer, options);
623 }
624
625 pub fn writeJsonlFromJsonlPath(
626 allocator: std.mem.Allocator,
627 path: []const u8,
628 writer: *std.Io.Writer,
629 options: Options,
630 ) !void {
631 return report.writeFromJsonlPath(Analyzer, writeJsonl, allocator, path, writer, options);
632 }
633
634 pub fn ingestPath(analyzer: *Analyzer, path: []const u8) !void {
635 return report.ingestJsonlPath(analyzer, path);
636 }
637
638 fn writeText(
639 allocator: std.mem.Allocator,
640 analyzer: *Analyzer,
641 writer: *std.Io.Writer,
642 options: Options,
643 ) !void {
644 var rows = try analyzer.collectRows(allocator, options);
645 defer rows.deinit(allocator);
646 var occurrences = try analyzer.collectOccurrences(allocator, options);
647 defer occurrences.deinit(allocator);
648 try writeTextSummary(writer, analyzer, options, rows.items.len);
649 try capture_mod.writeText(writer, analyzer.captureIntegrity());
650 for (rows.items) |row| {
651 try writer.print("lock id={d} name=", .{row.id});
652 try pretty_json.writeString(writer, row.name);
653 try writer.print(" mode={s}", .{row.mode.tag()});
654 try writeSummaryDurationsText(writer, row);
655 try writer.print(" threads={d} marks={d} last_event_ns={d}", .{
656 row.thread_count,
657 row.mark_count,
658 row.last_event_ns,
659 });
660 if (row.file) |file| try writer.print(" source={s}:{d}", .{ file, row.line });
661 if (row.last_mark_file) |file| {
662 try writer.print(" mark={s}:{d}", .{ file, row.last_mark_line });
663 }
664 try writer.writeByte('\n');
665 }
666 for (occurrences.items) |entry| {
667 try writeTextOccurrence(writer, analyzer, entry);
668 }
669 }
670
671 fn writeTextSummary(
672 writer: *std.Io.Writer,
673 analyzer: *Analyzer,
674 options: Options,
675 row_count: usize,
676 ) !void {
677 try writer.print(
678 "tracy locks locks={d} rows={d} events={d} waits={d} holds={d} " ++
679 "wait_samples={d} hold_samples={d} pending_waits={d} pending_holds={d} " ++
680 "duplicate_waits={d} duplicate_obtains={d} timestamp_regressions={d} " ++
681 "unmatched_releases={d} duration_evidence={s} duration_ns={d} " ++
682 "kind={s} mode={s} sort={s}\n",
683 .{
684 analyzer.locks.count(),
685 row_count,
686 analyzer.counters.events,
687 analyzer.counters.completed_waits,
688 analyzer.counters.completed_holds,
689 analyzer.counters.wait_samples,
690 analyzer.counters.hold_samples,
691 analyzer.pending_waits.count(),
692 analyzer.pending_holds.count(),
693 analyzer.counters.duplicate_waits,
694 analyzer.counters.duplicate_obtains,
695 analyzer.counters.timestamp_regressions,
696 analyzer.counters.unmatched_releases,
697 analyzer.durationEvidence(),
698 analyzer.durationNs(),
699 options.kind.tag(),
700 options.mode.tag(),
701 options.sort.tag(),
702 },
703 );
704 }
705
706 fn writeTextOccurrence(writer: *std.Io.Writer, analyzer: *Analyzer, entry: Entry) !void {
707 try writer.print(
708 "occurrence kind={s} lock={d} mode={s} thread={d} start_ns={d} " ++
709 "end_ns={d} duration_ns={d}",
710 .{
711 entry.kind.tag(),
712 entry.lock,
713 entryMode(entry).tag(),
714 entry.thread,
715 entry.start_ns,
716 entry.end_ns,
717 entry.duration_ns,
718 },
719 );
720 if (analyzer.locks.get(entry.lock)) |lock| {
721 try writer.writeAll(" name=");
722 try pretty_json.writeString(writer, lock.displayName());
723 }
724 if (!entry.valid_time) try writer.writeAll(" valid_time=false");
725 try writer.writeByte('\n');
726 }
727
728 fn writeJsonl(
729 allocator: std.mem.Allocator,
730 analyzer: *Analyzer,
731 writer: *std.Io.Writer,
732 options: Options,
733 ) !void {
734 var rows = try analyzer.collectRows(allocator, options);
735 defer rows.deinit(allocator);
736 var occurrences = try analyzer.collectOccurrences(allocator, options);
737 defer occurrences.deinit(allocator);
738 try writeJsonSummary(writer, analyzer, options, rows.items.len);
739 for (rows.items) |row| try writeJsonLock(writer, row);
740 for (occurrences.items) |entry| try writeJsonOccurrence(writer, analyzer, entry);
741 }
742
743 fn writeJsonSummary(
744 writer: *std.Io.Writer,
745 analyzer: *Analyzer,
746 options: Options,
747 row_count: usize,
748 ) !void {
749 var stream = pretty_json.Writer.init(writer, .minified);
750 const object = try stream.object();
751 try object.field("schema", schema);
752 try object.field("kind", "summary");
753 try object.field("locks", analyzer.locks.count());
754 try object.field("rows", row_count);
755 try object.field("events", analyzer.counters.events);
756 try object.field("waits", analyzer.counters.completed_waits);
757 try object.field("holds", analyzer.counters.completed_holds);
758 try object.field("wait_samples", analyzer.counters.wait_samples);
759 try object.field("hold_samples", analyzer.counters.hold_samples);
760 try object.field("pending_waits", analyzer.pending_waits.count());
761 try object.field("pending_holds", analyzer.pending_holds.count());
762 try object.field("duplicate_waits", analyzer.counters.duplicate_waits);
763 try object.field("duplicate_obtains", analyzer.counters.duplicate_obtains);
764 try object.field("timestamp_regressions", analyzer.counters.timestamp_regressions);
765 try object.field("unmatched_releases", analyzer.counters.unmatched_releases);
766 try object.field("duration_ns", analyzer.durationNs());
767 try object.field("filter_kind", options.kind.tag());
768 try object.field("mode", options.mode.tag());
769 try object.field("sort", options.sort.tag());
770 try object.field("duration_evidence", analyzer.durationEvidence());
771 try capture_mod.writeFields(object, analyzer.captureIntegrity());
772 try object.endLine();
773 }
774
775 fn writeJsonLock(writer: *std.Io.Writer, row: Row) !void {
776 var stream = pretty_json.Writer.init(writer, .minified);
777 const object = try stream.object();
778 try object.field("schema", schema);
779 try object.field("kind", "lock");
780 try object.field("id", row.id);
781 try object.field("name", row.name);
782 try object.field("mode", row.mode.tag());
783 try writeSummaryDurationFields(object, row);
784 try object.field("threads", row.thread_count);
785 try object.field("marks", row.mark_count);
786 try object.field("announce_ns", row.announce_ns);
787 try object.field("terminate_ns", row.terminate_ns);
788 try object.field("last_event_ns", row.last_event_ns);
789 if (row.file) |file| {
790 try object.field("file", file);
791 try object.field("line", row.line);
792 }
793 if (row.function) |function| try object.field("function", function);
794 if (row.last_mark_file) |file| {
795 try object.field("mark_file", file);
796 try object.field("mark_line", row.last_mark_line);
797 }
798 if (row.last_mark_function) |function| try object.field("mark_function", function);
799 try object.endLine();
800 }
801
802 fn writeJsonOccurrence(writer: *std.Io.Writer, analyzer: *Analyzer, entry: Entry) !void {
803 var stream = pretty_json.Writer.init(writer, .minified);
804 const object = try stream.object();
805 try object.field("schema", schema);
806 try object.field("kind", entry.kind.tag());
807 try object.field("lock", entry.lock);
808 try object.field("thread", entry.thread);
809 try object.field("start_ns", entry.start_ns);
810 try object.field("end_ns", entry.end_ns);
811 try object.field("duration_ns", entry.duration_ns);
812 try object.field("mode", entryMode(entry).tag());
813 if (analyzer.locks.get(entry.lock)) |lock| try object.field("name", lock.displayName());
814 if (!entry.valid_time) try object.field("valid_time", false);
815 try object.endLine();
816 }
817
818 fn parseMode(lock_kind: ?[]const u8) Mode {
819 const text = lock_kind orelse return .lock;
820 return Mode.fromName(text) orelse .lock;
821 }
822
823 fn entryMode(entry: Entry) Mode {
824 return if (entry.shared) .shared else .lock;
825 }
826
827 fn duration(start_ns: u64, end_ns: u64) u64 {
828 if (end_ns <= start_ns) return 0;
829 return end_ns - start_ns;
830 }
831
832 fn applyDurationDistributions(
833 rows: []Row,
834 row_index: *const std.AutoHashMapUnmanaged(u64, usize),
835 samples: []DurationSample,
836 kind: Kind,
837 ) void {
838 std.mem.sort(DurationSample, samples, {}, durationSampleLessThan);
839 var start: usize = 0;
840 while (start < samples.len) {
841 var end = start + 1;
842 while (end < samples.len and samples[end].lock == samples[start].lock) : (end += 1) {}
843 const row = &rows[row_index.get(samples[start].lock).?];
844 applyDurationDistribution(row, samples[start..end], kind);
845 start = end;
846 }
847 }
848
849 fn applyDurationDistribution(row: *Row, samples: []const DurationSample, kind: Kind) void {
850 const count: u64 = @intCast(samples.len);
851 switch (kind) {
852 .wait => {
853 row.wait_mean_ns = row.total_wait_ns / count;
854 row.wait_min_ns = durationPercentile(samples, 0);
855 row.wait_p50_ns = durationPercentile(samples, 50);
856 row.wait_p90_ns = durationPercentile(samples, 90);
857 row.wait_p99_ns = durationPercentile(samples, 99);
858 row.max_wait_ns = durationPercentile(samples, 100);
859 },
860 .hold => {
861 row.hold_mean_ns = row.total_hold_ns / count;
862 row.hold_min_ns = durationPercentile(samples, 0);
863 row.hold_p50_ns = durationPercentile(samples, 50);
864 row.hold_p90_ns = durationPercentile(samples, 90);
865 row.hold_p99_ns = durationPercentile(samples, 99);
866 row.max_hold_ns = durationPercentile(samples, 100);
867 },
868 .all => unreachable,
869 }
870 }
871
872 fn durationPercentile(samples: []const DurationSample, percent: u64) u64 {
873 const rank: usize = @intCast((@as(u128, @min(percent, 100)) * samples.len + 99) / 100);
874 const index = @min(@max(rank, 1) - 1, samples.len - 1);
875 return samples[index].duration_ns;
876 }
877
878 fn durationSampleLessThan(_: void, left: DurationSample, right: DurationSample) bool {
879 if (left.lock != right.lock) return left.lock < right.lock;
880 return left.duration_ns < right.duration_ns;
881 }
882
883 fn replaceOptional(allocator: std.mem.Allocator, field: *?[]u8, text: ?[]const u8) !void {
884 if (field.*) |old| allocator.free(old);
885 field.* = null;
886 if (text) |actual| field.* = try allocator.dupe(u8, actual);
887 }
888
889 fn lockContains(lock: LockState, needle: []const u8, ignore_case: bool) bool {
890 if (contains(lock.displayName(), needle, ignore_case)) return true;
891 if (lock.file) |file| if (contains(file, needle, ignore_case)) return true;
892 if (lock.function) |function| if (contains(function, needle, ignore_case)) return true;
893 if (lock.last_mark_file) |file| if (contains(file, needle, ignore_case)) return true;
894 if (lock.last_mark_function) |function| {
895 if (contains(function, needle, ignore_case)) return true;
896 }
897 return false;
898 }
899
900 fn contains(haystack: []const u8, needle: []const u8, ignore_case: bool) bool {
901 if (!ignore_case) return std.mem.indexOf(u8, haystack, needle) != null;
902 if (needle.len == 0) return true;
903 if (needle.len > haystack.len) return false;
904 var index: usize = 0;
905 while (index + needle.len <= haystack.len) : (index += 1) {
906 if (asciiEqlIgnoreCase(haystack[index .. index + needle.len], needle)) return true;
907 }
908 return false;
909 }
910
911 fn asciiEqlIgnoreCase(left: []const u8, right: []const u8) bool {
912 if (left.len != right.len) return false;
913 for (left, right) |a, b| {
914 if (std.ascii.toLower(a) != std.ascii.toLower(b)) return false;
915 }
916 return true;
917 }
918
919 fn sortRows(items: []Row, sort: Sort) void {
920 std.mem.sort(Row, items, sort, rowLessThan);
921 }
922
923 fn rowLessThan(sort: Sort, left: Row, right: Row) bool {
924 return switch (sort) {
925 .wait => rowWaitGreaterThan({}, left, right),
926 .wait_tail => rowWaitTailGreaterThan({}, left, right),
927 .hold => rowHoldGreaterThan({}, left, right),
928 .hold_tail => rowHoldTailGreaterThan({}, left, right),
929 .contention => rowContentionGreaterThan({}, left, right),
930 .count => rowCountGreaterThan({}, left, right),
931 .name => rowNameLessThan({}, left, right),
932 .last => rowLastGreaterThan({}, left, right),
933 };
934 }
935
936 fn rowWaitGreaterThan(_: void, left: Row, right: Row) bool {
937 if (left.total_wait_ns != right.total_wait_ns) return left.total_wait_ns > right.total_wait_ns;
938 if (left.max_wait_ns != right.max_wait_ns) return left.max_wait_ns > right.max_wait_ns;
939 return rowNameLessThan({}, left, right);
940 }
941
942 fn rowWaitTailGreaterThan(_: void, left: Row, right: Row) bool {
943 if (left.wait_p99_ns != right.wait_p99_ns) return left.wait_p99_ns > right.wait_p99_ns;
944 if (left.max_wait_ns != right.max_wait_ns) return left.max_wait_ns > right.max_wait_ns;
945 return rowWaitGreaterThan({}, left, right);
946 }
947
948 fn rowHoldGreaterThan(_: void, left: Row, right: Row) bool {
949 if (left.total_hold_ns != right.total_hold_ns) return left.total_hold_ns > right.total_hold_ns;
950 if (left.max_hold_ns != right.max_hold_ns) return left.max_hold_ns > right.max_hold_ns;
951 return rowNameLessThan({}, left, right);
952 }
953
954 fn rowHoldTailGreaterThan(_: void, left: Row, right: Row) bool {
955 if (left.hold_p99_ns != right.hold_p99_ns) return left.hold_p99_ns > right.hold_p99_ns;
956 if (left.max_hold_ns != right.max_hold_ns) return left.max_hold_ns > right.max_hold_ns;
957 return rowHoldGreaterThan({}, left, right);
958 }
959
960 fn rowContentionGreaterThan(_: void, left: Row, right: Row) bool {
961 if (left.max_wait_ns != right.max_wait_ns) return left.max_wait_ns > right.max_wait_ns;
962 return rowWaitGreaterThan({}, left, right);
963 }
964
965 fn rowCountGreaterThan(_: void, left: Row, right: Row) bool {
966 if (left.eventCount() != right.eventCount()) return left.eventCount() > right.eventCount();
967 return rowWaitGreaterThan({}, left, right);
968 }
969
970 fn rowLastGreaterThan(_: void, left: Row, right: Row) bool {
971 if (left.last_event_ns != right.last_event_ns) return left.last_event_ns > right.last_event_ns;
972 return rowNameLessThan({}, left, right);
973 }
974
975 fn rowNameLessThan(_: void, left: Row, right: Row) bool {
976 if (!std.mem.eql(u8, left.name, right.name)) return std.mem.lessThan(u8, left.name, right.name);
977 return left.id < right.id;
978 }
979
980 fn entryDurationGreaterThan(_: void, left: Entry, right: Entry) bool {
981 if (left.duration_ns != right.duration_ns) return left.duration_ns > right.duration_ns;
982 if (left.end_ns != right.end_ns) return left.end_ns < right.end_ns;
983 return left.lock < right.lock;
984 }
985
986 pub fn writeSummaryDurationsText(writer: *std.Io.Writer, row: Summary) !void {
987 try writer.print(
988 " waits={d} wait_total_ns={d} wait_mean_ns={d} wait_min_ns={d} " ++
989 "wait_p50_ns={d} wait_p90_ns={d} wait_p99_ns={d} wait_max_ns={d} " ++
990 "holds={d} hold_total_ns={d} hold_mean_ns={d} hold_min_ns={d} " ++
991 "hold_p50_ns={d} hold_p90_ns={d} hold_p99_ns={d} hold_max_ns={d}",
992 .{
993 row.wait_count,
994 row.total_wait_ns,
995 row.wait_mean_ns,
996 row.wait_min_ns,
997 row.wait_p50_ns,
998 row.wait_p90_ns,
999 row.wait_p99_ns,
1000 row.max_wait_ns,
1001 row.hold_count,
1002 row.total_hold_ns,
1003 row.hold_mean_ns,
1004 row.hold_min_ns,
1005 row.hold_p50_ns,
1006 row.hold_p90_ns,
1007 row.hold_p99_ns,
1008 row.max_hold_ns,
1009 },
1010 );
1011 }
1012
1013 pub fn writeSummaryDurationFields(object: pretty_json.Object, row: Summary) !void {
1014 try object.field("waits", row.wait_count);
1015 try object.field("wait_total_ns", row.total_wait_ns);
1016 try object.field("wait_mean_ns", row.wait_mean_ns);
1017 try object.field("wait_min_ns", row.wait_min_ns);
1018 try object.field("wait_p50_ns", row.wait_p50_ns);
1019 try object.field("wait_p90_ns", row.wait_p90_ns);
1020 try object.field("wait_p99_ns", row.wait_p99_ns);
1021 try object.field("wait_max_ns", row.max_wait_ns);
1022 try object.field("holds", row.hold_count);
1023 try object.field("hold_total_ns", row.total_hold_ns);
1024 try object.field("hold_mean_ns", row.hold_mean_ns);
1025 try object.field("hold_min_ns", row.hold_min_ns);
1026 try object.field("hold_p50_ns", row.hold_p50_ns);
1027 try object.field("hold_p90_ns", row.hold_p90_ns);
1028 try object.field("hold_p99_ns", row.hold_p99_ns);
1029 try object.field("hold_max_ns", row.max_hold_ns);
1030 }
1031
1032 test "locks text aggregates wait and hold durations" {
1033 var trace = std.Io.Writer.Allocating.init(std.testing.allocator);
1034 defer trace.deinit();
1035 try (event.TraceEvent{ .seq = 1, .kind = .start, .time_ns = 90, .thread = 1, .name = "test" }).writeJsonLine(&trace.writer);
1036 try (event.TraceEvent{ .seq = 2, .kind = .lock_announce, .time_ns = 100, .thread = 1, .id = 7, .name = "queue-lock", .file = "locks.zig", .function = "init", .line = 3, .lock_kind = "lock" }).writeJsonLine(&trace.writer);
1037 try (event.TraceEvent{ .seq = 3, .kind = .lock_wait, .time_ns = 110, .thread = 1, .id = 7 }).writeJsonLine(&trace.writer);
1038 try (event.TraceEvent{ .seq = 4, .kind = .lock_obtain, .time_ns = 150, .thread = 1, .id = 7 }).writeJsonLine(&trace.writer);
1039 try (event.TraceEvent{ .seq = 5, .kind = .lock_mark, .time_ns = 155, .thread = 1, .id = 7, .file = "critical.zig", .function = "work", .line = 12 }).writeJsonLine(&trace.writer);
1040 try (event.TraceEvent{ .seq = 6, .kind = .lock_release, .time_ns = 210, .thread = 1, .id = 7 }).writeJsonLine(&trace.writer);
1041 try (event.TraceEvent{ .seq = 7, .kind = .lock_terminate, .time_ns = 220, .thread = 1, .id = 7 }).writeJsonLine(&trace.writer);
1042 try (event.TraceEvent{ .seq = 8, .kind = .stop, .time_ns = 230, .thread = 1 }).writeJsonLine(&trace.writer);
1043
1044 var analyzer = Analyzer.init(std.testing.allocator);
1045 defer analyzer.deinit();
1046 try analyzer.ingestJsonlBytes(trace.written());
1047
1048 var out = std.Io.Writer.Allocating.init(std.testing.allocator);
1049 defer out.deinit();
1050 try writeText(std.testing.allocator, &analyzer, &out.writer, .{ .top = 4, .occurrences = 4, .sort = .contention });
1051 const text = out.written();
1052 try expectLockContains(
1053 text,
1054 "events=8 waits=1 holds=1 wait_samples=1 hold_samples=1 " ++
1055 "pending_waits=0 pending_holds=0",
1056 );
1057 try expectLockContains(
1058 text,
1059 "wait_total_ns=40 wait_mean_ns=40 wait_min_ns=40 wait_p50_ns=40 " ++
1060 "wait_p90_ns=40 wait_p99_ns=40 wait_max_ns=40",
1061 );
1062 try expectLockContains(
1063 text,
1064 "hold_total_ns=60 hold_mean_ns=60 hold_min_ns=60 hold_p50_ns=60 " ++
1065 "hold_p90_ns=60 hold_p99_ns=60 hold_max_ns=60",
1066 );
1067 try expectLockContains(text, "mark=critical.zig:12");
1068 try expectLockContains(
1069 text,
1070 "occurrence kind=hold lock=7 mode=lock thread=1 start_ns=150 " ++
1071 "end_ns=210 duration_ns=60 name=\"queue-lock\"",
1072 );
1073 try expectLockContains(
1074 text,
1075 "occurrence kind=wait lock=7 mode=lock thread=1 start_ns=110 " ++
1076 "end_ns=150 duration_ns=40 name=\"queue-lock\"",
1077 );
1078 }
1079
1080 test "locks jsonl filters shared waits by thread and window" {
1081 var trace = std.Io.Writer.Allocating.init(std.testing.allocator);
1082 defer trace.deinit();
1083 try (event.TraceEvent{ .seq = 1, .kind = .lock_announce, .time_ns = 100, .thread = 1, .id = 2, .name = "cache", .lock_kind = "shared" }).writeJsonLine(&trace.writer);
1084 try (event.TraceEvent{ .seq = 2, .kind = .lock_shared_wait, .time_ns = 120, .thread = 3, .id = 2 }).writeJsonLine(&trace.writer);
1085 try (event.TraceEvent{ .seq = 3, .kind = .lock_shared_obtain, .time_ns = 170, .thread = 3, .id = 2 }).writeJsonLine(&trace.writer);
1086 try (event.TraceEvent{ .seq = 4, .kind = .lock_shared_release, .time_ns = 220, .thread = 3, .id = 2 }).writeJsonLine(&trace.writer);
1087 try (event.TraceEvent{ .seq = 5, .kind = .lock_shared_wait, .time_ns = 300, .thread = 4, .id = 2 }).writeJsonLine(&trace.writer);
1088 try (event.TraceEvent{ .seq = 6, .kind = .lock_shared_obtain, .time_ns = 310, .thread = 4, .id = 2 }).writeJsonLine(&trace.writer);
1089 try (event.TraceEvent{ .seq = 7, .kind = .lock_shared_release, .time_ns = 330, .thread = 4, .id = 2 }).writeJsonLine(&trace.writer);
1090
1091 var analyzer = Analyzer.init(std.testing.allocator);
1092 defer analyzer.deinit();
1093 try analyzer.ingestJsonlBytes(trace.written());
1094
1095 var out = std.Io.Writer.Allocating.init(std.testing.allocator);
1096 defer out.deinit();
1097 try writeJsonl(std.testing.allocator, &analyzer, &out.writer, .{
1098 .top = 4,
1099 .occurrences = 4,
1100 .kind = .wait,
1101 .mode = .shared,
1102 .thread = 3,
1103 .since_ns = 100,
1104 .until_ns = 200,
1105 .min_wait_ns = 40,
1106 .match = "CACHE",
1107 .ignore_case = true,
1108 });
1109 const text = out.written();
1110 try std.testing.expect(std.mem.indexOf(u8, text, "\"schema\":\"tracy.locks/v0\"") != null);
1111 try std.testing.expect(std.mem.indexOf(u8, text, "\"kind\":\"summary\",\"locks\":1,\"rows\":1") != null);
1112 try std.testing.expect(std.mem.indexOf(u8, text, "\"kind\":\"lock\",\"id\":2,\"name\":\"cache\",\"mode\":\"shared\",\"waits\":1,\"wait_total_ns\":50") != null);
1113 try std.testing.expect(std.mem.indexOf(u8, text, "\"kind\":\"wait\",\"lock\":2,\"thread\":3,\"start_ns\":120,\"end_ns\":170,\"duration_ns\":50,\"mode\":\"shared\",\"name\":\"cache\"") != null);
1114 try std.testing.expect(std.mem.indexOf(u8, text, "\"thread\":4") == null);
1115 }
1116
1117 test "locks preserve exact wait and hold distributions" {
1118 var trace = std.Io.Writer.Allocating.init(std.testing.allocator);
1119 defer trace.deinit();
1120 var seq: u64 = 1;
1121 try (event.TraceEvent{ .seq = seq, .kind = .start, .time_ns = 1 })
1122 .writeJsonLine(&trace.writer);
1123 seq += 1;
1124 var time_ns: u64 = 100;
1125 for ([_]u64{ 10, 20, 30, 40, 100 }, [_]u64{ 5, 15, 25, 35, 95 }) |
1126 wait_ns,
1127 hold_ns,
1128 | {
1129 try appendLockSample(&trace.writer, &seq, 1, 7, time_ns, wait_ns, hold_ns);
1130 time_ns += wait_ns + hold_ns + 10;
1131 }
1132 try appendLockSample(&trace.writer, &seq, 2, 8, time_ns, 200, 1);
1133 try (event.TraceEvent{ .seq = seq, .kind = .stop, .time_ns = time_ns + 210 })
1134 .writeJsonLine(&trace.writer);
1135
1136 var analyzer = Analyzer.init(std.testing.allocator);
1137 defer analyzer.deinit();
1138 try analyzer.ingestJsonlBytes(trace.written());
1139 try std.testing.expectEqualStrings("complete", analyzer.durationEvidence());
1140
1141 var wait_rows = try analyzer.collectRows(std.testing.allocator, .{ .sort = .wait_tail });
1142 defer wait_rows.deinit(std.testing.allocator);
1143 try std.testing.expectEqual(@as(u64, 2), wait_rows.items[0].id);
1144 const target = wait_rows.items[1];
1145 try std.testing.expectEqual(@as(u64, 5), target.wait_count);
1146 try std.testing.expectEqual(@as(u64, 40), target.wait_mean_ns);
1147 try std.testing.expectEqual(@as(u64, 10), target.wait_min_ns);
1148 try std.testing.expectEqual(@as(u64, 30), target.wait_p50_ns);
1149 try std.testing.expectEqual(@as(u64, 100), target.wait_p90_ns);
1150 try std.testing.expectEqual(@as(u64, 100), target.wait_p99_ns);
1151 try std.testing.expectEqual(@as(u64, 100), target.max_wait_ns);
1152 try std.testing.expectEqual(@as(u64, 35), target.hold_mean_ns);
1153 try std.testing.expectEqual(@as(u64, 25), target.hold_p50_ns);
1154 try std.testing.expectEqual(@as(u64, 95), target.hold_p99_ns);
1155
1156 var hold_rows = try analyzer.collectRows(std.testing.allocator, .{ .sort = .hold_tail });
1157 defer hold_rows.deinit(std.testing.allocator);
1158 try std.testing.expectEqual(@as(u64, 1), hold_rows.items[0].id);
1159 }
1160
1161 test "locks retain first state and mark invalid timing evidence" {
1162 var trace = std.Io.Writer.Allocating.init(std.testing.allocator);
1163 defer trace.deinit();
1164 var seq: u64 = 1;
1165 try appendLockEvent(&trace.writer, &seq, .start, 10, 0);
1166 try appendLockEvent(&trace.writer, &seq, .lock_wait, 100, 1);
1167 try appendLockEvent(&trace.writer, &seq, .lock_wait, 130, 1);
1168 try appendLockEvent(&trace.writer, &seq, .lock_obtain, 160, 1);
1169 try appendLockEvent(&trace.writer, &seq, .lock_obtain, 180, 1);
1170 try appendLockEvent(&trace.writer, &seq, .lock_release, 220, 1);
1171 try appendLockEvent(&trace.writer, &seq, .lock_wait, 300, 2);
1172 try appendLockEvent(&trace.writer, &seq, .lock_obtain, 250, 2);
1173 try appendLockEvent(&trace.writer, &seq, .lock_release, 240, 2);
1174 try appendLockEvent(&trace.writer, &seq, .stop, 400, 0);
1175
1176 var analyzer = Analyzer.init(std.testing.allocator);
1177 defer analyzer.deinit();
1178 try analyzer.ingestJsonlBytes(trace.written());
1179 try std.testing.expectEqual(@as(u64, 1), analyzer.counters.duplicate_waits);
1180 try std.testing.expectEqual(@as(u64, 1), analyzer.counters.duplicate_obtains);
1181 try std.testing.expectEqual(@as(u64, 2), analyzer.counters.timestamp_regressions);
1182 try std.testing.expectEqual(@as(u64, 1), analyzer.counters.wait_samples);
1183 try std.testing.expectEqual(@as(u64, 1), analyzer.counters.hold_samples);
1184 try std.testing.expectEqualStrings("partial", analyzer.durationEvidence());
1185
1186 var rows = try analyzer.collectRows(std.testing.allocator, .{ .sort = .wait_tail });
1187 defer rows.deinit(std.testing.allocator);
1188 try std.testing.expectEqual(@as(usize, 1), rows.items.len);
1189 try std.testing.expectEqual(@as(u64, 60), rows.items[0].wait_p99_ns);
1190 try std.testing.expectEqual(@as(u64, 60), rows.items[0].hold_p99_ns);
1191
1192 var out = std.Io.Writer.Allocating.init(std.testing.allocator);
1193 defer out.deinit();
1194 try writeJsonl(std.testing.allocator, &analyzer, &out.writer, .{});
1195 try expectLockContains(out.written(), "\"duplicate_waits\":1");
1196 try expectLockContains(out.written(), "\"duration_evidence\":\"partial\"");
1197 try expectLockContains(out.written(), "\"valid_time\":false");
1198 }
1199
1200 test "locks retain flight reports and sequence gaps" {
1201 var trace = std.Io.Writer.Allocating.init(std.testing.allocator);
1202 defer trace.deinit();
1203 try (event.TraceEvent{ .seq = 1, .kind = .start, .time_ns = 10 })
1204 .writeJsonLine(&trace.writer);
1205 try (event.TraceEvent{ .seq = 3, .kind = .lock_wait, .time_ns = 20, .id = 1 })
1206 .writeJsonLine(&trace.writer);
1207 try (event.TraceEvent{ .seq = 4, .kind = .lock_obtain, .time_ns = 30, .id = 1 })
1208 .writeJsonLine(&trace.writer);
1209 try (event.TraceEvent{ .seq = 5, .kind = .lock_release, .time_ns = 40, .id = 1 })
1210 .writeJsonLine(&trace.writer);
1211 try (event.TraceEvent{ .seq = 6, .kind = .stop, .time_ns = 50 })
1212 .writeJsonLine(&trace.writer);
1213 const flight_report = lockTestFlightReport();
1214 try flight_report.writeJsonl(&trace.writer);
1215
1216 var analyzer = Analyzer.init(std.testing.allocator);
1217 defer analyzer.deinit();
1218 try analyzer.ingestJsonlBytes(trace.written());
1219 const integrity = analyzer.captureIntegrity();
1220 try std.testing.expectEqualStrings("sequence_gaps", integrity.status);
1221 try std.testing.expectEqualDeep(flight_report, integrity.flight_report.?);
1222 try std.testing.expectEqualStrings("partial", analyzer.durationEvidence());
1223
1224 var out = std.Io.Writer.Allocating.init(std.testing.allocator);
1225 defer out.deinit();
1226 try writeJsonl(std.testing.allocator, &analyzer, &out.writer, .{});
1227 try expectLockContains(out.written(), "\"flight_report\":{");
1228 }
1229
1230 test "locks release duration evidence on allocation failure" {
1231 try std.testing.checkAllAllocationFailures(
1232 std.testing.allocator,
1233 analyzeLockDurations,
1234 .{},
1235 );
1236 }
1237
1238 fn analyzeLockDurations(allocator: std.mem.Allocator) !void {
1239 var trace = std.Io.Writer.Allocating.init(std.testing.allocator);
1240 defer trace.deinit();
1241 var seq: u64 = 1;
1242 try appendLockEvent(&trace.writer, &seq, .start, 10, 0);
1243 try (event.TraceEvent{
1244 .seq = seq,
1245 .kind = .lock_announce,
1246 .time_ns = 20,
1247 .id = 7,
1248 .name = "queue",
1249 .file = "queue.zig",
1250 .function = "push",
1251 }).writeJsonLine(&trace.writer);
1252 seq += 1;
1253 try appendLockSample(&trace.writer, &seq, 7, 3, 30, 10, 20);
1254 try appendLockSample(&trace.writer, &seq, 7, 3, 70, 30, 40);
1255 try appendLockEvent(&trace.writer, &seq, .stop, 150, 0);
1256 try lockTestFlightReport().writeJsonl(&trace.writer);
1257
1258 var analyzer = Analyzer.init(allocator);
1259 defer analyzer.deinit();
1260 try analyzer.ingestJsonlBytes(trace.written());
1261 var out = std.Io.Writer.Allocating.init(std.testing.allocator);
1262 defer out.deinit();
1263 try writeJsonl(allocator, &analyzer, &out.writer, .{ .sort = .hold_tail });
1264 }
1265
1266 fn appendLockSample(
1267 writer: *std.Io.Writer,
1268 seq: *u64,
1269 lock: u64,
1270 thread: u64,
1271 start_ns: u64,
1272 wait_ns: u64,
1273 hold_ns: u64,
1274 ) !void {
1275 try (event.TraceEvent{
1276 .seq = seq.*,
1277 .kind = .lock_wait,
1278 .time_ns = start_ns,
1279 .thread = thread,
1280 .id = lock,
1281 }).writeJsonLine(writer);
1282 seq.* += 1;
1283 try (event.TraceEvent{
1284 .seq = seq.*,
1285 .kind = .lock_obtain,
1286 .time_ns = start_ns + wait_ns,
1287 .thread = thread,
1288 .id = lock,
1289 }).writeJsonLine(writer);
1290 seq.* += 1;
1291 try (event.TraceEvent{
1292 .seq = seq.*,
1293 .kind = .lock_release,
1294 .time_ns = start_ns + wait_ns + hold_ns,
1295 .thread = thread,
1296 .id = lock,
1297 }).writeJsonLine(writer);
1298 seq.* += 1;
1299 }
1300
1301 fn appendLockEvent(
1302 writer: *std.Io.Writer,
1303 seq: *u64,
1304 kind: event.Kind,
1305 time_ns: u64,
1306 lock: u64,
1307 ) !void {
1308 try (event.TraceEvent{
1309 .seq = seq.*,
1310 .kind = kind,
1311 .time_ns = time_ns,
1312 .thread = 7,
1313 .id = lock,
1314 }).writeJsonLine(writer);
1315 seq.* += 1;
1316 }
1317
1318 fn lockTestFlightReport() transport.Report {
1319 return .{
1320 .policy = .overwrite_oldest,
1321 .state = .accepting,
1322 .capacity_bytes = 64,
1323 .retained_bytes = 32,
1324 .event_capacity_bytes = 16,
1325 .writer_capacity_bytes = 8,
1326 .observed_events = 5,
1327 .stored_events = 5,
1328 .retained_events = 4,
1329 .overwritten_events = 1,
1330 .dropped_events = 0,
1331 .oversized_events = 0,
1332 .partial_event_bytes = 0,
1333 .discarding_oversized_event = false,
1334 };
1335 }
1336
1337 fn expectLockContains(haystack: []const u8, needle: []const u8) !void {
1338 try std.testing.expect(std.mem.indexOf(u8, haystack, needle) != null);
1339 }