Skip to content

Add logger to the Python ASGI module#6186

Open
ryanking13 wants to merge 1 commit intomainfrom
gyeongjae/asgi-logging-error
Open

Add logger to the Python ASGI module#6186
ryanking13 wants to merge 1 commit intomainfrom
gyeongjae/asgi-logging-error

Conversation

@ryanking13
Copy link
Contributor

Adds logger to the Python ASGI module, users can overwrite the logger behavior by

logger = logging.getLogger("asgi")
do_something_with_logger(logger)

before this change, all the errors were not showed to the user at all, while after this change, errors are caught and showed to stderr.

For example, the bug reported in https://discord.com/channels/595317990191398933/1224715939581530112/1473759889582194758 which showed nothing now shows

⎔ Starting local server...
[wrangler:info] Ready on http://0.0.0.0:8787
[wrangler:info] - http://127.0.0.1:8787
[wrangler:info] - http://172.17.0.2:8787
✘ [ERROR] Exception in ASGI application after response started
✘ [ERROR] Traceback (most recent call last):
✘ [ERROR]   File "/lib/python3.13/site-packages/asgi.py", line 208, in run_app
✘ [ERROR]     await app(request_to_scope(req, env), receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/fastapi/applications.py", line 1160, in __call__
✘ [ERROR]     await super().__call__(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/applications.py", line 107, in __call__
✘ [ERROR]     await self.middleware_stack(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/middleware/errors.py", line 186, in __call__
✘ [ERROR]     raise exc
✘ [ERROR]   File "/session/metadata/python_modules/starlette/middleware/errors.py", line 164, in __call__
✘ [ERROR]     await self.app(scope, receive, _send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/middleware/exceptions.py", line 63, in __call__
✘ [ERROR]     await wrap_app_handling_exceptions(self.app, conn)(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/_exception_handler.py", line 53, in wrapped_app
✘ [ERROR]     raise exc
✘ [ERROR]   File "/session/metadata/python_modules/starlette/_exception_handler.py", line 42, in wrapped_app
✘ [ERROR]     await app(scope, receive, sender)
✘ [ERROR]   File "/session/metadata/python_modules/fastapi/middleware/asyncexitstack.py", line 18, in __call__
✘ [ERROR]     await self.app(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/routing.py", line 716, in __call__
✘ [ERROR]     await self.middleware_stack(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/routing.py", line 736, in app
✘ [ERROR]     await route.handle(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/routing.py", line 290, in handle
✘ [ERROR]     await self.app(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/fastapi/routing.py", line 119, in app
✘ [ERROR]     await wrap_app_handling_exceptions(app, request)(scope, receive, send)
✘ [ERROR]   File "/session/metadata/python_modules/starlette/_exception_handler.py", line 53, in wrapped_app
✘ [ERROR]     raise exc
✘ [ERROR]   File "/session/metadata/python_modules/starlette/_exception_handler.py", line 42, in wrapped_app
✘ [ERROR]     await app(scope, receive, sender)
✘ [ERROR]   File "/session/metadata/python_modules/fastapi/routing.py", line 105, in app
✘ [ERROR]     response = await f(request)
✘ [ERROR]                ^^^^^^^^^^^^^^^^
✘ [ERROR]   File "/session/metadata/python_modules/fastapi/routing.py", line 431, in app
✘ [ERROR]     raw_response = await run_endpoint_function(
✘ [ERROR]                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
✘ [ERROR]     ...<3 lines>...
✘ [ERROR]     )
✘ [ERROR]     ^
✘ [ERROR]   File "/session/metadata/python_modules/fastapi/routing.py", line 315, in run_endpoint_function
✘ [ERROR]     return await run_in_threadpool(dependant.call, **values)
✘ [ERROR]            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
✘ [ERROR]   File "/session/metadata/python_modules/starlette/concurrency.py", line 32, in run_in_threadpool
✘ [ERROR]     return await anyio.to_thread.run_sync(func)
✘ [ERROR]            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
✘ [ERROR]   File "/session/metadata/python_modules/anyio/to_thread.py", line 63, in run_sync
✘ [ERROR]     return await get_async_backend().run_sync_in_worker_thread(
✘ [ERROR]            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
✘ [ERROR]         func, args, abandon_on_cancel=abandon_on_cancel, limiter=limiter
✘ [ERROR]         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
✘ [ERROR]     )
✘ [ERROR]     ^
✘ [ERROR]   File "/session/metadata/python_modules/anyio/_backends/_asyncio.py", line 2470, in run_sync_in_worker_thread
✘ [ERROR]     worker.start()
✘ [ERROR]     ~~~~~~~~~~~~^^
✘ [ERROR]   File "/lib/python313.zip/threading.py", line 973, in start
✘ [ERROR]     _start_joinable_thread(self._bootstrap, handle=self._handle,
✘ [ERROR]     ~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
✘ [ERROR]                            daemon=self.daemon)
✘ [ERROR]                            ^^^^^^^^^^^^^^^^^^^
✘ [ERROR] RuntimeError: can't start new thread
[wrangler:info] GET / 500 Internal Server Error (4678ms)

which helps us to debug the issue.

@ryanking13 ryanking13 requested review from a team as code owners February 26, 2026 04:22
Copy link
Contributor

@ask-bonk ask-bonk bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm Bonk, and I've done a quick review of your PR.

Adds a Python logging logger to the ASGI module so errors are surfaced to stderr instead of silently swallowed.

Issues

  1. Bug — logger.exception() in done callback loses traceback (asgi.py:24): logger.exception() relies on sys.exc_info() to capture the traceback, but future done callbacks execute outside any except block, so sys.exc_info() returns (None, None, None). The exception type and traceback are silently dropped. Use logger.error(..., exc_info=exc) to pass the exception object directly — Python's logging will extract the traceback from it.

  2. Bug — two test assertions will fail (worker.py:175-176, worker.py:203-204): r.getMessage() only returns the formatted message string (e.g. "Unhandled exception in background task"), not the exception text. The tests check for the exception's message (e.g. "post-response error for testing") inside getMessage(), which will never match. The assertions need to inspect r.exc_info or use r.exc_text / format the full record instead.

@ask-bonk
Copy link
Contributor

ask-bonk bot commented Feb 26, 2026

I'm Bonk, and I've done a quick review of your PR.

Adds a Python logging logger to the ASGI module so errors are surfaced to stderr instead of silently swallowed.

Issues found

  1. Bug — logger.exception() in done callback loses traceback (asgi.py:24): logger.exception() relies on sys.exc_info() to get the traceback, but future done callbacks run outside an except block, so sys.exc_info() is always (None, None, None). The fix is logger.error("...", exc_info=exc).

  2. Bug — two test assertions will never match (worker.py:175-176, worker.py:203-204): r.getMessage() returns only the log message string, not the exception text. The tests check for the exception's message inside getMessage(), which won't contain it. They need to inspect r.exc_info instead.

All three issues have concrete suggestion comments posted on the PR.

github run

@ryanking13 ryanking13 force-pushed the gyeongjae/asgi-logging-error branch from e833768 to 045fa61 Compare February 26, 2026 04:32
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant