Debugging tools#

This describes what is currently in place in TeaL applications to allow easier debugging of them and their usage by other applications.

Unit tests#

To run the unit tests, you can use make test. This will automatically use poetry, print the coverage on the console, as well as generate an htmlcov directory and echo a link to it in the console, which you can directly click to access the coverage report.

$ make test
> pytest --cov
=============================================== test session starts ================================================
platform linux -- Python 3.11.4, pytest-7.4.2, pluggy-1.3.0
rootdir: /home/thomas/teal
configfile: pyproject.toml
plugins: mock-3.11.1, cov-4.1.0, timeout-2.1.0, redis-3.0.2, asyncio-0.20.3, anyio-4.0.0, rabbitmq-3.0.2
asyncio: mode=Mode.STRICT
collected 125 items

tests/test_amq.py ...........                                                                                [  8%]
tests/test_logging.py .....                                                                                  [ 12%]
tests/test_redis.py .........                                                                                [ 20%]
tests/web_listener/test_asgi.py ..........................................                                   [ 53%]
tests/web_listener/test_asgi_with_powens_fallback.py ......                                                  [ 58%]
tests/web_listener/test_utils.py .......................................                                     [ 89%]
tests/websocket_dispatcher/test_asgi.py .............                                                        [100%]

---------- coverage: platform linux, python 3.11.4-final-0 -----------
Name                                    Stmts   Miss  Cover
-----------------------------------------------------------
teal/__init__.py                            3      0   100%
teal/amq.py                               168      0   100%
teal/logging.py                            54      1    98%
teal/redis.py                              44      0   100%
teal/web_listener/__init__.py               4      0   100%
teal/web_listener/asgi.py                 108      0   100%
teal/web_listener/config.py                 9      0   100%
teal/web_listener/exceptions.py            45      0   100%
teal/web_listener/utils.py                287      0   100%
teal/websocket_dispatcher/__init__.py       4      0   100%
teal/websocket_dispatcher/asgi.py          78      0   100%
teal/websocket_dispatcher/config.py        18      0   100%
teal/websocket_dispatcher/protocol.py      82      0   100%
teal/websocket_dispatcher/utils.py        110      0   100%
-----------------------------------------------------------
TOTAL                                    1014      1    99%
Coverage HTML written to dir htmlcov


========================================== 125 passed in 81.02s (0:01:21) ==========================================
> HTML coverage is available under the following directory:
> file:///home/thomas/teal/htmlcov/index.html

Development Docker images#

While developing on TeaL, it is recommended you use the docker/docker-compose-dev.yml Compose file instead of the production equivalent one. It brings the following:

  • The teal directory is mounted from the host instead of copied; this allows testing changes without having to rebuild the Docker images.

  • The log level for the teal namespace is set to DEBUG instead of INFO.

  • The gunicorn –reload option is enabled; although this can be flaky, prefer restarting your Docker containers altogether.

Correlation through the X-Request-ID header#

For every request made to any TeaL application, an X-Request-ID header is emitted in the response. For example:

$ curl "http://localhost:8080/callback?state=123" -i
HTTP/1.1 204 No Content
date: Sat, 09 Sep 2023 14:34:50 GMT
server: uvicorn
x-request-id: f7169664-16c7-49fc-bbfb-3f4d080d085b

The value of this header is also placed in the logs directly related to the processing of this request, through the request_id property:

{
    "module": "redis",
    "name": "teal.redis",
    "funcName": "get_stored_state",
    "lineno": 113,
    "message": "Callback data was found for state \"123\", will expire on 2023-09-15T12:50:36.",
    "request_id": "f7169664-16c7-49fc-bbfb-3f4d080d085b",
    "time": "2023-09-09T14:34:50",
    "level": "INFO"
}

{
    "module": "asgi",
    "name": "teal.web_listener.asgi",
    "funcName": "get_callback",
    "lineno": 183,
    "message": "Stopping redirection here.",
    "request_id": "f7169664-16c7-49fc-bbfb-3f4d080d085b",
    "time": "2023-09-09T14:34:50",
    "level": "INFO"
}

{
    "module": "amq",
    "name": "teal.amq",
    "funcName": "send",
    "lineno": 359,
    "message": "Sending message to routing key '123' on exchange \"AMQExchangeName.CALLBACKS\" with body b'{\"timestamp\":\"2023-09-09T14:34:50.430827\",\"url\":\"http://localhost:8080/callback?state=123\",\"state\":\"123\"}'",
    "request_id": "f7169664-16c7-49fc-bbfb-3f4d080d085b",
    "time": "2023-09-09T14:34:50",
    "level": "INFO"
}

It is also possible to control the value of this header by sending an X-Request-ID header with the desired value, which will also be included in the logs:

$ curl "http://localhost:8080/callback?state=123" -H 'X-Request-ID: My-Request-ID' -i
HTTP/1.1 204 No Content
date: Sat, 09 Sep 2023 14:40:20 GMT
server: uvicorn
x-request-id: My-Request-ID