Skip to content

introduce the concept of "logging" to the standard library #2586

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
andrewrk opened this issue May 29, 2019 · 13 comments · Fixed by #5348
Closed

introduce the concept of "logging" to the standard library #2586

andrewrk opened this issue May 29, 2019 · 13 comments · Fixed by #5348
Labels
accepted This proposal is planned. contributor friendly This issue is limited in scope and/or knowledge of Zig internals. proposal This issue suggests modifications. If it also has the "accepted" label then it is planned. standard library This issue involves writing Zig code for the standard library.
Milestone

Comments

@andrewrk
Copy link
Member

@hasDecl is implemented. After #2189 is implemented, the standard library could do something like this:

  • move std.debug.warn to std.log.warn

std.log would have functions like this:

const root = @import("root");
pub const Level = enum {
    /// helpful information for debugging. 
    Info,
    /// can't be sure something is wrong, but it is probably worth investigating
    Warning,
    /// a bug in the application has been detected, but it is recoverable.
    Error,
    /// a bug in the application has been detected, and the application must terminate now
    Fatal,
};

pub const default_level = switch (builtin.mode) {
    .Debug => Level.Info,
    .ReleaseSafe => Level.Warning,
    .ReleaseFast => Level.Error,
    .ReleaseSmall => Level.Fatal, // save bytes by not storing error messages
};
pub const level: Level = if (@hasDecl(root, "log_level")) root.log_level else default_level;

pub fn info(comptime format: []const u8, args: ...) void {
    // ...similar to warn fn...
}

pub fn warn(comptime format: []const u8, args: ...) void {
    if (@enumToInt(level) <= @enumToInt(Level.Warning))
        return;
    if (@hasDecl(root.log)) {
        root.log(Level.Warning, format, args);
    } else {
        // default to trying to get standard error and write to it, ignoring errors
        // on freestanding / targets without standard error, do nothing
    }
}

pub fn err(comptime format: []const u8, args: ...) void {
    @setCold(true);
    // ...similar to warn fn...
}

pub fn fatal(comptime format: []const u8, args: ...) noreturn {
    @setCold(true);
    if (@hasDecl(root.log)) {
        root.log(Level.Fatal, format, args);
        unreachable;
    } else {
        const msg = ...; // somehow collect format/args into a msg suitable for @panic
        @panic(msg);
    }
}

Note that log functions cannot fail, and the fatal one does not return. That's part of the semantics of logging: they don't provide a way to detect that log messages have been successfully handled, and that's intentional. "Hello World" becomes:

const std = @import("std");

pub fn main() void {
    std.log.info("Hello, World!\n");
}

I think this is better than trying to prove a point about error handling.

What this accomplishes is that developers can leave printf-style debugging log statements in their codebase, causing no harm, not printing anything to stderr, not even compiled, depending on the log level. Even in libraries are intended to be used in freestanding mode, could use the log system. Freestanding programs would simply implement the log function in their root source file, and either disregard the log messages, or better yet implement a way for them to be displayed.

The other component to this issue is how to specify the log level when building. One concept that this would benefit from is "package-local overrides" which is this idea that a package is a scope where one might want to tweak the parameters that are in builtin.zig. For example maybe I want ffmpeg package to be in release-fast mode but everything else in release-small mode.

In the build mode example, this is a concept recognized in the compiler itself, but the goal of this logging concept is to be a pure-userland solution. This means that we need some kind of system for libraries to officially expose "build options" that can be overridden per-package. In the above code example, it allows the log level to be overridden globally, which is good. But there also needs to be a way to override that setting per-package. Even better, if it allows such an option to be overridden per-scope. I don't have a proposed solution to that yet.

Ideally the default log level would be different in the main application package and in other packages. For example std.log.info in the main application should print by default, but in dependency packages those log messages should be silenced.

@andrewrk andrewrk added standard library This issue involves writing Zig code for the standard library. proposal This issue suggests modifications. If it also has the "accepted" label then it is planned. labels May 29, 2019
@andrewrk andrewrk added this to the 0.6.0 milestone May 29, 2019
@daurnimator
Copy link
Contributor

    std.log.info("Hello, World!\n");

But this would print nothing in release small mode?

    /// can't be sure something is wrong, but it is probably worth investigating

zig itself doesn't have compile warnings; why should other code?

we need some kind of system for libraries to officially expose "build options" that can be overridden per-package.

It would need to be more than per-package, I think it would often need to be per function.

@bheads
Copy link

bheads commented May 30, 2019

A good logger should be configurable at run time as well, ie: Your production system is having issues, but you dont/cant stop it, so just change the running log level. Its even more useful when you have a difficult to reproduce bug in a production environment, having to deploy a code change to just enable more logging then waiting for the bug to happen again costs time and money.

