Skip to content
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

add unit tests, docs related to available log level names #189

Merged
merged 10 commits into from Dec 7, 2020

Conversation

salewski
Copy link
Contributor

@salewski salewski commented Dec 5, 2020

This PR adds some unit tests and freshens up docs related to logging levels.

This work started as an effort to provide unit tests that exercise simple scenarios in which a single logging level is specified for the entire application (without any more specific logging directives). It grew into a bit of a doc updating effort, too.

The unifying theme behind the individual commits in this series is the surfacing of simple facts about the env_logger crate. These changes help provide answers to some fairly basic questions such as:

  • "What log levels are available?"
  • "Is INFO allowed in addition to info?"
  • "How do I configure it?"
  • "Does it have a config file?"
  • "How do I make it write to a log file?"
  • "How do I completely disable logging?"

The doc changes also include fixes to some contradictory statements about what the default behavior is.

Most of this is just gathering data from elsewhere else and putting it where people are already looking (info from the README.md file that wasn't in the crate-level API docs (or vice versa); info that can be guessed at from glancing at the log crate's API docs, but which are important for using env_logger with confidence; and so on). The idea is that the user reading the crate-level API docs on crates.io should get roughly the same sense for the crate as does the person reading the project's 'README.md' file on GitHub.

The newly added unit tests exercise functionality in a way that is more basic than the existing tests (that involve more sophisticated logging directives). These new tests also serve as easy to locate in-tree examples of simple use.

All in all, these changes help make the documentation of env_logger more self contained -- able to stand better on its own, and with less reliance on the user's familiarity with the log crate.

@salewski
Copy link
Contributor Author

salewski commented Dec 5, 2020

Heads-up: The failed CI check is unrelated to this PR.

The "Check formatting" check is complaining about a trailing comma on an existing line of code, not something introduced here.

Copy link
Contributor

@jplatte jplatte left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the PR, I like the improved docs!

I've now fixed the rustfmt issue on the master branch, could you rebase? Also, why do your commit messages all start with [N of 9]: ? I've seen this before but don't really understand what value it provides.

README.md Show resolved Hide resolved
src/lib.rs Outdated
@@ -123,19 +123,30 @@
//! The letter case is not significant for the logging level names; e.g.,
//! `debug`, `DEBUG`, and `dEbuG` all represent the same logging level.
//!
//! There is also a pseudo logging level, `OFF`, which may be specified to
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since the "canonical" (most often referred to) form is lowercase, maybe this should be lowercase as well.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay. I have only limited experience with env_logger; my experience with other loggers in other language ecosystems has conditioned me to recognize the upper case as something akin to either a global constant or the name of a global variable name. But I'm not fixated on it :-)

As I'm tweaking things for my rebase, I'll try to work in a mention that lowercase is preferred.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh, I wasn't saying that it should be preferred. Just that the docs most often use the lowercase form. I was suggesting

Suggested change
//! There is also a pseudo logging level, `OFF`, which may be specified to
//! There is also a pseudo logging level, `off`, which may be specified to

src/lib.rs Outdated Show resolved Hide resolved
src/lib.rs Outdated
//! * `info` turns on all info logging
//! * `INFO` turns on all info logging (same as previous)
//! * `hello=debug` turns on debug logging for 'hello'
//! * `hello=DEBUG` turns on debug logging for 'hello' (same as previous)
//! * `hello,std::option` turns on hello, and std's option logging
//! * `error,hello=warn` turn on global error logging and also warn for hello
//! * `error,hello=off`` turn on global error logging, but turn off logging for hello
//! * `OFF` turns off all logging for the application
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And here.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And here.

For this one I was deliberately trying to show that both upper and lower case variants are accepted. It's one thing to state the rules in the prose, but I think that seeing examples of both will help more people to recognize both as valid "on sight". But maybe there's a better way to convey that; I've got a couple of ideas to try. More on that shortly...

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Right. Could also keep this one as-is.

@salewski
Copy link
Contributor Author

salewski commented Dec 6, 2020

@jplatte Thanks for the review!

Thanks for the PR, I like the improved docs!

I've now fixed the rustfmt issue on the master branch, could you rebase?

Sure; I'll do that as soon as I make the adjustments outlined below.

Also, why do your commit messages all start with [N of 9]: ? I've seen this before but don't really understand what value it provides.

