mindbeam / unbase

Other
39 stars 10 forks source link

Convert to logging framework #4

Open NoraCodes opened 7 years ago

NoraCodes commented 7 years ago

I'd really like to dig into this codebase but I don't really have much of an idea where to start.

I did notice that it's currently using raw println! rather than a logging framework. I'd be interested in converting to the log facade so that tests could use env_logger and clients could use any log-compatible backend.

dnorman commented 7 years ago

Hey @SilverWingedSeraph As you can see the code is very young, and the println! are not meant to stay of course. Your suggestion to use env_logger seems pretty reasonable to me. I'll gladly accept pull requests to that effect. Let me know if you're undertaking such an initiative, else I'll plan to convert the code to it myself when I get a chance.

NoraCodes commented 7 years ago

OK, I'll plan to do this over my upcoming spring break (starting this weekend).

NoraCodes commented 7 years ago

OK, having considered a number of options I've decided to go with log over slog because it prevents having to pass around references to a logger. I've also decided on using the flexi_logger backend for tests because it allows programmatically setting the log level.

This comes with some tradeoffs and new tasks, however:

  1. Every integration test must extern crate flexi_logger; use flexi_logger::*;
  2. Every test function must have as its first line LogOptions::new().init(Some("unbase=DEBUG".to_string())).unwrap();, which sets up a new logger that logs things from Unbase at DEBUG level.
  3. We have to decide what is appropriate for which logging levels, i.e., when things should be logged at info, when at debug, and when at trace. debug level is supposed to be everything that developers need except for the most thorny of bugs, at which point they can enable trace level logging, but I'm not sure where we should draw that line in this project.

Anyway, if you are OK with those tradeoffs re: reducing how ergonomic tests are, I'll submit a PR.

dnorman commented 7 years ago

@SilverWingedSeraph This seems reasonable to me.

It may make sense in the future to move the LogOption init inside of an unbase library so as to abstract the details of the logging framework, but this will require a bit more thought, would constitute a trivial change, and needn't be decided now anyway.

I'd suggest you use your best judgement re: log levels. In all likelihood, you have probably thought about it more than I have (which is to say, not very much)

As this is pre-alpha, there's a pretty good amount of flexibility in those kinds of details, and I intend to take a pretty liberal approach to merging PRs.

NoraCodes commented 7 years ago

OK. There's a problem with this approach right now in that Cargo doesn't correctly capture stderr in tests, so I've filed a bug for that; once it's fixed I'll finish this up. (Until they fix it, logging to stderr will make debugging annoyingly difficult.)

dnorman commented 7 years ago

I've always used -- --nocapture to get around that FWIW

dnorman commented 7 years ago

@SilverWingedSeraph Any thoughts on how to sensibly represent scope with tabbing/nesting in the debug and trace logs?

Eg:

Function A info 1 Function A info 2 \ Function B info 1 \ Function B info 2 \ Function C info 1 Function A info 3

Presently it looks like:

info 1 info 2 info 1 <- no way to know that this is function B info 2 info 1 <- no way to know that this is function C info 3 < no way to know we're back in function A again

could just add the function name / arguments to everything, but that would likely make it even more difficult to comprehend than it already is.

NoraCodes commented 7 years ago

I've always used -- --nocapture to get around that FWIW

Actually this is the opposite of what I was talking about; stderr is never captured, but we don't want to see it when tests pass.

Any thoughts on how to sensibly represent scope with tabbing/nesting in the debug and trace logs?

There's not really a way to do that without passing in scope counts to each function or using compiler intrinsics, since the stack gets built at runtime; I could set things up with slog instead of log which would give us a lot more power for things like that but require a bit more effort in the codebase itself.