Crate evaluation for 2017-05-16: log


#33

It’s not clear to me whether some incomplete evaluation tasks have been claimed or not, so I added a section to the end of the template for listing tasks that people have volunteered for, and I added it to this op, and signed myself up for the “naming” and “interop” sections, which I will do shortly.

I also think that for simplicity’s sake we should stick to the log crate here, and worry about env_logger later. Otherwise we basically have to do the evaluation twice and create a whole second checklist. I’ll update the blitz thread to reflect this.


#34

I did the “naming” and “interop” sections and updated the op with the following:

Crate issues

  • Implement Debug for LogMetadata, LogRecord
  • FromStr impls for LogLevel, LogLevelFilter use () as error type

Guidelines changes

  • C-CONV-TRAITS should discuss FromStr

Discussion topics

  • Can any of these Debug representations be empty, per C-DEBUG-NONEMPTY?
  • Possible trait impls
    • LogLocation: Eq/PartialEq, Ord/PartialOrd, Hash, Clone
    • LogMetadata: Eq/ParialEq, Ord/PartialOrd, Hash
    • LogRecord: Eq/PartialEq, Ord/PartialOrd, Hash
    • LogLevel: Hash
    • LogLevelFilter: Hash
  • Should anything here implement serde?
    • If not what does that say about the guidelines C-SERDE?

#35

I’m going to do the docs checklist next.


#36

I also did “debuggability”.


#37

Updated the op with the following for documentation:

Crate issues

  • Document what happens when log is initialized more than once
    • crate docs say “may only be initalized once”, not why, or what happens if you initialize twice
  • Use env_logger instead of my_logger in example
    • env_logger is something a user can try themselves
  • Crate docs should mention the logging levels and corresponding macros
  • Add example for log! macro
    • using both variants
  • Document max_level_*, release_max_level_* features in crate docs
  • Add examples to debug!, error!, info!, trace!, warn!
    • Both pattern variants
  • Expand log! docs for max_level_*
    • Seems like a non-sequiter here, but other logging macros have better explanations of this feature
  • Add example for second log_enabled! pattern variant
    • There’s an example, but it only covers one variant of the macro
  • LogLocation doc improvements
    • How are these values created?
    • Are these for logger implementors or log user?
    • Add an example
  • LogMetadata doc improvements
    • How are these values created?
    • Are these for logger implementors or log user?
    • Add an example
  • LogRecord doc improvements
    • How are these values created?
    • Are these for logger implementors or log user?
    • What’s the difference between the ‘level’/‘target’ accessors here and on the attached LogMetadata?
    • Add an example
  • SetLoggerError doc improvements
    • Add links to functions
  • ShutdownLeggerError doc improvements
    • Add links to functions
  • LogLevel doc improvements
    • Do end-users use this type or just loggers?
    • Add link to LogLevelFilter
  • LogLevelFilter doc improvements
    • Do end-users use this type or just loggers?
    • Add link to LogLevel
  • max_log_level
    • Add links
  • set_logger docs
    • Add links
    • Add “Errors” section
    • Add example
  • set_logger_raw docs
    • Add links
    • Add “Errors” section
    • Add example
  • shutdown_logger docs
    • Add links
    • Add “Errors” section
    • Add example
  • shutdown_logger_raw docs
    • Add links
    • Add “Errors” section
    • Add example
  • Add links to crate docs
  • Add CI badges to Cargo.toml
  • Change Cargo.toml ocumentation key to point to https://docs.rs/log
  • Add keywords to Cargo.toml
  • Change html_root_url to https://docs.rs/$crate/$version

Guidelines changes

Discussion topics

  • Are there any panic conditions in this lib? Not documented.
  • There are several “musts” about usage here that are kinda scary
    • should we say more about why?
    • e.g. “This function may only be called once in the lifetime of a program, and may not be called before set_logger”
      • This is a safe function and I sure can do what is says I can’t

#38