It's mainly a way of organizing work informed by experience reviewing patch series in email threads. It attaches to a commit useful metadata that will live with the commit indefinitely (unless it gets removed in a future rebase or "squash and merge"). Having that small bit of metadata handy avoids the need to re-derive it, and provides a number of small benefits that can make things easier to manage, especially when working with a large number of projects and branches within those projects.

  • Personal commit management during development: While working on a change (always on a dedicated branch), the numbering helps with managing the individual commits across rebases, of which I do tons.

    I don't usually sit down to write a patch series, but rather "just one small patch...". While trying to keep commits small and self-contained, one change grows into to two, two grows into three, and so on, and they almost never flow out in the same order as the final sequence. They continually get split apart, squashed together, and rearranged via rebases throughout.

    Because Emacs and Magit make interactive rebases so easy, I do tons of them. Most never get pushed anywhere; they're just cyclical refinements made on my local branch leading up to the thing that eventually gets pushed.

    Those interactive rebases involve nudging individual commits "up" and "down" in the order, inserting "fixup" and "squash" merges in between them, and similar things. That type of activity is more difficult for me to screw up when the commit messages have numbers on them.

    I can also do the rebases more quickly when I can focus on the locality of the sequence numbers, which I already thought through at some earlier time when assigning the numbers. I do not have to again get my head into the context of each of those individual commits and redo the total sequencing.

    The numbers help to tell at a glance how the change series is sizing up. As it evolves, I frequently inspect the output of:

        $ git log --pretty=oneline --no-decorate --reverse ${COMMIT}..

    It is more convenient (and less error prone) to just run that one command than to run that command and then run it again to pipe to ...| wc -l to get the patch/commit count. And if I mis-specified the "since" commit hash, the numbers in the summary lines make that obvious.

  • Reviewing changes: When I'm reviewing somebody's changes, seeing "n of m" on them is a hint that the person has thought through the sequencing of the changes -- it is less likely to be "just a clump of changes". It's a small quality indicator heuristic.

    Though GitHub does not directly support a workflow in which commits can be reviewed in email, it does include the commit summary in the email messages it sends out. I, for one, prefer to read that first before reading the (potentially much longer) PR description. I think the "n of m" number makes the commit summary easier to digest. Here's what it looks like in the email message I received for this PR:

        -- Commit Summary --
    
          * [1 of 9]: filter::parse_spec(): add more parse_spec_global* tests
          * [2 of 9]: filter::parse_spec(): add more parse_default* tests
          * [3 of 9]: update docs to note that level names are case insensitive
          * [4 of 9]: markdown now shows 'RUST_LOG'; in bold (first mention only)
          * [5 of 9]: update crate-level docs to note non-env-var configuration
          * [6 of 9]: docs: clarify default enabled/disabled log level behavior
          * [7 of 9]: docs: show log levels in bulleted list
          * [8 of 9]: document 'OFF' pseudo log level feature
          * [9 of 9]: docs: term "logging directives" emphasized (first mention)
    

    When reviewing patches in email, seeing the collective "[PATCH n of m]" subject line would let the reader know at a glance whether they even have all of the pieces. This isn't a concern on GitHub, of course, but depending on how a commit series ultimately gets merged back into the main project there could be an analogous benefit when reviewing the Git history of a project (more on this below).

    Finally, if I'm on the fence about whether or not to go get a coffee refill before reviewing a series of commits, seeing "n of 27" nudges me toward a different decision than does "n of 3" :-)

  • Commit history: The "n of m" messages make it easy to quickly inspect the 'git log' output while reviewing a pull request locally (e.g., after doing git fetch ${REMOTE_NAME} pull/${ID}/head:${LOCAL_BRANCH_NAME}). And that makes it easy to find the commit from which to start reading a la: $ git log -p --reverse d4606a33b38d..

    The "n of m" message are also useful when it comes time to merge the changes from a branch. There are different schools of thought on what types of merges to perform in different circumstances, but the "n of m" helps with a couple of common scenarios when doing a "recursive" merge (the Git (and GitHub) default):

    • If --no-ff (also the GitHub default) or --ff-only options are used, then the individual commits will live on in the Git history as independent entities. Having the "n of m" on the commit message shows that the commit was part of a broader context, which may be useful to consider when reading the commit history.

    • If doing a "Squash and merge", then the combined commit messages from the series will be grouped together in the "starter commit message" presented, which the person performing the merge will (typically) then massage (hopefully with the help of a good text editor, in non-trivial cases). In this content the "[n of m]:" tokens can be used within one's editor (assuming a programmable editor) to partially automate the task of editing the message. For example, they facilitate landmark parsing while building up an editing macro interactively.

@salewski
Copy link
Contributor Author

salewski commented Dec 6, 2020

@jplatte By the way, thanks for fixing the rustfmt issue!

@jplatte
Copy link
Contributor

jplatte commented Dec 6, 2020

@jplatte By the way, thanks for fixing the rustfmt issue!

I only re-ran cargo fmt 😅
(although I would really prefer the formatting as it was too)

Also, why do your commit messages all start with [N of 9]: ? I've seen this before but don't really understand what value it provides.

[...]

