Compare commits

..

9 Commits

3 changed files with 468 additions and 108 deletions

View File

@@ -34,9 +34,18 @@ pub fn build(b: *std.Build) void
.target = target, .target = target,
}); });
const test_mod = b.createModule(.{
.root_source_file = b.path("src/root.zig"),
.target = target,
.link_libc = true,
});
mod.addImport("toml", toml_dep.module("toml")); mod.addImport("toml", toml_dep.module("toml"));
mod.addImport("args", args_dep.module("args")); mod.addImport("args", args_dep.module("args"));
test_mod.addImport("toml", toml_dep.module("toml"));
test_mod.addImport("args", args_dep.module("args"));
const exe = b.addExecutable(.{ const exe = b.addExecutable(.{
.name = "zocket", .name = "zocket",
.root_module = b.createModule(.{ .root_module = b.createModule(.{
@@ -66,20 +75,13 @@ pub fn build(b: *std.Build) void
} }
const mod_tests = b.addTest(.{ const mod_tests = b.addTest(.{
.root_module = mod, .root_module = test_mod,
}); });
const run_mod_tests = b.addRunArtifact(mod_tests); const run_mod_tests = b.addRunArtifact(mod_tests);
const exe_tests = b.addTest(.{
.root_module = exe.root_module,
});
const run_exe_tests = b.addRunArtifact(exe_tests);
const test_step = b.step("test", "Run tests"); const test_step = b.step("test", "Run tests");
test_step.dependOn(&run_mod_tests.step); test_step.dependOn(&run_mod_tests.step);
test_step.dependOn(&run_exe_tests.step);
} }
fn getGitVersion(b: *std.Build) []const u8 fn getGitVersion(b: *std.Build) []const u8

View File

@@ -4,99 +4,213 @@ const std = @import("std");
/// ///
/// A `Logger`'s configured `level` acts as a filter: messages logged /// A `Logger`'s configured `level` acts as a filter: messages logged
/// at a lower severity than the logger's level are silently dropped. /// at a lower severity than the logger's level are silently dropped.
pub const Level = enum { pub const Level = enum(u8) {
debug, debug,
info, info,
warn, warn,
@"error", @"error",
fatal,
/// 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
{
return switch (level)
{
inline else => |l| comptime comptimeTag(@tagName(l)),
};
}
fn comptimeTag(comptime name: []const u8) []const u8
{
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: [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 passed to `Logger.init`. /// Configuration used to create an initial `Logger` handle.
/// ///
/// `level` sets the minimum severity that will be written; messages /// `level` sets the initial handle's minimum severity. A logger made
/// below this level are discarded. /// 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, of the internal write buffer /// `buffer` is the size, in bytes, allocated for the shared internal
/// allocated for `writer`. Larger buffers reduce the number of /// write buffer. Larger buffers can reduce underlying writes at the
/// underlying writes at the cost of more memory and higher latency /// cost of memory use and latency before buffered messages are flushed.
/// 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 { pub const InitOptions = struct {
pub const ErrorCallback = Logger.ErrorCallback;
level: Level = .info, level: Level = .info,
buffer: usize = 1024, buffer: usize = 1024,
on_error: ?ErrorCallback = null,
file: std.Io.File, file: std.Io.File,
io: std.Io, io: std.Io,
}; };
/// A minimal, thread-safe, buffered logger. /// Thread-safe, move-safe, copy-safe (through `.clone`), buffered file logger
/// with shared writer state.
/// ///
/// Writes are buffered and only flushed automatically on `warn`, /// A `Logger` is an owning handle to shared writer state. Handles made
/// `@"error"`, or `deinit`. /// with `clone` share one buffer, `File.Writer`, I/O context, and mutex,
/// `debug` and `info` messages may sit in the buffer until it fills, /// so writes from all clones are serialized and cannot interleave.
/// a higher-severity message is logged, `flush` or `deinit` is called.
/// ///
/// Must be initialized with `init` before use and cleaned up with /// `level` and `on_error` belong to each individual logger handle.
/// `deinit`. Not copyable once initialized, as `mutex` and `writer` /// Consequently, clones may use different severity filters and error
/// hold state tied to the original instance. /// 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 Logger = struct {
level: Level = .info, pub const ErrorCallback = struct {
buffer: []u8 = undefined, ctx: ?*anyopaque,
writer: std.Io.File.Writer = undefined, func: *const fn (ctx: ?*anyopaque, err: anyerror) void,
mutex: std.Io.Mutex = undefined,
alloc: std.mem.Allocator = undefined, pub fn call(cb: ErrorCallback, e: anyerror) void { cb.func(cb.ctx, e); }
io: std.Io = undefined, };
level: std.atomic.Value(Level) = .init(.info),
on_error: ?ErrorCallback = null,
state: *WriterState,
const Self = @This(); const Self = @This();
/// Creates and returns an initialized `Logger`. /// Heap-allocated state shared by all `Logger` clones.
/// ///
/// Allocates `options.buffer` bytes from `allocator` for internal /// This stores the buffer, writer, I/O context, and mutex together at
/// write buffering; ownership of this allocation belongs to the /// a stable address. `File.Writer` retains a pointer into `buffer`, so
/// returned `Logger` and is freed in `deinit`. /// neither may move for as long as any owning logger handle remains.
/// ///
/// `allocator` is stored on the result and reused for cleanup, so /// `refs` counts owning handles created by `init` and `clone`. The last
/// it must remain valid for the logger's lifetime. /// 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.
/// ///
/// Safe to move or copy the returned value freely before first /// Allocates `options.buffer` bytes for the shared write buffer and a
/// use, since the write buffer lives on the heap rather than /// `WriterState` containing the buffer's writer, I/O context, mutex,
/// inside the `Logger` struct itself. Once a method has been /// allocator, and initial ownership reference.
/// 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. /// 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 pub fn init(allocator: std.mem.Allocator, options: InitOptions) !Self
{ {
const buffer = try allocator.alloc(u8, options.buffer); 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{ return Self{
.level = options.level, .level = .init(options.level),
.buffer = buffer, .on_error = options.on_error,
.writer = options.file.writer(options.io, buffer), .state = state,
.mutex = .init,
.alloc = allocator,
.io = options.io,
}; };
} }
/// Flushes any buffered output and releases the logger's buffer. /// Releases this logger handle's ownership of the shared writer state.
/// ///
/// Safe to call once initialization via `init` has succeeded. /// If other logger handles created with `clone` remain, this only
/// Flush errors are silently ignored, since there is no caller /// decrements the shared reference count. The final owning handle
/// left to meaningfully report them to at teardown time. /// flushes buffered output and frees the shared buffer and `WriterState`.
/// ///
/// Must not be called more than once, as the buffer is freed /// Flush and lock errors during final cleanup are reported through this
/// unconditionally. /// handle's `on_error` callback when one is configured; otherwise they
pub fn deinit(logger: *Self) void /// are ignored.
///
/// Each logger returned by `init` or `clone` must be deinitialized
/// exactly once.
pub fn deinit(logger: Self) void
{ {
logger.mutex.lock(logger.io) catch {}; const state = logger.state;
logger.writer.interface.flush() catch {};
logger.mutex.unlock(logger.io);
logger.alloc.free(logger.buffer); // 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,36 +228,278 @@ pub const Logger = struct {
/// ///
/// Returns an error if formatting or writing to the underlying /// Returns an error if formatting or writing to the underlying
/// writer fails. /// 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); if (level == .fatal) return logger.fatalLog(fmt, args);
defer logger.mutex.unlock(logger.io);
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.state.writer.interface.print(
try logger.writer.interface.flush(); "{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 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: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .info) catch {}; } 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: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .warn) catch {}; } 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: *Self, comptime fmt: []const u8, args: anytype) void { logger.log(fmt, args, .@"error") catch {}; } 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 /// Forces any buffered output to be written to the underlying
/// writer immediately. /// writer immediately.
/// ///
/// Returns an error if the underlying writer fails to flush. /// 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); try logger.state.mutex.lock(logger.state.io);
defer logger.mutex.unlock(logger.io); defer logger.state.mutex.unlock(logger.state.io);
try logger.writer.interface.flush(); try logger.state.writer.interface.flush();
} }
}; };
//
extern fn mkdtemp(template: [*:0]u8) ?[*:0]u8;
fn mktmpdir(buffer: *[64:0]u8, pattern: []const u8) ![]u8
{
if (pattern.len >= buffer.len) return error.PatternTooLong;
@memcpy(buffer[0..pattern.len], pattern);
buffer[pattern.len] = 0;
const result = mkdtemp(buffer) orelse return error.MkDtempFailed;
return std.mem.span(result);
}
test "filtering, buffering and automatic flushing"
{
const io = std.testing.io;
const allocator = std.testing.allocator;
const fname = "logger.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);
const log = try Logger.init(allocator, .{
.io = io, .buffer = 256, .file = file
});
defer log.deinit();
//
// The file is expected to be empty, as this does not force the internal buffer to auto-flush.
log.info("info={d}", .{1});
{
const contents = try dir.readFile(io, fname, &read_buf);
try std.testing.expect(contents.len == 0);
}
// 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] info=1\n", contents);
}
try file.setLength(io, 0);
try log.state.writer.seekTo(0);
@memset(read_buf[0..], 0);
// 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.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);
@memset(read_buf[0..], 0);
// 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);
// 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.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,
);
}
}

View File

@@ -8,8 +8,10 @@ pub const memory = @import("memory/util.zig");
pub const signals = @import("signals/models.zig"); pub const signals = @import("signals/models.zig");
pub const logging = @import("logging/log.zig"); pub const logging = @import("logging/log.zig");
//
const std = @import("std");
test { test {
_ = config; std.testing.refAllDecls(@This());
_ = memory;
_ = signals;
} }