Request processing logging

[florimondmanca]

Is your feature request related to a problem? Please describe.

When debugging, understanding why the request is not behaving properly can be difficult. As a framework developer, I often find myself printing my way through. I think this also affects framework users.

Describe the solution you'd like

Log information about what a request goes through while being processed, eg:

• Middleware classes
• Route (and the list of unmatched routes until we got to this one?)
• Route parameters
• Query parameters
• Providers
• Error handlers
• (Anything else?)

Users should be able to turn these on via an environment variable, eg DEBUG=middleware,routing,views,providers. Show all info with DEBUG=all.

Describe alternatives you've considered

• Let users turn on/off the loggers via the logging module: not impossible, but not sure this is the most user friendly approach. Depending on the implementation, see if we can allow this for advanced use cases.
• Not sure yet if the DEBUG env var would conflict with other tools picking up on it (eg uvicorn).

Implementation ideas

TBD

Additional context

/

[florimondmanca]

Hmm, okay, so uvicorn already provides a bunch of useful ASGI information when passing --log-level=debug, e.g.:

DEBUG: ('127.0.0.1', 50854) - Connected
DEBUG: ('127.0.0.1', 50854) - ASGI [2] Started
DEBUG: [Bocadillo] New request: {"type": "http", "path": "/", "root_path": ""}
DEBUG: ('127.0.0.1', 50854) - ASGI [2] Received {'type': 'http.response.start', 'status': 200, 'headers': '<...>'}
INFO: ('127.0.0.1', 50854) - "GET / HTTP/1.1" 200
DEBUG: ('127.0.0.1', 50854) - ASGI [2] Received {'type': 'http.response.body', 'body': '<298 bytes>'}
DEBUG: ('127.0.0.1', 50854) - ASGI [2] Completed
DEBUG: ('127.0.0.1', 50854) - Disconnected

This is a first level of debug information. And then I'm not sure whether we really want to provide as much information as listed in the issue.

Closing this for now…