Documentation
tomodachi

Logging and log formatters

A context aware logger is available from the tomodachi.logging module that can be fetched with tomodachi.logging.get_logger() (or just tomodachi.get_logger() for short).

The logger is a initiated using the popular structlog package, and can be used in the same way as the standard library logger, with a few additional features, such as holding a context and logging of additional values.

The logger returned from tomodachi.get_logger() will hold the context of the current handler task or request for rich contextual log records.

To get a logger with another name than the logger set for the current context, use tomodachi.get_logger(name="my-logger").

Example

from typing import Any

import tomodachi

class Service(tomodachi.Service):  
    name = "service"

    @tomodachi.aws_sns_sqs("test-topic", queue_name="test-queue")
    async def sqs_handler(self, data: Any, topic: str, sns_message_id: str) -> None:
        tomodachi.get_logger().info("received message", topic=topic, sns_message_id=sns_message_id)

The log record will be enriched with the context of the current handler task or request and the output should look something like this if the json formatter is used (note that the example output below has been prettified – the JSON that is actually used outputs the entire log entry on one single line)

{
    "timestamp": "2023-08-13T17:44:09.176295Z",
    "logger": "tomodachi.awssnssqs.handler",
    "level": "info",
    "message": "received message",
    "handler": "sqs_handler",
    "type": "tomodachi.awssnssqs",
    "topic": "test-topic",
    "sns_message_id": "a1eba63e-8772-4b36-b7e0-b2f524f34bff"
}

Interactions with Python's built-in logging module

Note that the log entries are propagated to the standard library logger (as long as it wasn't filtered), in order to allow third party handler hooks to pick up records or act on them. This will make sure that integrations such a Sentry's exception tracing will work out of the box.

Similarly the tomodachi logger will also by default receive records from the standard library logger as adds a logging.root handler, so that the tomodachi logger can be used as a drop-in replacement for the standard library logger. Because of this third party modules using Python's default logging module will use the same formatter as tomodachi. Note that if logging.basicConfig() is called before the tomodachi logger is initialized, tomodachi may not be able to add its logging.root handler.

Note that when using the standard library logger directly the contextual logger won't be selected by default.

Example

import logging

from aiohttp.web import Request, Response  
import tomodachi

class Service(tomodachi.Service):  
    name = "service"

    @tomodachi.http("GET", r"/example")
    async def http_handler(self, request: Request) -> Response:
        # contextual logger
        tomodachi.get_logger().info("http request")

        # these two rows result in similar log records
        logging.getLogger("service.logger").info("with logging module")
        tomodachi.get_logger("service.logger").info("with tomodachi.logging module")

        # extra fields from built in logger ends up as "extra" in log records
        logging.getLogger("service.logger").info("adding extra", extra={"http_request_path": request.path})

        return Response(body="hello world")

A GET request to /example of this service would result in five log records being emitted. The four from the example above and the last one from the tomodachi.transport.http module.

{"timestamp": "2023-08-13T19:25:15.923627Z", "logger": "tomodachi.http.handler", "level": "info", "message": "http request", "handler": "http_handler", "type": "tomodachi.http"}
{"timestamp": "2023-08-13T19:25:15.923894Z", "logger": "service.logger", "level": "info", "message": "with logging module"}
{"timestamp": "2023-08-13T19:25:15.924043Z", "logger": "service.logger", "level": "info", "message": "with tomodachi.logging module"}
{"timestamp": "2023-08-13T19:25:15.924172Z", "logger": "service.logger", "level": "info", "message": "adding extra", "extra": {"http_request_path": "/example"}}
{"timestamp": "2023-08-13T19:25:15.924507Z", "logger": "tomodachi.http.response", "level": "info", "message": "", "status_code": 200, "remote_ip": "127.0.0.1", "request_method": "GET", "request_path": "/example", "http_version": "HTTP/1.1", "response_content_length": 11, "user_agent": "curl/7.88.1", "handler_elapsed_time": "0.00135s", "request_time": "0.00143s"}

Configuring the logger

Start the service using the --logger json arguments (or setting TOMODACHI_LOGGER=json environment value) to change the log formatter to use the json log formatter. The default log formatter console is mostly suited for local development environments as it provides a structured and colorized view of log records.

It's also possible to use your own logger implementation by specifying --custom-logger ... (or setting TOMODACHI_CUSTOM_LOGGER=... environment value).

Read more about how to start the service with another formatter or implementation in the usage section on "Running a service".


Related sections