kernel: serialize test markers through the log lock; render one write per line

tests.zig wrote markers straight to serial, racing user-process records
rendered on other cores — visible as 16-byte UART-FIFO interleave once
the tagged renderer emitted several writes per record. Markers now go
through kernel log print (same serial sink, now under the log lock), the
renderer composes each line into one buffer and hits each sink once, and
the vfs-client-death needle drops the old self-written 'vfs: ' prefix.
This commit is contained in:
Daniel Samson
2026-07-21 15:53:45 +01:00
parent f480c5d790
commit d0c1b3e45b
2 changed files with 36 additions and 15 deletions
+29 -10
View File
@@ -139,26 +139,45 @@ fn appendLocked(pid: u32, name: []const u8, level: abi.KlogLevel, now: u64, byte
fn render(pid: u32, name: []const u8, level: abi.KlogLevel, line: []const u8, line_complete: bool) void {
if (sink_count == 0) return;
if (line.len == 0 and !line_complete) return;
// Compose the whole rendered piece first and emit it in ONE sink call per
// sink: fewer, larger UART writes, and no partial-line window should any
// path ever reach a sink without the log lock.
var buffer: [render_buffer_size]u8 = undefined;
var used: usize = 0;
if (!at_line_start and open_line_pid != pid) {
fanOut("\n");
buffer[used] = '\n';
used += 1;
at_line_start = true;
}
if (at_line_start and level != .raw) {
fanOut(name);
fanOut(": ");
switch (level) {
.err => fanOut("error: "),
.warn => fanOut("warning: "),
.debug => fanOut("debug: "),
.info, .raw => {},
used += place(buffer[used..], name);
used += place(buffer[used..], ": ");
used += place(buffer[used..], switch (level) {
.err => "error: ",
.warn => "warning: ",
.debug => "debug: ",
.info, .raw => "",
});
}
used += place(buffer[used..], line);
if (line_complete and used < buffer.len) {
buffer[used] = '\n';
used += 1;
}
fanOut(line);
if (line_complete) fanOut("\n");
fanOut(buffer[0..used]);
at_line_start = line_complete;
open_line_pid = pid;
}
/// newline + name + ": warning: " + a full payload line + newline.
const render_buffer_size = 1 + abi.maximum_process_name + 11 + abi.klog_maximum_message + 1;
fn place(destination: []u8, bytes: []const u8) usize {
const n = @min(destination.len, bytes.len);
@memcpy(destination[0..n], bytes[0..n]);
return n;
}
fn fanOut(bytes: []const u8) void {
for (sinks[0..sink_count]) |sink| sink(bytes);
}
+6 -4
View File
@@ -26,11 +26,13 @@ const irq = @import("irq.zig");
const sync = @import("sync.zig");
const process = @import("process.zig");
const initial_ramdisk = @import("initial-ramdisk");
const kernel_log = @import("log.zig");
/// Formatted write straight to serial, independent of the framebuffer console.
/// Formatted test-marker write. Goes through the kernel log (not straight to
/// serial): the log lock is what keeps marker lines from interleaving with
/// concurrent user-process records on other cores.
fn log(comptime fmt: []const u8, args: anytype) void {
var buffer: [128]u8 = undefined;
architecture.serialWrite(std.fmt.bufPrint(&buffer, fmt, args) catch return);
kernel_log.print(fmt, args);
}
var passed: u32 = 0;
@@ -2171,7 +2173,7 @@ fn vfsClientDeathTest(boot_information: *const BootInformation) void {
check("the exit notification arrived", badge == abi.notify_badge_bit | abi.notify_exit_bit | client);
// The VFS heard the same published event; its release line is the proof.
const released = "vfs: released 1 handle(s) for dead client";
const released = "released 1 handle(s) for dead client";
scheduler.setPriority(1);
deadline = architecture.millis() + 10000;
while (architecture.millis() < deadline) {