improved copy-safety, refined shared state handling, extended tests, updated comments

src/logging/log.zig

@@ -4,99 +4,213 @@ 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,
     @"error",
-};
+    fatal,
 
-/// Configuration passed to `Logger.init`.
-///
-/// `level` sets the minimum severity that will be written; messages
-/// below this level are discarded.
-///
-/// `buffer` is the size, in bytes, of the internal write buffer
-/// allocated for `writer`. Larger buffers reduce the number of
-/// underlying writes at the cost of more memory and higher latency
-/// before data is flushed.
-///
-/// `writer` is the underlying file the logger writes to (e.g. stderr
-/// or a log file). The logger takes no ownership of it beyond the
-/// lifetime of the wrapping `std.Io.File.Writer`.
-pub const InitOptions = struct {
-    level:  Level = .info,
-    buffer: usize = 1024,
-    file:   std.Io.File,
-    io:     std.Io,
-};
-
-/// A minimal, thread-safe, buffered logger.
-///
-/// Writes are buffered and only flushed automatically on `warn`,
-/// `@"error"`, or `deinit`.
-/// `debug` and `info` messages may sit in the buffer until it fills,
-/// a higher-severity message is logged, `flush` or `deinit` is called.
-///
-/// Must be initialized with `init` before use and cleaned up with
-/// `deinit`. Not copyable once initialized, as `mutex` and `writer`
-/// hold state tied to the original instance.
-pub const Logger = struct {
-    level:  Level              = .info,
-    buffer: []u8               = undefined,
-    writer: std.Io.File.Writer = undefined,
-    mutex:  std.Io.Mutex       = undefined,
-    alloc:  std.mem.Allocator  = undefined,
-    io:     std.Io             = undefined,
-
-    const Self = @This();
-
-    /// Creates and returns an initialized `Logger`.
-    ///
-    /// Allocates `options.buffer` bytes from `allocator` for internal
-    /// write buffering; ownership of this allocation belongs to the
-    /// returned `Logger` and is freed in `deinit`.
-    ///
-    /// `allocator` is stored on the result and reused for cleanup, so
-    /// it must remain valid for the logger's lifetime.
-    ///
-    /// Safe to move or copy the returned value freely before first
-    /// use, since the write buffer lives on the heap rather than
-    /// inside the `Logger` struct itself. Once a method has been
-    /// called on it, the logger must stay at a fixed address (e.g.
-    /// behind a pointer or in a `var` that isn't reassigned by value)
-    /// for the remainder of its life.
-    ///
-    /// Returns an error if the buffer allocation fails.
-    pub fn init(allocator: std.mem.Allocator, options: InitOptions) !Self
+    /// Returns the fixed-width, uppercase label used as the log-line
+    /// prefix for `level` (e.g. `"[INFO] "` for `.info`), derived from
+    /// the enum's own field name via `@tagName`.
+    /// All labels are padded to the width of the longest level name,
+    /// so prefixes line up in a fixed-width terminal/file.
+    fn prefix(level: Level) []const u8
     {
-        const buffer = try allocator.alloc(u8, options.buffer);
-
-        return Self{
-            .level  = options.level,
-            .buffer = buffer,
-            .writer = options.file.writer(options.io, buffer),
-            .mutex  = .init,
-            .alloc  = allocator,
-            .io     = options.io,
+        return switch (level)
+        {
+            inline else => |l| comptime comptimeTag(@tagName(l)),
         };
     }
 
-    /// Flushes any buffered output and releases the logger's buffer.
-    ///
-    /// Safe to call once initialization via `init` has succeeded.
-    /// Flush errors are silently ignored, since there is no caller
-    /// left to meaningfully report them to at teardown time.
-    ///
-    /// Must not be called more than once, as the buffer is freed
-    /// unconditionally.
-    pub fn deinit(logger: *Self) void
+    fn comptimeTag(comptime name: []const u8) []const u8
     {
-        logger.mutex.lock(logger.io) catch {};
-        logger.writer.interface.flush() catch {};
-        logger.mutex.unlock(logger.io);
+        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 "]"
 
-        logger.alloc.free(logger.buffer);
+        comptime var buf: [width]u8 = .{' '} ** width;
+
+        buf[0] = '[';
+        inline for (name, 0..) |c, i| buf[i + 1] = std.ascii.toUpper(c);
+        buf[name.len + 1] = ']';
+
+        const result = buf;
+        return &result;
+    }
+};
+
+/// Configuration used to create an initial `Logger` handle.
+///
+/// `level` sets the initial handle's minimum severity. A logger made
+/// with `clone` receives an independent copy of this setting and may
+/// change it without affecting other logger handles that share the
+/// same writer.
+///
+/// `buffer` is the size, in bytes, allocated for the shared internal
+/// write buffer. Larger buffers can reduce underlying writes at the
+/// cost of memory use and latency before buffered messages are flushed.
+pub const InitOptions = struct {
+    pub const ErrorCallback = Logger.ErrorCallback;
+
+    level:    Level          = .info,
+    buffer:   usize          = 1024,
+    on_error: ?ErrorCallback = null,
+    file:     std.Io.File,
+    io:       std.Io,
+};
+
+/// Thread-safe, move-safe, copy-safe (through `.clone`), buffered file logger
+/// with shared writer state.
+///
+/// A `Logger` is an owning handle to shared writer state. Handles made
+/// with `clone` share one buffer, `File.Writer`, I/O context, and mutex,
+/// so writes from all clones are serialized and cannot interleave.
+///
+/// `level` and `on_error` belong to each individual logger handle.
+/// Consequently, clones may use different severity filters and error
+/// callbacks while writing to the same destination.
+///
+/// Use `clone` to create another owning logger handle. Do not duplicate
+/// a `Logger` through assignment, aggregate initialization, or
+/// `@memcpy`; those operations do not retain the shared state. Every
+/// logger returned by `init` or `clone` must be passed to `deinit`
+/// exactly once.
+///
+/// Writes are buffered and automatically flushed for `warn`, `@"error"`,
+/// and `fatal` messages; they are also flushed when the final owning
+/// handle is deinitialized or when the writer drains due to buffer
+/// overflow. `debug` and `info` messages may remain buffered until then,
+/// or until `flush` is called.
+///
+/// Fatal logging is best-effort: the logger attempts to lock, write, and
+/// flush the fatal message, but ignores failures so logging failures can
+/// never prevent the subsequent panic.
+///
+/// Unless an `ErrorCallback` is specified, errors from the public
+/// logging methods are swallowed.
+pub const Logger = struct {
+    pub const ErrorCallback = struct {
+        ctx:  ?*anyopaque,
+        func: *const fn (ctx: ?*anyopaque, err: anyerror) void,
+
+        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,
+
+
+    const Self = @This();
+
+    /// Heap-allocated state shared by all `Logger` clones.
+    ///
+    /// This stores the buffer, writer, I/O context, and mutex together at
+    /// a stable address. `File.Writer` retains a pointer into `buffer`, so
+    /// neither may move for as long as any owning logger handle remains.
+    ///
+    /// `refs` counts owning handles created by `init` and `clone`. The last
+    /// handle released by `deinit` flushes the writer and frees this state.
+    const WriterState = struct {
+        refs: std.atomic.Value(usize) = .init(1),
+
+        io:        std.Io,
+        allocator: std.mem.Allocator,
+        buffer:    []u8,
+        mutex:     std.Io.Mutex,
+        writer:    std.Io.File.Writer,
+    };
+
+    /// Creates an initialized owning logger handle.
+    ///
+    /// Allocates `options.buffer` bytes for the shared write buffer and a
+    /// `WriterState` containing the buffer's writer, I/O context, mutex,
+    /// allocator, and initial ownership reference.
+    ///
+    /// The returned logger owns one reference to the shared state. It must
+    /// be passed to `deinit` exactly once, unless ownership is explicitly
+    /// transferred to another part of the program.
+    ///
+    /// Returns an error if either allocation fails.
+    pub fn init(allocator: std.mem.Allocator, options: InitOptions) !Self
+    {
+        const buffer = try allocator.alloc(u8, options.buffer);
+        errdefer allocator.free(buffer);
+
+        const state = try allocator.create(WriterState);
+        state.* = .{
+            .allocator = allocator,
+            .io        = options.io,
+            .buffer    = buffer,
+            .mutex     = .init,
+            .writer    = options.file.writer(options.io, buffer),
+        };
+
+        return Self{
+            .level     = .init(options.level),
+            .on_error  = options.on_error,
+            .state     = state,
+        };
+    }
+
+    /// Releases this logger handle's ownership of the shared writer state.
+    ///
+    /// If other logger handles created with `clone` remain, this only
+    /// decrements the shared reference count. The final owning handle
+    /// flushes buffered output and frees the shared buffer and `WriterState`.
+    ///
+    /// Flush and lock errors during final cleanup are reported through this
+    /// handle's `on_error` callback when one is configured; otherwise they
+    /// are ignored.
+    ///
+    /// Each logger returned by `init` or `clone` must be deinitialized
+    /// exactly once.
+    pub fn deinit(logger: Self) void
+    {
+        const state = logger.state;
+
+        // Another owning logger remains responsible for the shared state.
+        if (state.refs.fetchSub(1, .acq_rel) != 1) return;
+
+        if (state.mutex.lock(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.call(e);
+
+        state.allocator.free(state.buffer);
+        state.allocator.destroy(state);
+    }
+
+    /// Returns another owning logger handle that shares the same buffered
+    /// writer and mutex, while retaining this handle's current level and
+    /// error callback by value.
+    pub fn clone(logger: *const Self) Self
+    {
+        _ = logger.state.refs.fetchAdd(1, .monotonic);
+        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;
     }
 
     //
@@ -114,37 +228,72 @@ 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;
 
-        try logger.mutex.lock(logger.io);
-        defer logger.mutex.unlock(logger.io);
+        if (level == .fatal) return logger.fatalLog(fmt, args);
 
-        try logger.writer.interface.print(fmt, args);
+        try logger.state.mutex.lock(logger.state.io);
+        defer logger.state.mutex.unlock(logger.state.io);
 
-        if (level == .warn or level == .@"error") {
-            try logger.writer.interface.flush();
+        try logger.state.writer.interface.print(
+            "{s} " ++ fmt,
+            .{Level.prefix(level)} ++ args
+        );
+        try logger.state.writer.interface.writeByte('\n');
+
+        switch (level)
+        {
+            .warn, .@"error" => { try logger.state.writer.interface.flush(); },
+            else             => return,
         }
     }
 
+    /// Best-effort write-then-panic path for `.fatal` messages.
+    ///
+    /// Ignores lock/write/flush failures rather than propagating them,
+    /// 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: *const Self, comptime fmt: []const u8, args: anytype) noreturn
+    {
+        @branchHint(.cold);
+
+        const f = "{s} " ++ fmt;
+        const a = .{Level.prefix(.fatal)} ++ args;
+
+        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 {};
+        }
+
+        std.debug.panic(f, a);
+    }
+
     //
 
-    pub fn    debug(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .debug)    catch {}; }
-    pub fn     info(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .info)     catch {}; }
-    pub fn     warn(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .warn)     catch {}; }
-    pub fn @"error"(logger: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .@"error") catch {}; }
+    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.mutex.lock(logger.io);
-        defer logger.mutex.unlock(logger.io);
+        try logger.state.mutex.lock(logger.state.io);
+        defer logger.state.mutex.unlock(logger.state.io);
 