I was not expecting such an elaborate reply! Doing a lot of rebases myself I don't really get the benefits for that, but I can see how it would be nice to see when reviewing large change sets as a quick gauge for how far into the review one is.

I'll be doing the default GitHub "merge", i.e. with a merge commit, if that matters.

These test parse_spec() against strings that contain only a legit
log level name. Several case variants are exercised, and confirmed
to obtain the same result.
Add tests that elaborate on the existing parse_default() unit
test. These new tests exercise all of log::Level variants (plus the
"OFF" pseudo log level), and also serve as minimal examples of how
to set the default log level. For example, they exercise both
lowercase and uppercase variants. There is one mixed case variant
test thrown in, too, since that is specifically allowed for by the
external log::Level::from_str() implementation on which we depend.

There is also a test to ensure all log::Level variants are accounted
for in the above tests. That one is intended to avoid the false
sense of comfort from passing tests in the unlikely event that a new
variant is added to the externally defined log::Level enum. (Note
that this compile-time check does not include the "OFF" pseudo log
level, as it exists outside of the log::Level enum.)
The fact that user-specified logging level names are handled in a
case-insensitive fashion is now noted in both the 'README.md' file
and in the crate-level API docs.
The first mention of the 'RUST_LOG' environment variable in the
prose in both the 'README.md' file and in the crate-level API docs
now uses bold text markdown. This is intended to draw attention to
it for both first time readers and for those skimming the docs
quickly.
For symmetry with the 'README.md' file, the crate-level API docs now
note that 'env_logger' can be configured by means other than via
environment variables, and (like README.md) directs the user to the
examples in the GitHub repo.

This is useful information for somebody first discovering the
'env_logger' crate on crates.io; it provides a more comprehensive
picture of how the crate is intended to be used.
The "Enabling logging" section of the crate-level docs are here
updated to clarify the default behavior as it pertains to the
logging level.

Previously, the first paragraph stated that all logging is disabled
except for the default level, but the third paragraph stated that if
no log level was specified then /all/ logging was enabled.

It turns out that the third paragraph was really intended as a
continuation of the second paragraph, the applicable context of
which is limited to those scenarios in which a logging directive has
been supplied.

This changeset reworks the paragraph structure slightly to make the
intent more clear, and also to make it easy to quickly identify the
most important aspects:

    A. Old para 1 split into two separate paras:
        - first states clearly the default behavior (now in bold)
        - second introduces 'RUST_LOG' and logging directives

    B. Old para 3 split into two separate paras:
        - first now qualifies the statement with "When specifying
          the crate name or a module path..."
        - second introduces log level names

    C. The existing statement that describes the behavior when only
       a log level is provided (it sets the global log level) is
       now in bold markdown.

It might make sense to refine this further at some point so that the
flow of the text answers in order the user's questions:

    1. "What is the default behavior?"  (Already first; good.)

    2. "How do I set the log level for the entire app?"

    3. "How do I set the log level more surgically?"

Our current flow is: (1), (3), (2)
The 'README.md' and crate-level API docs are both updated to show
the available logging levels in a bulleted list (rather then a
comma-separated list in the prose), and to note that they correspond
to the externally defined log::Level enum in the 'log' crate.

For the README.md file, this is an addition. The universe of valid
log levels was not previously listed there.

The order of the log levels is also now sorted in the list highest
precedence to lowest:
    error, warn, info, debug, trace

The previous order in which they were presented was:
    debug, error, info, warn, trace
Add markdown to emphasize (typical rendering would be italics) the
term "logging directive" upon the first mention in the text.
Since our convention throughout the docs is to use the lower case
form of log level names (e.g., "info" rather than "INFO"), users
might mistakenly infer that we are implying that only the lower case
forms are legit. Careful readers might even suspect that the handful
of departures are typos rather than deliberate examples.

This change adds a blurblet to the README.md and to the top-level
API docs explaining the convention and the motivation for using
it (consistency).
@salewski salewski force-pushed the ads/parse-spec-raw-level-tests branch from f81a239 to 5595a4d Compare December 6, 2020 23:36
@salewski
Copy link
Contributor Author

salewski commented Dec 6, 2020

I was not expecting such an elaborate reply!

Yeah, I kinda got on roll there... :-)

I'll be doing the default GitHub "merge", i.e. with a merge commit, if that matters.

I generally prefer that , too, because it keeps a more perfect record of the already-massaged history.

I just pushed my rebased update. It's identical to the previous set with two exceptions:

  • Commit 8is tweaked as we discussed above (for the "OFF" -> "off" changes)
  • I added a commit 10 to the end to explain the use of lowercase for consistency, and that the handful of exceptions are not typos

Please take a look when you can. I'm happy to refine it further, too.

@salewski salewski requested a review from jplatte December 7, 2020 01:30
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants