tintoy / seqlog

Python logging integration for Seq (https://getseq.net)
https://seqlog.readthedocs.io/
MIT License
17 stars 11 forks source link

How to integrate seqlog into fastapi app? #31

Closed maxhermann closed 1 year ago

maxhermann commented 4 years ago

Description

I would like to integrate seq into a fastapi application. I could send messages via logging.info(..) to SEQ within my own code but if uvicorn tries to log something i got an error. Can someone post an example? What im doing wrong?

What I Did

Im using this configuration .yml:

# This is the Python logging schema version (currently, only the value 1 is supported here).
version: 1

# Configure logging from scratch.
disable_existing_loggers: True

# Configure the root logger to use Seq
root:
  level: INFO
  handlers:
  - seq
  - console

# You can also configure non-root loggers.
loggers:
  another_logger:
      propagate: True
      level: INFO
      handlers:
      - seq
      - console

handlers:
# Log to STDOUT
  console:
    class: seqlog.structured_logging.ConsoleStructuredLogHandler
    formatter: seq

# Log to Seq
  seq:
    class: seqlog.structured_logging.SeqLogHandler
    formatter: seq

    # Seq-specific settings (add any others you need, they're just kwargs for SeqLogHandler's constructor).
    server_url: 'http://localhost:5341'
    api_key: 'your_api_key_if_you_have_one'

    # Use a custom JSON encoder, if you need to.
    json_encoder_class: json.encoder.JSONEncoder

formatters:
  seq:
    style: '{'

And calling seqlog within main.py like:

    seqlog.configure_from_file('logging.yml')

    # Use the root logger.
    root_logger = logging.getLogger()
    root_logger.info('This is the root logger.')

    # Use another logger
    another_logger = logging.getLogger('another_logger')
    another_logger.info('This is another logger.')

I do recieve both messages in SEQ. This works pretty fine.

But sending a GET Request (/engine/api/v1/openapi.json) to an defined endpoint results in this error message:

--- Logging error ---
Traceback (most recent call last):
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\logging\__init__.py", line 1025, in emit
    msg = self.format(record)
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\logging\__init__.py", line 869, in format
    return fmt.format(record)
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\logging\__init__.py", line 611, in format
    s = self.formatMessage(record)
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\logging.py", line 111, in formatMessage
    scope = recordcopy.__dict__["scope"]
KeyError: 'scope'
Call stack:
  File "C:/files/Repositories/***/server/main.py", line 68, in <module>
    uvicorn.run(app, host=configuration.HOST_ADDRESS, port=configuration.HOST_PORT)
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\main.py", line 391, in run
    server.run()
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\main.py", line 419, in run
    loop.run_until_complete(self.serve(sockets=sockets))
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\asyncio\base_events.py", line 574, in run_until_complete
    self.run_forever()
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\asyncio\base_events.py", line 541, in run_forever
    self._run_once()
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\asyncio\base_events.py", line 1786, in _run_once
    handle._run()
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\asyncio\events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\protocols\http\h11_impl.py", line 389, in run_asgi
    result = await app(self.scope, self.receive, self.send)
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\middleware\proxy_headers.py", line 45, in __call__
    return await self.app(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\middleware\message_logger.py", line 61, in __call__
    await self.app(scope, inner_receive, inner_send)
  File "C:\files\Repositories\***\venv\lib\site-packages\fastapi\applications.py", line 179, in __call__
    await super().__call__(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\applications.py", line 111, in __call__
    await self.middleware_stack(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\middleware\errors.py", line 159, in __call__
    await self.app(scope, receive, _send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\middleware\cors.py", line 78, in __call__
    await self.app(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\exceptions.py", line 71, in __call__
    await self.app(scope, receive, sender)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\routing.py", line 566, in __call__
    await route.handle(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\routing.py", line 376, in handle
    await self.app(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\fastapi\applications.py", line 179, in __call__
    await super().__call__(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\applications.py", line 111, in __call__
    await self.middleware_stack(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\middleware\errors.py", line 159, in __call__
    await self.app(scope, receive, _send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\exceptions.py", line 71, in __call__
    await self.app(scope, receive, sender)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\routing.py", line 566, in __call__
    await route.handle(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\routing.py", line 227, in handle
    await self.app(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\routing.py", line 44, in app
    await response(scope, receive, send)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\responses.py", line 136, in __call__
    "headers": self.raw_headers,
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\exceptions.py", line 68, in sender
    await send(message)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\middleware\errors.py", line 156, in _send
    await send(message)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\exceptions.py", line 68, in sender
    await send(message)
  File "C:\files\Repositories\***\venv\lib\site-packages\starlette\middleware\errors.py", line 156, in _send
    await send(message)
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\middleware\message_logger.py", line 55, in inner_send
    await send(message)
  File "C:\files\Repositories\***\venv\lib\site-packages\uvicorn\protocols\http\h11_impl.py", line 458, in send
    extra={"status_code": status_code, "scope": self.scope},
  File "C:\Users\***\AppData\Local\Programs\Python\Python37\lib\logging\__init__.py", line 1378, in info
    self._log(INFO, msg, args, **kwargs)
  File "C:\files\Repositories\***\venv\lib\site-packages\seqlog\structured_logging.py", line 189, in _log
    super()._log(level, msg, args, exc_info, extra, stack_info)
Message: '%s - "%s %s HTTP/%s" %d'
Arguments: ('127.0.0.1:62841', 'GET', '/engine/api/v1/openapi.json', '1.1', 200)
Vacant0mens commented 1 year ago

This seems to be an issue with the uvicorn package's implementation of logging rather than an issue with the seqlog module.

The initial Traceback block shows that it's uvicorn\logging.py, line 111, in formatMessage that threw the error, not the structured_logging.py module.

Also, checking the uvicorn repo, it looks like they already fixed the bug that caused your issue since you opened your issue, so it'd be worth trying again with a newer version now, if you can.