slog icon indicating copy to clipboard operation
slog copied to clipboard

slog_scope's NoGlobalLoggerSet panic a bad default

Open pjenvey opened this issue 6 years ago • 2 comments

After an older gitter conversation, slog_scope's default global logger was changed to default to panic!()ing when the logger guard goes out of scope.

I think this is a bad default, especially for test suites. It's not uncommon to startup/teardown logging during tests. slog could intercept something before your first test is run (which it'll just Discard), then after the first scope tear down, these intercepts suddenly become panic!()s.

log messages might trigger panics from obscure places (I've seen one triggered from a lazy_static! block). They could be triggered differently depending on debug/release builds (the former might enable debug! calls). Tracking down these panics from the log system is not always a straightforward task.

pjenvey avatar Apr 23 '18 23:04 pjenvey

The asymmetry between before and after is indeed bad.

IIRC, the guard was added so that ther's something reliabily dropping slog-async::Async so that logging messages are flushed, to avoid a pitfall.

Problems with global state just won't go away...

My intuition tells me that panicking both before and after and pointing to documentation why it happens, would be a best option, even if it seems not very convenient for the users.

That would be hover rather bad breaking change.

Maybe both before and after we could print an eprintln poinitng to documentation ... but that's potentially also breaking change...

So I guess I'm fine with Discard here and there, and having user sometime report missing logging records.

dpc avatar Apr 24 '18 20:04 dpc

Whatever direction you go, it seems a good idea to keep the guard around to make sure Async gets flushed. Note that the documentation actually suggests that it will panic if you log before setting a global logger:

//! **Warning**: Since `slog-scope` version 4.0.0, `slog-scope` defaults to
//! panicking on logging if no scope or global logger was set. Because of it, it
//! is advised to always set a global logger upfront with `set_global_logger`.

Ideas:

  • Use Discard before and after
  • Use NoGlobalLoggerSet before and after
  • Provide a stack such that test setup and teardown can push and pop a child logger from a more global one
  • When not set, default to a new logger which, rather than just discarding or panicing, does an eprintln! saying that log messages were dropped
    • Probably store an AtomicBool on it so it only does so once

The third feels the most useful...

#[derive(Default)]
struct WarnNoLogger {
    has_warned: AtomicBool,
}

impl slog::Drain for WarnNoLogger {
    type Ok = ();
    type Err = !;
    fn log(&self, _, _) -> Result<(), !> {
        if !self.has_warned.swap(true, Ordering::Relaxed) {
            eprintln!("{}\n{}\n{}",
                "[slog-scope] No logger set.",
                "[slog-scope] Use `slog_scope::set_global_logger` or `slog_scope::scope`.",
                "[slog-scope] If you see this message, you're dropping logs.",
            );
        }
        Ok(())
    }
}

For what it's worth, I would consider behavior in scoped logging unspecified when you haven't provided a logger, unless otherwise indicated by the library. As quoted at the start, you're actually suggesting that you'll panic any time you try to use the log without having one set.

CAD97 avatar Apr 25 '18 00:04 CAD97