A question I’d add for the discussion: do all the types need the Log prefix? LogLevel, LogRecord, LogMetadata, etc? Usually we like to say that there shouldn’t be a stutter, that a crate or module name is fine for differentiation (log::LogRecord vs log::Record).


#39

I filled out the “future proofing” and “necessities” sections. And I discovered something that confused me really badly about the documentation on docs.rs: the README is also displayed there. I didn’t bother evaluating the README as we have no guidelines, but we need to figure out how we think README should be handled.


#40

@seanmonstar I added it to the discussion points.


#41

One question I would have: is there any possibility in adding another crate “below” the log crate as an implementation detail that would handle inter-op between multiple versions of the log crate?

Changing log::LogRecord and log::LogMetaData to log::Record and log::Metadata is something I support, but having a breaking change in log would definitely split the ecosystem with users being unable to have loggers which receive records from both log 0.3 and 0.4 crates.

Could we create a log_dist crate which is meant only for use from within log which provides a very minimal API matching that of the log crate?

This way the log crate itself could be upgraded with incompatible changes (or to a 1.0 state after it’s been fully checked out), and it’d just have to call the same things in log_dist. It could be a non-breaking upgrade to add log_dist as a backend to log 0.3.x.


#42

Handling the 0.3 to 0.4 or 1.0 or whatever bump is definitely really important. Hopefully we can have 0.3 loggers “just work” via some hacky magic.


#43

Have anyone thought about changing the default compile time logging level?

In slog I made release builds by default ignore trace and debug and debug builds ignore trace. The rationale is: applications that need debug logging level in production can just enable it in Cargo.toml. Most apps probably don’t need it, and at times the performance hit can be substantial (especially as async logging is not implemented). Check here: https://github.com/rust-lang-nursery/log/issues/112 . 20% perf drop by using env_logger.

With trace and debug being by default disabled, developers are encouraged to use trace and debug and leave it inside the code without fear of slowing things down.


#44

Well the case was worst than I thought, should be done by Wednesday I think (I got caught by administrative things).


#45

