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

PositionalArgumentsFormatter raises TypeError when postional argument is not a formatting tuple #258

Open
ryan-bever opened this issue Apr 23, 2020 · 6 comments

Comments

@ryan-bever
Copy link

When a structlog BouldLogger user incorrectly uses a postional argument that is not a formatting tuple, the PositionalArgumentsFormatter raises a TypeError.

The documentation states that this "must contain a tuple that is used for formatting".

What I want to point out is that this behavior is different than the stdlib when that method is misused. When the stdlib method is misused it catches the exception and prints a stacktrace, but it does not result in an uncaught exception.
e.g.

import logging
logging.basicConfig()
logging.getLogger('stdlib').warning('Info message', 'x')

Results in:

--- Logging error ---
Traceback (most recent call last):
  File "/Users/rbever/.pyenv/versions/3.7.6/lib/python3.7/logging/__init__.py", line 1025, in emit
    msg = self.format(record)
  File "/Users/rbever/.pyenv/versions/3.7.6/lib/python3.7/logging/__init__.py", line 869, in format
    return fmt.format(record)
  File "/Users/rbever/.pyenv/versions/3.7.6/lib/python3.7/logging/__init__.py", line 608, in format
    record.message = record.getMessage()
  File "/Users/rbever/.pyenv/versions/3.7.6/lib/python3.7/logging/__init__.py", line 369, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
  File "scratch.py", line 4, in <module>
    logging.getLogger('stdlib').warning('Info message', 'x')
Message: 'Info message'
Arguments: ('x',)

Process finished with exit code 0

PositionalArgumentsFormatter does result in an uncaught exception
e.g.

import structlog
structlog.configure(
    processors=[
        structlog.stdlib.PositionalArgumentsFormatter(),
        structlog.dev.ConsoleRenderer(),
    ],
    context_class=dict,
    logger_factory=structlog.stdlib.LoggerFactory(),
    wrapper_class=structlog.stdlib.BoundLogger,
    cache_logger_on_first_use=True,
)
structlog.get_logger('structlog').warning('Info message', 'x')

Results in:

Traceback (most recent call last):
  File "/Users/rbever/git/sfprime/nde-node-service/scratch.py", line 17, in <module>
    structlog.get_logger('structlog').warning('Info message', 'x')
  File "/Users/rbever/.pyenv/versions/nde-node-service/lib/python3.7/site-packages/structlog/stdlib.py", line 80, in warning
    return self._proxy_to_logger("warning", event, *args, **kw)
  File "/Users/rbever/.pyenv/versions/nde-node-service/lib/python3.7/site-packages/structlog/stdlib.py", line 124, in _proxy_to_logger
    method_name, event=event, **event_kw
  File "/Users/rbever/.pyenv/versions/nde-node-service/lib/python3.7/site-packages/structlog/_base.py", line 189, in _proxy_to_logger
    args, kw = self._process_event(method_name, event, event_kw)
  File "/Users/rbever/.pyenv/versions/nde-node-service/lib/python3.7/site-packages/structlog/_base.py", line 149, in _process_event
    event_dict = proc(self._logger, method_name, event_dict)
  File "/Users/rbever/.pyenv/versions/nde-node-service/lib/python3.7/site-packages/structlog/stdlib.py", line 328, in __call__
    event_dict["event"] = event_dict["event"] % args
TypeError: not all arguments converted during string formatting

Process finished with exit code 1

Which is an uncaught error.

Ideally logging even when misused in this manner wouldn't cause Runtime errors.

@nel-iprv
Copy link

Hi,
Nothing happened regarding to this?

@hynek
Copy link
Owner

hynek commented Mar 10, 2023

Well, I'm a bit conflicted on this one. Sure logging does it, but there's the zen of Python that errors shouldn't pass silently and what logging is doing here is masking an error that can lead to data loss in production because nobody reads warnings.

What exactly is motivation to allow for bugs here? Just because it's logging?

@nel-iprv
Copy link

I do agree that is masking an error and potentially losing logs in production but, while migrating from logging to structlog, these errors which were silent can now break the code - in perfect world everything would be unit tested, agree.

Perhaps a optional flag similar to the logging.raiseExceptions could be used.

@hynek
Copy link
Owner

hynek commented Mar 10, 2023

But… isn’t that a feature that you’re finding those bugs now? You’re basically asking me to tape over an engine warning light.

@ruslaniv
Copy link

Wait a minute, i'm completely lost!
I thought this is exactly how I could use the logger by passing positional arguments, it is actually in the documentation:

log.info("hello, %s!", "world", key="value!", more_than_strings=[1, 2, 3])  

although I do get exactly the same error, when I'm trying to use logger this way:

logger = structlog.get_logger(__name__)
logger.error("Update ticker", ticker.name)
logger.error("Update ticker", ticker.name)
  File ".../site-packages/structlog/_native.py", line 136, in meth
    return self._proxy_to_logger(name, event % args, **kw)
                                       ~~~~~~^~~~~~
TypeError: not all arguments converted during string formatting

What is going on here?

@hynek
Copy link
Owner

hynek commented May 27, 2024

There's a %s in the example and none in yours.

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

No branches or pull requests

4 participants