@andrewrk
Copy link
Member Author

Making it configurable at runtime would not be something the default thing would do but you could override the log function to achieve that behavior.

@marler8997
Copy link
Contributor

You could also make default_level a function, which just returns a comptime value by default, or root can make it a function that returns a comptime or runtime value.

@andrewrk andrewrk added the accepted This proposal is planned. label Sep 19, 2019
@andrewrk andrewrk added the contributor friendly This issue is limited in scope and/or knowledge of Zig internals. label Nov 26, 2019
@andrewrk
Copy link
Member Author

Marking this issue as contributor friendly now that all the prerequisites are complete. Just a heads-up to potential contributors though, I will probably be particularly picky about where this API lands.

@ifreund
Copy link
Member

ifreund commented May 15, 2020

I'm going to start work on this. Commenting to give myself some obligation to see it through and to hopefully avoid duplicated effort.

@Aransentin
Copy link
Contributor

It'd be nice if the standard logging library could optionally support the systemd journal as well. For example, if something like log_mode = .systemd; is set and the program is running as a systemd service, the logs are sent to the journal instead.

This is useful in that you can attach any type of structured data to it, e.g. the priority level (which is what colorizes the text in journalctl) or perhaps things like what file & line called the logging function, or an unique ID that identifies the particular message so you can search for it no matter how the language/spelling/phrasing etc. changes.

@Sobeston
Copy link
Contributor

Sobeston commented May 15, 2020

It'd be nice if the standard logging library could optionally support the systemd journal as well. For example, if something like log_mode = .systemd; is set and the program is running as a systemd service, the logs are sent to the journal instead.

If you can get this behaviour to fit in an io writer, then that's ideally the job done, which shouldn't be too hard.

@ifreund
Copy link
Member

ifreund commented May 15, 2020

In my opinion support for a specific init system does not belong in the standard library, especially as it would be easy to implement as a library by declaring your own log function in root.

@ifreund ifreund mentioned this issue May 15, 2020
4 tasks
@demizer
Copy link

demizer commented May 15, 2020

One thing we should strongly consider the ability to format the logging output from all sources, main app and dependent packages (as indicated in the issue description). I have implemented this for timestamps in emekoi/log.zig#3 using a time library ported from Go (https://github.com/gernest/time, zig 0.6 update here: https://github.com/demizer/time). It uses function callbacks (not sure if this strategy is idiomatic zig as I am new), but it works and allows me to "plugin" date formatting without adding an extra dependency to the logging library.

@FireFox317
Copy link
Contributor

Also shouldnt we keep std.debug.warn for simple debug printing? Calling std.log.warn to me looks like I want to log something, but if I just want a quick and dirty debug print, I think std.debug.warn makes more sense. Or maybe this is just because I'm used to std.debug.warn, but I can see that someone doesnt want all the logging features inside their simple app.

@demizer
Copy link

demizer commented May 15, 2020

I'm also all for simple logging API, but there should be a way to easily expand the API for people or use cases that require more logging detail (web apps, line numbers, coloring, etc..). Go logging is simple (some say too simple), and easily "up-gradable" through interfaces, hence why there are a million logging libraries for Go. I am not yet sure if we want that in Zig (also not sure if Zig stdlib is "batteries included" or not). Python has, IMHO, a great logging library in their stdlib and it works well enough for all use cases. Python also doesn't have a million third party logging libraries last time I checked.

In Python, you can set log handlers for each "component" of your application and configure where the logging for that component gets dumped to, and even the output format. They use yaml to configure the handlers. To see this in practice, have a look at the cuda image script generation tool logging config and output. Not saying we should use yaml, or anything like that, but the description of this issue, Andrew is suggesting the logging facility for Zig have support for something like that.

I authored the example above at work, and it is incredibly helpful to have the line numbers in the output of where the log statement is in the code to quickly debug any issues I am having. I have refactored this code twice already and each time takes me a few days, all thanks to detailed logging. Granted Python is much higher level than Zig, but I feel I'll eventually be just as productive in Zig as I am in Python. A good logging library would help with that.

@tecanec
Copy link
Contributor

tecanec commented May 21, 2020

I think we should take a similar approach to logging as we do to memory allocation. We would have a struct named Logger that contains a function pointer to a logFn that's equivalent to the root.log function in the original example implementation. It'd let us easily utilize multiple output terminals at once without managing global state. We would also have a singleton std_out logger that simply prints to the default terminal.
The only problem I can see with this is that of passing the loggers around.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
accepted This proposal is planned. contributor friendly This issue is limited in scope and/or knowledge of Zig internals. proposal This issue suggests modifications. If it also has the "accepted" label then it is planned. standard library This issue involves writing Zig code for the standard library.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

10 participants