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

fix: Use a noop with the same signature as the real one for make_filtering_bound_logger #401

Merged
merged 1 commit into from
Mar 10, 2022
Merged

Conversation

GriceTurrble
Copy link
Contributor

@GriceTurrble GriceTurrble commented Feb 22, 2022

Summary

In my team's app, we're using make_filtering_bound_logger in our configuration, which is working fine except in one corner case. Another developer introduced a bug that was missed in review and testing, and it only appears at runtime when the log level is DEBUG (below INFO, our standard level):

log.debug(x=y)

Obviously this is incorrect: there needs to be an event string in this call. However, the original _nop method that gets returned has no checks for this missing argument, so their (admittedly poor) testing didn't turn up a problem at this line. Later when running at DEBUG level to research a different issue, the entire app failed to start up because of this call alone.

Root cause for us was incorrect code from our teammate, but I figured it could use some help from structlog, which seems to be silently passing what should be an error.

This change operates identically, returning None when the log level is too high. Now, though, it returns a method with the same signature every time, so a logging call written incorrectly will always raise an exception for missing arguments, regardless of the configured log level.

Pull Request Check List

  • Added tests for changed code.
    • The CI fails with less than 100% coverage.
  • New APIs are added to typing_examples.py.
  • Updated documentation for changed code.
    • New functions/classes have to be added to docs/api.rst by hand.
    • Changed/added classes/methods/functions have appropriate versionadded, versionchanged, or deprecated directives.
      Find the appropriate next version in our __init__.py file.
  • Documentation in .rst and .md files is written using semantic newlines.
  • Changes (and possible deprecations) are documented in the changelog.
  • Consider granting push permissions to the PR branch, so maintainers can fix minor issues themselves without pestering you.

@GriceTurrble
Copy link
Contributor Author

Just came back around to this and squashed all the commits down to the most pertinent changes. :)

Copy link
Owner

@hynek hynek left a comment

Choose a reason for hiding this comment

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

Hi thanks for the fixes, I was on vacation. Here's a few mostly doc fixes and it should be good to go after.

tests/test_log_levels.py Outdated Show resolved Hide resolved
tests/test_log_levels.py Show resolved Hide resolved
tests/test_log_levels.py Outdated Show resolved Hide resolved
tests/test_log_levels.py Show resolved Hide resolved
CHANGELOG.rst Outdated Show resolved Hide resolved
…ering_bound_logger

In my team's app, we're using `make_filtering_bound_logger`, which is
working fine except in one corner case. Another developer introduced a
bug that was missed in review and testing, and it only appears at
runtime when the log level is DEBUG or below:

    log.debug(x=y)

Obviously this is incorrect: there needs to be an `event` string in
this call. However, the original `_nop` method that gets returned has
no checks for this missing argument, so their (admittedly poor) testing
didn't turn up a problem at this line. Later when running at DEBUG
level to research a different issue, the entire app failed to start up
because of this call alone.

This change *should* operate identically, but returns a more explicit
method with the same signature as the original. This should indicate to
developers that even though the call is unused at higher log levels, it
may still be incorrect; and that kind of error should not pass silently.
Copy link
Owner

@hynek hynek left a comment

Choose a reason for hiding this comment

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

Thanks!

@hynek hynek enabled auto-merge (squash) March 10, 2022 07:00
@hynek hynek merged commit 5871e78 into hynek:main Mar 10, 2022
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.

2 participants