235 lines
10 KiB
Zig
235 lines
10 KiB
Zig
//! The tagged kernel log ring — a circular byte buffer of framed records, each
|
|
//! stamped by the writer (the kernel) with the sender's pid, task name, level,
|
|
//! per-boot sequence number, and monotonic timestamp. Pure code over an
|
|
//! embedded buffer — no architecture or lock imports — so it host-tests
|
|
//! alongside the other pure kernel pieces (`zig build test`).
|
|
//!
|
|
//! `head` and `tail` are free-running u64 positions in a logical byte stream;
|
|
//! the physical wrap is invisible to readers (all copies are modulo the
|
|
//! buffer), so a record never splits logically and no padding records exist.
|
|
//! Reclaim happens record by record: the writer parses the header at `tail`
|
|
//! (which it wrote itself) and advances until the new record fits — `tail`
|
|
//! always sits on a record boundary, and sequence-number gaps tell a reader
|
|
//! exactly how many records it lost.
|
|
//!
|
|
//! Locking is the caller's job (log.zig holds its log lock around every call);
|
|
//! the ring itself is single-writer, snapshot-reader.
|
|
|
|
const std = @import("std");
|
|
const abi = @import("abi");
|
|
|
|
pub fn Ring(comptime capacity: usize) type {
|
|
comptime std.debug.assert(std.math.isPowerOfTwo(capacity));
|
|
return struct {
|
|
const Self = @This();
|
|
|
|
buffer: [capacity]u8 = undefined,
|
|
head: u64 = 0,
|
|
tail: u64 = 0,
|
|
next_sequence: u64 = 0,
|
|
|
|
/// Append one record; returns its sequence number. `name` and `message`
|
|
/// are clamped to their ABI caps (the syscall clamps earlier too — the
|
|
/// clamp here makes the ring safe in isolation).
|
|
pub fn append(
|
|
self: *Self,
|
|
pid: u32,
|
|
name: []const u8,
|
|
level: abi.KlogLevel,
|
|
timestamp_ns: u64,
|
|
message: []const u8,
|
|
truncated: bool,
|
|
) u64 {
|
|
const name_len: usize = @min(name.len, abi.maximum_process_name);
|
|
const message_len: usize = @min(message.len, abi.klog_maximum_message);
|
|
const record_len = recordLength(name_len, message_len);
|
|
|
|
// Reclaim whole records until the new one fits.
|
|
while (self.head + record_len - self.tail > capacity) self.reclaimOne();
|
|
|
|
const sequence = self.next_sequence;
|
|
self.next_sequence += 1;
|
|
|
|
const header = abi.KlogRecordHeader{
|
|
.magic = abi.klog_record_magic,
|
|
.level = level,
|
|
.name_len = @intCast(name_len),
|
|
.pid = pid,
|
|
.sequence = sequence,
|
|
.timestamp_ns = timestamp_ns,
|
|
.message_len = @intCast(message_len),
|
|
.flags = if (truncated) abi.klog_flag_truncated else 0,
|
|
._reserved = @splat(0),
|
|
};
|
|
self.put(self.head, std.mem.asBytes(&header));
|
|
self.put(self.head + abi.klog_record_header_size, name[0..name_len]);
|
|
self.put(self.head + abi.klog_record_header_size + name_len, message[0..message_len]);
|
|
// The alignment pad is dead space; zero it so raw dumps stay tidy.
|
|
var pad = abi.klog_record_header_size + name_len + message_len;
|
|
while (pad < record_len) : (pad += 1)
|
|
self.buffer[@intCast((self.head + pad) % capacity)] = 0;
|
|
self.head += record_len;
|
|
return sequence;
|
|
}
|
|
|
|
/// Copy stream bytes beginning at `offset` into `out`. Returns null if
|
|
/// `offset` fell behind `tail` (overwritten) or lies past `head` — the
|
|
/// reader re-syncs from status(). 0 bytes means caught up.
|
|
pub fn read(self: *const Self, offset: u64, out: []u8) ?usize {
|
|
if (offset < self.tail or offset > self.head) return null;
|
|
const n: usize = @intCast(@min(out.len, self.head - offset));
|
|
self.get(offset, out[0..n]);
|
|
return n;
|
|
}
|
|
|
|
/// Cursors for klog_status. boot_unix_seconds is the kernel wrapper's
|
|
/// to fill — the ring knows nothing of wall clocks.
|
|
pub fn status(self: *const Self) abi.KlogStatus {
|
|
return .{
|
|
.tail = self.tail,
|
|
.head = self.head,
|
|
.next_sequence = self.next_sequence,
|
|
.boot_unix_seconds = 0,
|
|
};
|
|
}
|
|
|
|
fn reclaimOne(self: *Self) void {
|
|
var header_bytes: [abi.klog_record_header_size]u8 = undefined;
|
|
self.get(self.tail, &header_bytes);
|
|
const header = std.mem.bytesToValue(abi.KlogRecordHeader, &header_bytes);
|
|
// The writer wrote this header itself: the assert guards against
|
|
// memory corruption, not bad input.
|
|
std.debug.assert(header.magic == abi.klog_record_magic);
|
|
self.tail += recordLength(header.name_len, header.message_len);
|
|
}
|
|
|
|
fn recordLength(name_len: usize, message_len: usize) usize {
|
|
return std.mem.alignForward(usize, abi.klog_record_header_size + name_len + message_len, abi.klog_record_alignment);
|
|
}
|
|
|
|
// Byte-at-a-time modulo copies keep the wrap logic obviously correct;
|
|
// if they ever show in a profile, split into two @memcpy spans.
|
|
fn put(self: *Self, offset: u64, bytes: []const u8) void {
|
|
for (bytes, 0..) |b, i| self.buffer[@intCast((offset + i) % capacity)] = b;
|
|
}
|
|
|
|
fn get(self: *const Self, offset: u64, out: []u8) void {
|
|
for (out, 0..) |*b, i| b.* = self.buffer[@intCast((offset + i) % capacity)];
|
|
}
|
|
};
|
|
}
|
|
|
|
// --- tests (host) -----------------------------------------------------------
|
|
|
|
const TestRing = Ring(4096);
|
|
|
|
/// Parse the record at `offset` out of `ring`, returning the header plus name
|
|
/// and message copies — the same walk a userspace drainer performs.
|
|
const Parsed = struct {
|
|
header: abi.KlogRecordHeader,
|
|
name: [abi.maximum_process_name]u8 = undefined,
|
|
message: [abi.klog_maximum_message]u8 = undefined,
|
|
|
|
fn nameSlice(self: *const Parsed) []const u8 {
|
|
return self.name[0..self.header.name_len];
|
|
}
|
|
fn messageSlice(self: *const Parsed) []const u8 {
|
|
return self.message[0..self.header.message_len];
|
|
}
|
|
fn next(self: *const Parsed, offset: u64) u64 {
|
|
return offset + std.mem.alignForward(usize, abi.klog_record_header_size + self.header.name_len + self.header.message_len, abi.klog_record_alignment);
|
|
}
|
|
};
|
|
|
|
fn parseAt(ring: *const TestRing, offset: u64) Parsed {
|
|
var p: Parsed = undefined;
|
|
var header_bytes: [abi.klog_record_header_size]u8 = undefined;
|
|
std.debug.assert(ring.read(offset, &header_bytes).? == header_bytes.len);
|
|
p.header = std.mem.bytesToValue(abi.KlogRecordHeader, &header_bytes);
|
|
std.debug.assert(p.header.magic == abi.klog_record_magic);
|
|
_ = ring.read(offset + abi.klog_record_header_size, p.name[0..p.header.name_len]);
|
|
_ = ring.read(offset + abi.klog_record_header_size + p.header.name_len, p.message[0..p.header.message_len]);
|
|
return p;
|
|
}
|
|
|
|
test "header size is pinned" {
|
|
try std.testing.expectEqual(abi.klog_record_header_size, @sizeOf(abi.KlogRecordHeader));
|
|
}
|
|
|
|
test "append/read round trip" {
|
|
var ring = std.testing.allocator.create(TestRing) catch unreachable;
|
|
defer std.testing.allocator.destroy(ring);
|
|
ring.* = .{};
|
|
|
|
_ = ring.append(7, "/system/services/fat", .info, 123, "mounted /volumes/usb", false);
|
|
_ = ring.append(0, "kernel", .raw, 456, "wall clock online", false);
|
|
|
|
const first = parseAt(ring, ring.tail);
|
|
try std.testing.expectEqual(@as(u32, 7), first.header.pid);
|
|
try std.testing.expectEqual(abi.KlogLevel.info, first.header.level);
|
|
try std.testing.expectEqual(@as(u64, 123), first.header.timestamp_ns);
|
|
try std.testing.expectEqualStrings("/system/services/fat", first.nameSlice());
|
|
try std.testing.expectEqualStrings("mounted /volumes/usb", first.messageSlice());
|
|
|
|
const second = parseAt(ring, first.next(ring.tail));
|
|
try std.testing.expectEqual(@as(u32, 0), second.header.pid);
|
|
try std.testing.expectEqualStrings("kernel", second.nameSlice());
|
|
try std.testing.expectEqual(@as(u64, 1), second.header.sequence);
|
|
}
|
|
|
|
test "wrap reclaims whole records and keeps tail on a boundary" {
|
|
var ring = std.testing.allocator.create(TestRing) catch unreachable;
|
|
defer std.testing.allocator.destroy(ring);
|
|
ring.* = .{};
|
|
|
|
// Fill far past capacity so the ring wraps many times.
|
|
var i: u32 = 0;
|
|
while (i < 200) : (i += 1) {
|
|
var message: [64]u8 = undefined;
|
|
const m = std.fmt.bufPrint(&message, "line {d} padding padding padding", .{i}) catch unreachable;
|
|
_ = ring.append(1, "/test/system/services/writer", .info, i, m, false);
|
|
}
|
|
try std.testing.expect(ring.head - ring.tail <= 4096);
|
|
|
|
// The record at tail parses cleanly (boundary held), and walking to head
|
|
// yields consecutive sequence numbers.
|
|
var offset = ring.tail;
|
|
var previous: ?u64 = null;
|
|
while (offset < ring.head) {
|
|
const p = parseAt(ring, offset);
|
|
if (previous) |q| try std.testing.expectEqual(q + 1, p.header.sequence);
|
|
previous = p.header.sequence;
|
|
offset = p.next(offset);
|
|
}
|
|
try std.testing.expectEqual(ring.head, offset);
|
|
// Records were lost (sequence at tail > 0), and the count is the gap.
|
|
try std.testing.expect(parseAt(ring, ring.tail).header.sequence > 0);
|
|
}
|
|
|
|
test "stale offset returns null; head offset reads zero bytes" {
|
|
var ring = std.testing.allocator.create(TestRing) catch unreachable;
|
|
defer std.testing.allocator.destroy(ring);
|
|
ring.* = .{};
|
|
|
|
var i: u32 = 0;
|
|
while (i < 300) : (i += 1)
|
|
_ = ring.append(1, "w", .info, i, "0123456789abcdef0123456789abcdef", false);
|
|
|
|
var out: [16]u8 = undefined;
|
|
try std.testing.expect(ring.read(0, &out) == null); // long overwritten
|
|
try std.testing.expect(ring.read(ring.head + 1, &out) == null); // past the end
|
|
try std.testing.expectEqual(@as(usize, 0), ring.read(ring.head, &out).?); // caught up
|
|
}
|
|
|
|
test "truncation flag and clamping" {
|
|
var ring = std.testing.allocator.create(TestRing) catch unreachable;
|
|
defer std.testing.allocator.destroy(ring);
|
|
ring.* = .{};
|
|
|
|
const long = "x" ** 300; // past klog_maximum_message
|
|
_ = ring.append(2, "w", .warn, 0, long, true);
|
|
const p = parseAt(ring, ring.tail);
|
|
try std.testing.expectEqual(@as(u16, abi.klog_maximum_message), p.header.message_len);
|
|
try std.testing.expect(p.header.flags & abi.klog_flag_truncated != 0);
|
|
}
|