Skip to content

Error logging.info() using runserver #576

@glmartinez01

Description

@glmartinez01

Description

Running Daphne v4.2.1. Getting this trace error stack when calling logging.info() (Only on runserver not asgi)

File "/app/.venv/lib/python3.13/site-packages/daphne/management/commands/runserver.py", line 181, in log_action
    logger.info(self.style.HTTP_SUCCESS(msg), details)
Message: '\x1b[mHTTP %(method)s %(path)s %(status)s [%(time_taken).2f, %(client)s]\x1b[0m'
Arguments: ('path', 'status', 'method', 'client', 'time_taken', 'size')
--- Logging error ---
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/logging/handlers.py", line 79, in emit
    if self.shouldRollover(record):
       ~~~~~~~~~~~~~~~~~~~^^^^^^^^
  File "/usr/local/lib/python3.13/logging/handlers.py", line 203, in shouldRollover
    msg = "%s\n" % self.format(record)
                   ~~~~~~~~~~~^^^^^^^^
  File "/usr/local/lib/python3.13/logging/__init__.py", line 999, in format
    return fmt.format(record)
           ~~~~~~~~~~^^^^^^^^
  File "/usr/local/lib/python3.13/logging/__init__.py", line 712, in format
    record.message = record.getMessage()
                     ~~~~~~~~~~~~~~~~~^^
  File "/usr/local/lib/python3.13/logging/__init__.py", line 400, in getMessage
    msg = msg % self.args
          ~~~~^~~~~~~~~~~
TypeError: format requires a mapping
Call stack:
  File "/usr/local/lib/python3.13/threading.py", line 1014, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.13/threading.py", line 1043, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.13/threading.py", line 994, in run
    self._target(*self._args, **self._kwargs)
  File "/app/.venv/lib/python3.13/site-packages/django/utils/autoreload.py", line 64, in wrapper
    fn(*args, **kwargs)
  File "/app/.venv/lib/python3.13/site-packages/daphne/management/commands/runserver.py", line 148, in inner_run
    ).run()
  ...
    logger.info(self.style.HTTP_SUCCESS(msg), details)
Message: '\x1b[mHTTP %(method)s %(path)s %(status)s [%(time_taken).2f, %(client)s]\x1b[0m'
Arguments: ('path', 'status', 'method', 'client', 'time_taken', 'size')

Loggers @ settings.py

"loggers": {
        "django": {
            "handlers": ["console", "file"],
            "level": config("DJANGO_LOG_LEVEL", default="INFO"),
            "propagate": False,
        },
        "src": {
            "handlers": ["console", "file"],
            "level": config("APP_LOG_LEVEL", default="INFO"),
            "propagate": False,
        },
        "daphne": {
            "handlers": ["console"],
            "level": "DEBUG",
            "propagate": False,
        }

Installed Apps & ASGI_APPLICATION

As mentioned by the docs @ https://docs.djangoproject.com/en/5.2/howto/deployment/asgi/daphne/

INSTALLED_APPS = [
    # Unfold admin theme (must be before django.contrib.admin)
    "daphne"
...]
ASGI_APPLICATION = "src.asgi.application"

Possible Explanation

Python's logger.info(msg, *args) expects to use *args for lazy logging formatting, not as a dictionary.

management/commands/runserver.py (lines 176-194)

  msg = "HTTP %(method)s %(path)s %(status)s [%(time_taken).2f, %(client)s]"

  # Utilize terminal colors, if available
  if 200 <= details["status"] < 300:
      # Put 2XX first, since it should be the common case
      logger.info(self.style.HTTP_SUCCESS(msg), details)  # <-- Error: details is being sent as second arg without previous formatting.
  elif 100 <= details["status"] < 200:
      logger.info(self.style.HTTP_INFO(msg), details)

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions