From 69be6470b3ff12648e474e47a492c3111ae7d4f5 Mon Sep 17 00:00:00 2001 From: Overlord Date: Sat, 8 Aug 2026 18:02:46 +0200 Subject: [PATCH] improved copy-safety, refined shared state handling, extended tests, updated comments --- src/logging/log.zig | 225 ++++++++++++++++++++++++++++++++++++-------- 1 file changed, 186 insertions(+), 39 deletions(-) diff --git a/src/logging/log.zig b/src/logging/log.zig index 9f58c3b..c43a7a1 100644 --- a/src/logging/log.zig +++ b/src/logging/log.zig @@ -4,7 +4,7 @@ const std = @import("std"); /// /// A `Logger`'s configured `level` acts as a filter: messages logged /// at a lower severity than the logger's level are silently dropped. -pub const Level = enum { +pub const Level = enum(u8) { debug, info, warn, @@ -26,10 +26,13 @@ pub const Level = enum { fn comptimeTag(comptime name: []const u8) []const u8 { - const inner_width = 5; - const total_width = inner_width + 2; // account for "[" and "]" + const width = blk: { + var max = 0; + for (@typeInfo(Level).@"enum".fields) |f| max = @max(max, f.name.len); + break :blk max; + } + 2; // account for "[" and "]" - comptime var buf: [total_width]u8 = .{' '} ** total_width; + comptime var buf: [width]u8 = .{' '} ** width; buf[0] = '['; inline for (name, 0..) |c, i| buf[i + 1] = std.ascii.toUpper(c); @@ -53,9 +56,9 @@ pub const Level = enum { pub const InitOptions = struct { pub const ErrorCallback = Logger.ErrorCallback; - level: Level = .info, - buffer: usize = 1024, - on_error: ErrorCallback = null, + level: Level = .info, + buffer: usize = 1024, + on_error: ?ErrorCallback = null, file: std.Io.File, io: std.Io, }; @@ -90,10 +93,15 @@ pub const InitOptions = struct { /// Unless an `ErrorCallback` is specified, errors from the public /// logging methods are swallowed. pub const Logger = struct { - pub const ErrorCallback = ?*const fn (err: anyerror) void; + pub const ErrorCallback = struct { + ctx: ?*anyopaque, + func: *const fn (ctx: ?*anyopaque, err: anyerror) void, - level: Level = .info, - on_error: ErrorCallback = null, + pub fn call(cb: ErrorCallback, e: anyerror) void { cb.func(cb.ctx, e); } + }; + + level: std.atomic.Value(Level) = .init(.info), + on_error: ?ErrorCallback = null, state: *WriterState, @@ -143,7 +151,7 @@ pub const Logger = struct { }; return Self{ - .level = options.level, + .level = .init(options.level), .on_error = options.on_error, .state = state, }; @@ -161,7 +169,7 @@ pub const Logger = struct { /// /// Each logger returned by `init` or `clone` must be deinitialized /// exactly once. - pub fn deinit(logger: *Self) void + pub fn deinit(logger: Self) void { const state = logger.state; @@ -170,10 +178,14 @@ pub const Logger = struct { if (state.mutex.lock(state.io)) |_| { - state.writer.interface.flush() catch |e| if (logger.on_error) |h| h(e); - state.mutex.unlock(state.io); + if (state.writer.interface.flush()) |_| { state.mutex.unlock(state.io); } + else |e| + { + state.mutex.unlock(state.io); + if (logger.on_error) |h| h.call(e); + } } - else |e| { if (logger.on_error) |h| h(e); } + else |e| if (logger.on_error) |h| h.call(e); state.allocator.free(state.buffer); state.allocator.destroy(state); @@ -185,7 +197,20 @@ pub const Logger = struct { pub fn clone(logger: *const Self) Self { _ = logger.state.refs.fetchAdd(1, .monotonic); - return logger.*; + return .{ + .level = .init(logger.level.load(.monotonic)), + .on_error = logger.on_error, + .state = logger.state, + }; + } + + /// Returns a new owning handle like `clone`, but with a different + /// severity filter. + pub fn cloneWith(logger: *const Self, level: Level) Self + { + var c = logger.clone(); + c.level.store(level, .monotonic); + return c; } // @@ -203,9 +228,9 @@ pub const Logger = struct { /// /// Returns an error if formatting or writing to the underlying /// writer fails. - fn log(logger: *Self, comptime fmt: []const u8, args: anytype, level: Level) !void + fn log(logger: *const Self, comptime fmt: []const u8, args: anytype, level: Level) !void { - if (@intFromEnum(level) < @intFromEnum(logger.level)) return; + if (@intFromEnum(level) < @intFromEnum(logger.level.load(.monotonic))) return; if (level == .fatal) return logger.fatalLog(fmt, args); @@ -231,36 +256,39 @@ pub const Logger = struct { /// a failure to persist the fatal message must never prevent the /// panic itself. Marked cold since this is checked on every `log` /// call but taken essentially never. - fn fatalLog(logger: *Self, comptime fmt: []const u8, args: anytype) noreturn + fn fatalLog(logger: *const Self, comptime fmt: []const u8, args: anytype) noreturn { @branchHint(.cold); - logger.state.mutex.lock(logger.state.io) catch {}; + const f = "{s} " ++ fmt; + const a = .{Level.prefix(.fatal)} ++ args; - logger.state.writer.interface.print( - "{s} " ++ fmt, - .{Level.prefix(.fatal)} ++ args - ) catch {}; + if (logger.state.mutex.tryLock()) + { + logger.state.writer.interface.print(f, a) catch {}; + logger.state.writer.interface.writeByte('\n') catch {}; + logger.state.writer.interface.flush() catch {}; + } - logger.state.writer.interface.writeByte('\n') catch {}; - logger.state.writer.interface.flush() catch {}; - - std.debug.panic(fmt, args); + std.debug.panic(f, a); } // - pub fn debug(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .debug) catch |e| if (logger.on_error) |h| h(e); } - pub fn info(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .info) catch |e| if (logger.on_error) |h| h(e); } - pub fn warn(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .warn) catch |e| if (logger.on_error) |h| h(e); } - pub fn @"error"(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .@"error") catch |e| if (logger.on_error) |h| h(e); } - pub fn fatal(logger: *Self, comptime fmt: []const u8, args: anytype) noreturn { logger.log(fmt, args, .fatal) catch unreachable; unreachable; } + pub fn debug(logger: *const Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .debug) catch |e| if (logger.on_error) |h| h.call(e); } + pub fn info(logger: *const Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .info) catch |e| if (logger.on_error) |h| h.call(e); } + pub fn warn(logger: *const Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .warn) catch |e| if (logger.on_error) |h| h.call(e); } + pub fn @"error"(logger: *const Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .@"error") catch |e| if (logger.on_error) |h| h.call(e); } + pub fn fatal(logger: *const Self, comptime fmt: []const u8, args: anytype) noreturn { logger.log(fmt, args, .fatal) catch unreachable; unreachable; } + + // alias + pub const err = @"error"; /// Forces any buffered output to be written to the underlying /// writer immediately. /// /// Returns an error if the underlying writer fails to flush. - pub fn flush(logger: *Self) !void + pub fn flush(logger: *const Self) !void { try logger.state.mutex.lock(logger.state.io); defer logger.state.mutex.unlock(logger.state.io); @@ -295,7 +323,6 @@ test "filtering, buffering and automatic flushing" var read_buf: [512]u8 = undefined; const path = try mktmpdir(&path_buf,"/tmp/zocket-test-XXXXXX"); - const dir = try std.Io.Dir.openDirAbsolute(io, path, .{}); defer { @@ -307,7 +334,7 @@ test "filtering, buffering and automatic flushing" const file = try dir.createFile(io, fname, .{ .lock = .exclusive }); defer file.close(io); - var log = try Logger.init(allocator, .{ + const log = try Logger.init(allocator, .{ .io = io, .buffer = 256, .file = file }); defer log.deinit(); @@ -333,12 +360,21 @@ test "filtering, buffering and automatic flushing" try log.state.writer.seekTo(0); @memset(read_buf[0..], 0); - // The file should include '[WARN] warn=1\n' as warnings and errors automatically trigger a flush to disk. - log.warn("warn={d}", .{1}); + // The file is expected to be empty, as debug is below the default level (info). + log.debug("debug={d}", .{1}); + try log.flush(); { const contents = try dir.readFile(io, fname, &read_buf); - try std.testing.expectEqualStrings("[WARN] warn=1\n", contents); + try std.testing.expect(contents.len == 0); + } + + // The file should include '[ERROR] error=1\n' as warnings and errors automatically trigger a flush to disk. + log.err("error={d}", .{1}); + + { + const contents = try dir.readFile(io, fname, &read_buf); + try std.testing.expectEqualStrings("[ERROR] error=1\n", contents); } try file.setLength(io, 0); try log.state.writer.seekTo(0); @@ -356,3 +392,114 @@ test "filtering, buffering and automatic flushing" try log.state.writer.seekTo(0); @memset(read_buf[0..], 0); } + +test "init, shared state & individual handles, deinit" +{ + const io = std.testing.io; + const allocator = std.testing.allocator; + const fname = "logger-memory.test"; + + var path_buf: [64:0]u8 = undefined; + var read_buf: [512]u8 = undefined; + + const path = try mktmpdir(&path_buf, "/tmp/zocket-test-XXXXXX"); + const dir = try std.Io.Dir.openDirAbsolute(io, path, .{}); + defer + { + dir.deleteFile(io, fname) catch {}; + dir.close(io); + std.Io.Dir.deleteDirAbsolute(io, path) catch {}; + } + + const file = try dir.createFile(io, fname, .{ .lock = .exclusive }); + defer file.close(io); + + // A failed init doesn't leak memory, partial allocations are freed. + { + var failing = std.testing.FailingAllocator.init(allocator, .{}); + + // First allocation (the buffer) fails. + failing.fail_index = failing.alloc_index; + try std.testing.expectError(error.OutOfMemory, Logger.init(failing.allocator(), .{ + .io = io, .buffer = 128, .file = file, + })); + + // Second allocation (the WriterState) fails. + failing.fail_index = failing.alloc_index + 1; + try std.testing.expectError(error.OutOfMemory, Logger.init(failing.allocator(), .{ + .io = io, .buffer = 128, .file = file, + })); + } + + const log = try Logger.init(allocator, .{ + .io = io, .buffer = 128, .file = file, + }); + + // init acquires exactly one ownership reference. + try std.testing.expectEqual(1, log.state.refs.load(.monotonic)); + + const clone_a = log.clone(); + const clone_b = log.cloneWith(.debug); + try std.testing.expectEqual(3, log.state.refs.load(.monotonic)); + + // Clones share one state, buffer, writer, and mutex. + try std.testing.expectEqual(log.state, clone_a.state); + try std.testing.expectEqual(log.state, clone_b.state); + + // Handles are move-safe, the state is heap-stable, so an owning handle may be relocated and retains full ownership. + const state_ptr = clone_b.state; + + var slot: ?Logger = null; + slot = clone_b; + var moved = slot.?; + slot = null; + + try std.testing.expectEqual(state_ptr, moved.state); + try std.testing.expectEqual(3, moved.state.refs.load(.monotonic)); // Moves don't retain. + + // Buffered writes from two different handles accumulate in the one shared buffer. + log.info("from-original", .{}); + clone_a.info("from-clone", .{}); + + // Deinitializing a non-final handle neither flushes nor frees, the file stays empty and the buffered data survives. + log.deinit(); + + { + try std.testing.expectEqual(2, clone_a.state.refs.load(.monotonic)); + + const contents = try dir.readFile(io, fname, &read_buf); + try std.testing.expectEqual(0, contents.len); + } + + // Surviving handles keep full use of the shared state after the original handle is gone. + clone_a.warn("after-original-deinit", .{}); + + { + const contents = try dir.readFile(io, fname, &read_buf); + try std.testing.expectEqualStrings( + "[INFO] from-original\n" ++ + "[INFO] from-clone\n" ++ + "[WARN] after-original-deinit\n", + contents, + ); + } + + clone_a.deinit(); + + // The moved handle writes into the same still-alive shared buffer. + moved.info("still-buffered", .{}); + + // The final deinit flushes pending output and frees the buffer and WriterState. + moved.deinit(); + + { + const contents = try dir.readFile(io, fname, &read_buf); + try std.testing.expectEqualStrings( + "[INFO] from-original\n" ++ + "[INFO] from-clone\n" ++ + "[WARN] after-original-deinit\n" ++ + "[INFO] still-buffered\n", + contents, + ); + } +}