Skip to content

Add logger to the Python ASGI module - #6186

Merged
ryanking13 merged 1 commit into
mainfrom
gyeongjae/asgi-logging-error
Mar 3, 2026
Merged

ryanking13 merged 1 commit into
mainfrom
gyeongjae/asgi-logging-error

Conversation

@ryanking13

Copy link
Copy Markdown
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

@ask-bonk ask-bonk Bot left a comment

Copy link
Copy Markdown
Contributor

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.

Comment thread src/pyodide/internal/workers-api/src/asgi.py Outdated
Comment thread src/workerd/server/tests/python/asgi/worker.py Outdated
Comment thread src/workerd/server/tests/python/asgi/worker.py Outdated
@ask-bonk

ask-bonk Bot commented Feb 26, 2026

Copy link
Copy Markdown
Contributor

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

@dom96 dom96 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Nice! Awesome QoL improvement, thanks!

@ryanking13
ryanking13 force-pushed the gyeongjae/asgi-logging-error branch from 045fa61 to bb060a5 Compare March 3, 2026 05:30
@codecov-commenter

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 70.70%. Comparing base (58a384f) to head (bb060a5).

Additional details and impacted files
@@            Coverage Diff             @@
##             main    #6186      +/-   ##
==========================================
- Coverage   70.71%   70.70%   -0.02%     
==========================================
  Files         417      417              
  Lines      111059   111059              
  Branches    18340    18340              
==========================================
- Hits        78539    78523      -16     
- Misses      21569    21584      +15     
- Partials    10951    10952       +1     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@ryanking13
ryanking13 enabled auto-merge March 3, 2026 07:58
@ryanking13
ryanking13 merged commit c1ba467 into main Mar 3, 2026
44 of 48 checks passed
@ryanking13
ryanking13 deleted the gyeongjae/asgi-logging-error branch March 3, 2026 08:51
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.

3 participants