KeyError: "Attempt to overwrite 'filename' in LogRecord"

[luqasz]

This is what I am using. Gunicorn + uvicorn app.

elog = structlog.get_logger("gunicorn.error", )
alog = structlog.get_logger("gunicorn.error", )


class GunicornLogger:

    def __init__(self, cfg):
        self.cfg = cfg
        self.error_log = elog.bind()
        self.access_log = alog.bind()
        logging.getLogger().setLevel(logging.DEBUG) # bit hacky but only required to emit logs

    def debug(self, msg, *args, **kwargs) -> None:
        self.error_log.debug(msg, *args, **kwargs)

Traceback (most recent call last):
  File "/usr/local/bin/gunicorn", line 8, in <module>
    sys.exit(run())
  File "/usr/local/lib/python3.10/site-packages/gunicorn/app/wsgiapp.py", line 67, in run
    WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]").run()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/app/base.py", line 231, in run
    super().run()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/app/base.py", line 72, in run
    Arbiter(self).run()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 58, in __init__
    self.setup(app)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 105, in setup
    self.log.debug('Current configuration:\n{0}'.format(
  File "/app/src/myapp/logs.py", line 80, in debug
    self.error_log.debug(msg, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/structlog/stdlib.py", line 180, in debug
    return self._proxy_to_logger("debug", event, *args, **kw)
  File "/usr/local/lib/python3.10/site-packages/structlog/stdlib.py", line 247, in _proxy_to_logger
    return super()._proxy_to_logger(method_name, event=event, **event_kw)
  File "/usr/local/lib/python3.10/site-packages/structlog/_base.py", line 206, in _proxy_to_logger
    return getattr(self._logger, method_name)(*args, **kw)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1465, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1622, in _log
    record = self.makeRecord(self.name, level, fn, lno, msg, args,
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1596, in makeRecord
    raise KeyError("Attempt to overwrite %r in LogRecord" % key)
KeyError: "Attempt to overwrite 'filename' in LogRecord"

processors = [
    structlog.contextvars.merge_contextvars,
    # If log level is too low, abort pipeline and throw away log entry.
    structlog.stdlib.filter_by_level,
    # Add the name of the logger to event dict.
    structlog.stdlib.add_logger_name,
    # Add log level to event dict.
    structlog.stdlib.add_log_level,
    # Perform %-style formatting.
    structlog.stdlib.PositionalArgumentsFormatter(),
    # Add a timestamp in ISO 8601 format.
    structlog.processors.TimeStamper(fmt="iso"),
    # If the "stack_info" key in the event dict is true, remove it and
    # render the current stack trace in the "stack" key.
    structlog.processors.StackInfoRenderer(),
    # add exception frame as dict
    # structlog.processors.dict_tracebacks,
    # If the "exc_info" key in the event dict is either true or a
    # sys.exc_info() tuple, remove "exc_info" and render the exception
    # with traceback into the "exception" key.
    structlog.processors.format_exc_info,
    structlog.processors.ExceptionRenderer(),
    # Add callsite parameters.
    structlog.processors.CallsiteParameterAdder({
        structlog.processors.CallsiteParameter.FILENAME,
        structlog.processors.CallsiteParameter.FUNC_NAME,
        structlog.processors.CallsiteParameter.LINENO,
    }),
    # structlog.processors.JSONRenderer(),
    structlog.stdlib.render_to_log_kwargs,
]

structlog.configure(
    processors=processors,
    # `wrapper_class` is the bound logger that you get back from
    # get_logger(). This one imitates the API of `logging.Logger`.
    wrapper_class=structlog.stdlib.BoundLogger,
    # `logger_factory` is used to create wrapped loggers that are used for
    # OUTPUT. This one returns a `logging.Logger`. The final value (a JSON
    # string) from the final processor (`JSONRenderer`) will be passed to
    # the method of the same name as that you've called on the bound logger.
    logger_factory=structlog.stdlib.LoggerFactory(),
    # Effectively freeze configuration after creating the first bound
    # logger.
    cache_logger_on_first_use=True,
)

[hynek]

That's interesting – looks like it's illegal to set a callsite parameter twice:

    def makeRecord(self, name, level, fn, lno, msg, args, exc_info,
                   func=None, extra=None, sinfo=None):
        """
        A factory method which can be overridden in subclasses to create
        specialized LogRecords.
        """
        rv = _logRecordFactory(name, level, fn, lno, msg, args, exc_info, func,
                             sinfo)
        if extra is not None:
            for key in extra:
                if (key in ["message", "asctime"]) or (key in rv.__dict__):
                    raise KeyError("Attempt to overwrite %r in LogRecord" % key)
                rv.__dict__[key] = extra[key]
        return rv