diff --git a/src/node.zig b/src/node.zig index c567d67..8d8d022 100644 --- a/src/node.zig +++ b/src/node.zig @@ -65,6 +65,7 @@ const Descriptor = struct { gpa: Allocator, trace: *Trace, prng: *std.Random.DefaultPrng, +id: u32, local_time: u64, arena: std.heap.ArenaAllocator, argv: [][*:0]const u8, @@ -114,10 +115,11 @@ fn splitCommandArguments(command: []const u8, arena: Allocator) Allocator.Error! return result; } -pub fn init(self: *Node, real_io: std.Io, trace: *Trace, prng: *std.Random.DefaultPrng, scheduler: *Scheduler, network: *Network, command: []const u8, addresses: []const u32, gpa: Allocator) !void { +pub fn init(self: *Node, real_io: std.Io, trace: *Trace, prng: *std.Random.DefaultPrng, scheduler: *Scheduler, network: *Network, node_id: u32, command: []const u8, addresses: []const u32, gpa: Allocator) !void { self.gpa = gpa; self.trace = trace; self.prng = prng; + self.id = node_id; self.local_time = 0; self.arena = .init(gpa); self.scheduler = scheduler; diff --git a/src/simulator.zig b/src/simulator.zig index 199cab9..d5c620f 100644 --- a/src/simulator.zig +++ b/src/simulator.zig @@ -33,16 +33,18 @@ network: Network, nodes: std.ArrayList(*Node), executables: std.ArrayList(ExecutableName), real_io: std.Io, +next_node_id: u32, pub fn init(self: *Simulator, gpa: Allocator, real_io: std.Io, seed: u64) void { self.gpa = gpa; - self.trace.init(real_io); + self.trace.init(&self.scheduler, real_io); self.prng = std.Random.DefaultPrng.init(seed); self.scheduler.init(gpa, &self.trace, &self.prng); self.network.init(gpa); self.nodes = .empty; self.executables = .empty; self.real_io = real_io; + self.next_node_id = 0; } pub fn deinit(self: *Simulator) void { @@ -72,10 +74,13 @@ pub fn spawn(self: *Simulator, command: []const u8, options: SpawnOptions) Spawn const name = extractProgramNameFromCommand(command) orelse return SpawnError.InvalidCommand; const entry = self.getExecutableEntryPoint(name) orelse return SpawnError.NoSuchProgram; + const node_id = self.next_node_id; + self.next_node_id += 1; + const node = try self.gpa.create(Node); errdefer self.gpa.destroy(node); - try node.init(self.real_io, &self.trace, &self.prng, &self.scheduler, &self.network, command, options.addresses, self.gpa); + try node.init(self.real_io, &self.trace, &self.prng, &self.scheduler, &self.network, node_id, command, options.addresses, self.gpa); try self.nodes.append(self.gpa, node); errdefer _ = self.nodes.swapRemove(self.nodes.items.len-1); diff --git a/src/trace.zig b/src/trace.zig index a3fe1e1..b9cd3c7 100644 --- a/src/trace.zig +++ b/src/trace.zig @@ -1,9 +1,8 @@ const std = @import("std"); const Io = std.Io; const Node = @import("node.zig"); -const TaskID = @import("scheduler.zig").TaskID; - -const PendingTrace = struct {}; +const Scheduler = @import("scheduler.zig"); +const TaskID = Scheduler.TaskID; pub const Trace = struct { @@ -15,14 +14,43 @@ pub const Trace = struct { waiting_task, failed, returned, + + pub fn toString(self: TaskState) []const u8 { + return switch (self) { + .ready => "ready", + .running => "running", + .sleeping => "sleeping", + .waiting_futex => "waiting-futex", + .waiting_task => "waiting-task", + .failed => "failed", + .returned => "returned", + }; + } + }; + + const Pending = struct { + trace_id: u64, + local_time: u64, + global_time: u64, + node_id: u32, + task_id: TaskID, + disk: bool, + op: []const u8, }; io: Io, file: ?Io.File, + scheduler: *Scheduler, + task: ?TaskID, + node: ?*Node, + next_trace_id: u64, - pub fn init(self: *Trace, io: Io) void { + pub fn init(self: *Trace, scheduler: *Scheduler, io: Io) void { self.io = io; self.file = null; + self.scheduler = scheduler; + self.task = null; + self.node = null; } pub fn deinit(self: *Trace) void { @@ -38,65 +66,199 @@ pub const Trace = struct { pub fn enterTask(self: *Trace, task_id: TaskID, node: *Node) void { if (self.file == null) return; - _ = task_id; - _ = node; + self.task = task_id; + self.node = node; } pub fn leaveTask(self: *Trace) void { if (self.file == null) return; + self.task = null; + self.node = null; } pub fn taskSpawned(self: *Trace, task_id: TaskID, node: *Node, parent_id: ?TaskID) void { if (self.file == null) return; - _ = task_id; - _ = node; - _ = parent_id; + const global_time = self.scheduler.current_time; + const local_time = node.local_time; + + var line_buffer: [256]u8 = undefined; + const prefix = std.fmt.bufPrint(&line_buffer, + \\{{"time":{},"global_time":{},"event":"task_spawned","node":{},"task":{} + , .{ local_time, global_time, node.id, task_id }) catch return; + self.write(prefix); + if (parent_id) |it| { + const parent = std.fmt.bufPrint(&line_buffer, ",\"parent\":{}", .{it}) catch return; + self.write(parent); + } + self.write("}\n"); } pub fn taskRemoved(self: *Trace, task_id: TaskID, node: *Node) void { if (self.file == null) return; - _ = task_id; - _ = node; + const global_time = self.scheduler.current_time; + const local_time = node.local_time; + + var line_buffer: [256]u8 = undefined; + const line = std.fmt.bufPrint(&line_buffer, + \\{{"time":{},"global_time":{},"event":"task_removed","node":{},"task":{}}} + \\ + , .{ local_time, global_time, node.id, task_id }) catch return; + self.write(line); } pub fn taskState(self: *Trace, task_id: TaskID, node: *Node, state: Trace.TaskState, reason: []const u8) void { if (self.file == null) return; - _ = task_id; - _ = node; - _ = state; - _ = reason; + const global_time = self.scheduler.current_time; + const local_time = node.local_time; + + var line_buffer: [256]u8 = undefined; + const prefix = std.fmt.bufPrint(&line_buffer, + \\{{"time":{},"global_time":{},"event":"state","node":{},"task":{},"state": + , .{ local_time, global_time, node.id, task_id }) catch return; + self.write(prefix); + self.writeJsonString(state.toString()); + self.write(",\"reason\":"); + self.writeJsonString(reason); + self.write("}\n"); } pub fn timeAdvanced(self: *Trace, from: u64, to: u64) void { if (self.file == null) return; - _ = from; - _ = to; + var line_buffer: [256]u8 = undefined; + const line = std.fmt.bufPrint(&line_buffer, + \\{{"time":{},"global_time":{},"event":"time_advanced","from":{},"to":{}}} + \\ + , .{ to, to, from, to }) catch return; + self.write(line); + } - pub fn beginIO(self: *Trace, disk: bool, source: std.builtin.SourceLocation) PendingTrace { - if (self.file == null) return .{}; + pub fn beginIO(self: *Trace, disk: bool, source: std.builtin.SourceLocation) Pending { + if (self.file == null) + return .{ + .trace_id = 0, + .local_time = 0, + .global_time = 0, + .task_id = 0, + .node_id = 0, + .disk = false, + .op = &.{}, + }; - _ = disk; - _ = source; - return .{}; + std.debug.assert(self.task != null); + std.debug.assert(self.node != null); + const node = self.node.?; + const task = self.task.?; + + const global_time = self.scheduler.current_time; + const local_time = node.local_time; + + const trace_id = self.next_trace_id; + self.next_trace_id += 1; + + var line_buffer: [256]u8 = undefined; + const prefix = std.fmt.bufPrint(&line_buffer, + \\{{"time":{},"global_time":{},"event":"io_start","id":{},"node":{},"task":{},"op": + , .{ local_time, global_time, trace_id, node.id, task }) catch @panic("TODO"); + self.write(prefix); + self.writeJsonString(source.fn_name); + self.write(",\"resource\":"); + self.writeJsonString(if (disk) "disk" else "io"); + self.write("}\n"); + + return .{ + .trace_id = trace_id, + .local_time = local_time, + .global_time = global_time, + .node_id = node.id, + .task_id = task, + .disk = disk, + .op = source.fn_name, + }; } - pub fn failIO(self: *Trace, pending_trace: PendingTrace, e: anyerror) void { + pub fn failIO(self: *Trace, pending_trace: Pending, e: anyerror) void { if (self.file == null) return; - _ = pending_trace; - _ = e catch {}; + var result_buffer: [96]u8 = undefined; + const result = std.fmt.bufPrint(&result_buffer, "error.{s}", .{@errorName(e)}) catch "error"; + self.completeIO(pending_trace, result); } - pub fn completeIO(self: *Trace, pending_trace: PendingTrace, result: anytype) void { + pub fn completeIO(self: *Trace, pending_trace: Pending, result: anytype) void { if (self.file == null) return; - _ = pending_trace; - _ = result; + const global_time = self.scheduler.current_time; + const node = self.node orelse return; + const local_time = node.local_time; + + var line_buffer: [256]u8 = undefined; + const prefix = std.fmt.bufPrint(&line_buffer, + \\{{"time":{},"global_time":{},"event":"io_complete","id":{},"node":{},"task":{},"op": + , .{ local_time, global_time, pending_trace.trace_id, pending_trace.node_id, pending_trace.task_id }) catch return; + self.write(prefix); + self.writeJsonString(pending_trace.op); + self.write(",\"resource\":"); + self.writeJsonString(if (pending_trace.disk) "disk" else "io"); + const suffix = std.fmt.bufPrint(&line_buffer, + \\,"start":{},"end":{},"result": + , .{ pending_trace.local_time, local_time }) catch return; + self.write(suffix); + var result_buffer: [96]u8 = undefined; + self.writeJsonString(resultText(&result_buffer, result)); + self.write("}\n"); + + if (pending_trace.disk) { + var disk_line_buffer: [256]u8 = undefined; + const disk_prefix = std.fmt.bufPrint(&disk_line_buffer, + \\{{"time":{},"global_time":{},"event":"disk","node":{},"op": + , .{ pending_trace.local_time, global_time, pending_trace.node_id }) catch return; + self.write(disk_prefix); + self.writeJsonString(pending_trace.op); + const middle = std.fmt.bufPrint(&disk_line_buffer, + \\,"start":{},"end":{},"detail": + , .{ pending_trace.local_time, local_time }) catch return; + self.write(middle); + self.writeJsonString(resultText(&result_buffer, result)); + self.write("}\n"); + } + } + + fn writeJsonString(self: *Trace, text: []const u8) void { + self.write("\""); + for (text) |byte| { + switch (byte) { + '"' => self.write("\\\""), + '\\' => self.write("\\\\"), + '\n' => self.write("\\n"), + '\r' => self.write("\\r"), + '\t' => self.write("\\t"), + else => self.write((&byte)[0..1]), + } + } + self.write("\""); + } + + fn write(self: *Trace, bytes: []const u8) void { + const file = self.file orelse return; + file.writeStreamingAll(self.io, bytes) catch {}; } }; + +fn resultText(buffer: []u8, result: anytype) []const u8 { + const T = @TypeOf(result); + return switch (@typeInfo(T)) { + .void => "ok", + .@"struct" => "ok", + .pointer => |pointer| if (pointer.size == .slice and pointer.child == u8) + result + else + std.fmt.bufPrint(buffer, "{any}", .{result}) catch "result", + else => std.fmt.bufPrint(buffer, "{}", .{result}) catch "result", + }; +}