-        try logger.writer.interface.flush();
+        try logger.state.writer.interface.flush();
     }
 };
 
@@ -174,19 +323,18 @@ 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
     {
-        dir.deleteFile(io, fname) catch unreachable;
+        dir.deleteFile(io, fname) catch {};
         dir.close(io);
-        std.Io.Dir.deleteDirAbsolute(io, path) catch unreachable;
+        std.Io.Dir.deleteDirAbsolute(io, path) catch {};
     }
 
     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();
@@ -201,36 +349,157 @@ test "filtering, buffering and automatic flushing"
         try std.testing.expect(contents.len == 0);
     }
 
-    // The file should include 'info=1' after flushing to disk.
+    // The file should include '[INFO]  info=1\n' after flushing to disk.
     try log.flush();
 
     {
         const contents = try dir.readFile(io, fname, &read_buf);
-        try std.testing.expectEqualStrings("info=1", contents);
+        try std.testing.expectEqualStrings("[INFO]  info=1\n", contents);
     }
     try file.setLength(io, 0);
-    try log.writer.seekTo(0);
+    try log.state.writer.seekTo(0);
     @memset(read_buf[0..], 0);
 
-    // The file should include 'warn=1' 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=1", 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.writer.seekTo(0);
+    try log.state.writer.seekTo(0);
     @memset(read_buf[0..], 0);
 
-    // The file should include 'info=x...' as it's bigger than the allocated 256 buffer, forcing it to automatically drain on overflow.
+    // The file should include '[INFO]  info=x...' as it's bigger than the allocated 256 buffer, forcing it to automatically drain on overflow.
     log.info("info={s}", .{[_]u8{'x'} ** 300});
 
     {
         const contents = try dir.readFile(io, fname, &read_buf);
-        try std.testing.expectEqualStrings("info=" ++ ([_]u8{'x'} ** 300), contents);
+        // Note: This doesn't expect a newline, as it only drains the actual overflow, not the newline written into the buffer afterwards!
+        try std.testing.expectEqualStrings("[INFO]  info=" ++ ([_]u8{'x'} ** 300), contents);
     }
     try file.setLength(io, 0);
-    try log.writer.seekTo(0);
+    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,
+        );
+    }
+}