Just throwing an example of a non-traditional(from log's API point of view) logging ?style?: I was also working(sadly, no plans to work on it in the next 3 months) on a logging library based on log: dlt-rs. For context?: DLT is very popular in the Automotive industry. In DLT you usually register a context(Ctid in the image from the link I posted - used for filtering) and when calling the log level, we also pass the Context ID(C++ example):

qCDebug(MyContext) << "Hello";

More info about the initialization steps, log levels, etc…: https://at.projects.genivi.org/wiki/display/PROJ/DLT+cheatsheet

At work we use DLT through Qt’s logging framework. Calling qCDebug would actually call QMessageLogger(links mostly for inspiration). Observe that the log levels also have function overloads with QLoggingCategory as a parameter - this covers DLT’s Context ID use-case. qCDebug by default calls Qt’s logging implementation(think env_logger) but we swap it with our implementation(dlt-rs?) with 1 header include.

Now to the issue: At the moment, log's macros are not very friendly to this use-case. There are workarounds of course - own macros for example. I am not even sure if log needs to cover such a use-case - just wanted to throw the info out there.


#46

Ok it’s now almost time for the review of the log crate! We’ll convene tomorrow 2016-05-16 at 1pm PST for a recorded video session to discuss this crate. I’ll be sure to post a link to the recording once it’s available.

In the meantime I’ve filled out the remaining minor points of evaluation (thanks @brson for filling out big chunks!) and I think we’re ready to go. I’ve copied everything and started trimming it down a bit into https://public.etherpad-mozilla.org/p/rust-crate-eval-log where we’ll take notes during the meeting. I’ll be sure to copy everything new back to this thread though for continuing the discussion.

Thanks again to everyone who’s participated so far! We’ve got a great list of discussion topics and there’s steady progress implementing examples in the cookbook. In the meantime I’ve added “migration away from 0.3” and “default log levels” to the discussion points, thanks for bringing those up @daboross and @dpc!


#47

I don’t really agree with that approach. Assuming you have not enabled trace level logs via RUST_LOG at runtime, the cost of a trace! call at runtime is a single integer load and comparison. If a project has so much logging that it’s spending 20% of its time performing that check, it’s unclear to me how useful such logs can possibly be. env-logger’s filtering logic is also pretty naiive IIRC.

IMO, high verbosity logging is useful because it’s there when you need it. For example, we were seeing Hyper unable to keep connections alive, but were able to turn on trace logging for Hyper and track down a bug in its handling of chunked request bodies. If trace is turned off by default, you either have to choose between defaulting to no trace messages and having to roll out custom one-off builds when you need access to them, or enable trace logging by default and face the performance penalties of libraries that over-log because they’re tuned off by default.


#48

Debug/trace logging also bumps executable size by all those text lines.


#49

Sure, and end users can choose to disable whatever levels of logging they want at compile time. This is just a discussion of defaults.


#50

Here are the API guideline issues that came out of this evaluation and our review:


#51

Alright everyone, time for another update! This past Tuesday the libs team (no guests this time) performed a review of the log crate and we discussed quite a few topics! We ended up getting through all of the discussion points above, and I’ll summarize in highlight our conclusions here. In addition to the links @dtolnay mentioned above I’ll add:

Discussion highlights:

What is the log crate’s relation to slog and fern?

This ended up being one of the largest discussion points of the meeting! The conclusion was that there’s no reason to not be more ambitious in log and attempt to cover structured logging as well. A tracking issue has been opened to continue discussoin and coordinate.

Should env_logger stay in the repository or should it get split out?

One discussion point brought up is that env_logger as a crate typically is misunderstood as the “main” and/or only logger implementation, lots of which stems from the fact that it’s in the log repository. The conclusion was to move the crate to its own repo, and if you’re interested in helping out and/or maintaining this please comment on the issue!

Many other concerns with env_logger were lumped into this, we didn’t talk about much specifically. Improvements to env_logger are of course always welcome!

Should shutdown of a logger be supported?

Conclusion was no, but flushing may want explicit support. Discussion may wish to continue on the tracking issue

Should anything here implement serde?

We’ve decided to update the guidelines here wrt what’s recommended to implement serde traits (not all types, just expand on the motivation for implementing the traits)

Are there any panic conditions in this lib?

Amazingly, no!

What should we do about README duplication?

We should comment on the associated RFC

The types here stutter in a way we usually don’t do (LogLevel)

A guidelines is born!

Should the static default log levels change? Should debug and trace be disabled by default in release mode? (e.g. see slog for an example)

A tracking issue has been created, and @sfackler had some good rationale for the current state of affairs, which he’ll copy to the tracking issue shortly.


If you’d like to help out please feel free to take a look at the tracking issue and dive in on any open issues! If you’d like to implement some cookbook examples there’s still some open as well!

Otherwise if you’ve got any questions please of course feel welcome to comment here, we’ll try to help direct you to the right location. Thanks again everyone for all the discussions here!


Rust libz blitz!
#52

I’ve found some time to watch the meeting video, especially interested in slog discussion.

So the most controversial feature was the “contextual logging” part (Logger object that carries its own key-value pairs) which is orthogonal to structured logging. I find it unsurprising. A lot of people don’t like the additional work of passing Logger around. It does affect APIs, it is opinionated, etc. I myself am not sure if it belongs to standard logging crate. Some applications need it, some don’t. For slog it makes sense to have them, as if you carred about structured logging so much to switch to slog your app will probably benefit from contextual logging as well.

Just to clarify: Loggers purpose is primarily to carry the context of logging message, not filtering, etc. Also, I very much dislike slog-scope crate, and I added because people kept asking for it (and who am I to tell them what they should do :smiley: ). I wouldn’t focus on it too much: genearlly in slog you have to pass Logger around, and nothing is global (but nothing prevents anyone from creating own globals or use slog-scope to carry Loggers implicitly).