Allow adding file name and line number to logging output in std.log

[demizer]

When running code in a live environment, it is incredibly handy to have the line number and filename where the log statement was made to quickly jump to that portion of the code.

The following is the best I could come up with (with help from IRC) in a timely manner and limited experience (DON'T COPY THIS).

std.debug.StackIterator is used to get the address of the function where the logging call is made and printed to a buffer. Then i get the end of the line where ": " (note the space) is and used that to slice the buffer. Very janky:

const std = @import("std");

// Set the log level to warning
pub const log_level: std.log.Level = .warn;

var arena = std.heap.ArenaAllocator.init(std.heap.page_allocator);
var allocator = &arena.allocator;

// Define root.log to override the std implementation
pub fn log(
    comptime level: std.log.Level,
    comptime scope: @TypeOf(.EnumLiteral),
    comptime format: []const u8,
    args: anytype,
) void {
    const scope_prefix = "(" ++ switch (scope) {
        .my_project, .nice_library, .default => @tagName(scope),
        else => if (@enumToInt(level) <= @enumToInt(std.log.Level.crit))
            @tagName(scope)
        else
            return,
    } ++ ")";

    var config: std.debug.TTY.Config = .no_color;
    var buf = std.ArrayList(u8).init(allocator);
    const debug_info = std.debug.getSelfDebugInfo() catch unreachable;
    var it = std.debug.StackIterator.init(@returnAddress(), null);
    var count: u8 = 0;
    var address: usize = 0;
    while (it.next()) |return_address| {
        if (count == 2) {
            address = return_address;
            break;
        }
        count += 1;
    }
    std.debug.printSourceAtAddress(debug_info, buf.outStream(), address - 1, config) catch unreachable;

    const colPos = std.mem.indexOf(u8, buf.items[0..], ": ");
    var bufPrefix: [400]u8 = undefined;
    const prefix = std.fmt.bufPrint(bufPrefix[0..], "[{}] {} [{}]: ", .{ @tagName(level), scope_prefix, buf.items[0..colPos.?] }) catch unreachable;
    var bufOut: [400]u8 = undefined;
    const out = std.fmt.bufPrint(bufOut[0..], format, args) catch unreachable;
    const final = std.mem.concat(allocator, u8, &[_][]const u8{ prefix, out, "\n" }) catch unreachable;

    // Print the message to stderr, silently ignoring any errors
    const held = std.debug.getStderrMutex().acquire();
    defer held.release();
    const stderr = std.io.getStdErr().writer();
    nosuspend stderr.writeAll(final) catch return;
}

pub fn main() void {
    // Using the default scope:
    std.log.info("Just a simple informational log message", .{}); // Won't be printed as log_level is .warn
    std.log.warn("Flux capacitor is starting to overheat", .{});

    // Using scoped logging:
    const my_project_log = std.log.scoped(.my_project);
    const nice_library_log = std.log.scoped(.nice_library);
    const verbose_lib_log = std.log.scoped(.verbose_lib);

    my_project_log.info("Starting up", .{}); // Won't be printed as log_level is .warn
    nice_library_log.err("Something went very wrong, sorry", .{});
    verbose_lib_log.err("Added 1 + 1: {}", .{1 + 1}); // Won't be printed as it gets filtered out by our log function
}

With output that looks like:

[warn] (default) [/data/code/zig/markzig/logline.zig:56:17]: Flux capacitor is starting to overheat
[err] (nice_library) [/data/code/zig/markzig/logline.zig:64:25]: Something went very wrong, sorry

There are other ways this could possibly be done with @src() but that would require it being used everywhere a log statement is made. Also having to create a buffer for every log statement is probably not good.

There should be a better way to do this, for example, Go has it built into the logging library: https://golang.org/pkg/log/#pkg-constants. Same goes for Python.

[komuw]

I might be missing something, is this what you are looking for?;

const std = @import("std");

pub fn main() void {
    std.log.info("{}-{}: Hello world", .{ @src().fn_name, @src().line });
}

https://ziglang.org/documentation/master/#src

[VojtechStep]

I think the idea here is to be able to implement it in the log function only, without the caller having to provide the @src() argument.

[demizer]

I have another janky implementation here that doesn't require an allocator. This allows one to set the logging format when testing. The test runner doesn't expose the root source file so it's not currently possible to setup a logging scope.

[LGFae]

I'd like to point out that this would also be very helpful if it was implemented by default for std.debug.print. The documentation says explicitly that it is meant to be used for printf debugging. I think that having something like the filename and line number printed by default next to print statement would be very useful in this scenario.

[shizhaojingszj]

Is there any update here? Actually this is essential when debugging with stdout ...

[Gnyblast]

I think this is a bit interconnected to the issue https://github.com/ziglang/zig/issues/21906. Because if you can have @callerSrc() which returns you the caller information, you can override the default logger and use the variables produced by @callerSrc() to format what your logs should look like. Also it will significantly reduce the amount of parameters will be sent as duplicate on every single callback.