Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: event handler error breaks stream #2810

Merged
merged 1 commit into from
Dec 1, 2023

Conversation

peterschutt
Copy link
Contributor

Pull Request Checklist

  • New code has 100% test coverage
  • (If applicable) The prose documentation has been updated to reflect the changes introduced by this PR
  • (If applicable) The reference documentation has been updated to reflect the changes introduced by this PR
  • Pre-Commit Checks were ran and passed
  • Tests were ran and passed

Description

This PR prevents exceptions raised from within event handlers from closing the event receive stream, and from further propagation beyond the event emitter backend.

When an exception is caught from an event handler, we log it at ERROR level.

Close Issue(s)

Closes #2809

@peterschutt peterschutt requested review from a team as code owners November 30, 2023 23:08
@peterschutt
Copy link
Contributor Author

peterschutt commented Nov 30, 2023

Before this PR, the request that triggers the error event returns OK, then we get a weird asgi message, and on next request that emits an event we get a 500 error:

INFO:     127.0.0.1:44188 - "GET /check-value/3 HTTP/1.1" 200 OK
INFO:     ASGI 'lifespan' protocol appears unsupported.
ERROR - 2023-12-01 09:09:25,746 - litestar - config - exception raised on http connection to route /check-value/2

Traceback (most recent call last):
  File "/home/peter/PycharmProjects/litestar/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 81, in handle
    response = await self._get_response_for_request(
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 133, in _get_response_for_request
    return await self._call_handler_function(
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 153, in _call_handler_function
    response_data, cleanup_group = await self._get_response_data(
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 201, in _get_response_data
    data = await route_handler.fn(**parsed_kwargs)
  File "/home/peter/PycharmProjects/litestar-hello-world/app.py", line 23, in check_value
    request.app.emit("raise_exception", value)
  File "/home/peter/PycharmProjects/litestar/litestar/app.py", line 875, in emit
    self.event_emitter.emit(event_id, *args, **kwargs)
  File "/home/peter/PycharmProjects/litestar/litestar/events/emitter.py", line 134, in emit
    self._send_stream.send_nowait((listener.fn, args, kwargs))
  File "/home/peter/.local/share/pdm/venvs/litestar-hello-world-qe1MW6VZ-3.8/lib/python3.8/site-packages/anyio/streams/memory.py", line 189, in send_nowait
    raise ClosedResourceError
anyio.ClosedResourceError
Traceback (most recent call last):
  File "/home/peter/PycharmProjects/litestar/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 81, in handle
    response = await self._get_response_for_request(
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 133, in _get_response_for_request
    return await self._call_handler_function(
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 153, in _call_handler_function
    response_data, cleanup_group = await self._get_response_data(
  File "/home/peter/PycharmProjects/litestar/litestar/routes/http.py", line 201, in _get_response_data
    data = await route_handler.fn(**parsed_kwargs)
  File "/home/peter/PycharmProjects/litestar-hello-world/app.py", line 23, in check_value
    request.app.emit("raise_exception", value)
  File "/home/peter/PycharmProjects/litestar/litestar/app.py", line 875, in emit
    self.event_emitter.emit(event_id, *args, **kwargs)
  File "/home/peter/PycharmProjects/litestar/litestar/events/emitter.py", line 134, in emit
    self._send_stream.send_nowait((listener.fn, args, kwargs))
  File "/home/peter/.local/share/pdm/venvs/litestar-hello-world-qe1MW6VZ-3.8/lib/python3.8/site-packages/anyio/streams/memory.py", line 189, in send_nowait
    raise ClosedResourceError
anyio.ClosedResourceError
INFO:     127.0.0.1:50308 - "GET /check-value/2 HTTP/1.1" 500 Internal Server Error

After this PR the exception is caught and logged, and the next event emitting request succeeds:

INFO:     127.0.0.1:54846 - "GET /check-value/3 HTTP/1.1" 200 OK
ERROR - 2023-12-01 09:11:27,768 - litestar.events.emitter - emitter - Error in event listener: unhandled errors in a TaskGroup (1 sub-exception)
  + Exception Group Traceback (most recent call last):
  |   File "/home/peter/PycharmProjects/litestar/litestar/events/emitter.py", line 96, in _worker
  |     task_group.start_soon(fn, *args)
  |   File "/home/peter/.local/share/pdm/venvs/litestar-hello-world-qe1MW6VZ-3.8/lib/python3.8/site-packages/anyio/_backends/_asyncio.py", line 664, in __aexit__
  |     raise BaseExceptionGroup(
  | exceptiongroup.ExceptionGroup: unhandled errors in a TaskGroup (1 sub-exception)
  +-+---------------- 1 ----------------
    | Traceback (most recent call last):
    |   File "/home/peter/PycharmProjects/litestar-hello-world/app.py", line 12, in raise_exception_if_odd
    |     raise ValueError(f"{value} is odd")
    | ValueError: 3 is odd
    +------------------------------------
INFO:     127.0.0.1:54846 - "GET /check-value/2 HTTP/1.1" 200 OK

@peterschutt peterschutt force-pushed the 2809-catch-event-listener-exceptions branch 2 times, most recently from a9d4b2f to 46c1f40 Compare November 30, 2023 23:32
@peterschutt peterschutt force-pushed the 2809-catch-event-listener-exceptions branch from 46c1f40 to 8e77858 Compare November 30, 2023 23:42
@peterschutt peterschutt added the Bug 🐛 This is something that is not working as expected label Nov 30, 2023
This PR prevents exceptions raised from within event handlers from closing the event receive stream, and from further propagation beyond the event emitter backend.

When an exception is caught from an event handler, we log it at ERROR level.

Closes #2809
@peterschutt peterschutt force-pushed the 2809-catch-event-listener-exceptions branch from 8e77858 to d0dbdc5 Compare December 1, 2023 00:21
Copy link

sonarcloud bot commented Dec 1, 2023

Kudos, SonarCloud Quality Gate passed!    Quality Gate passed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 1 Code Smell

100.0% 100.0% Coverage
0.0% 0.0% Duplication

Copy link

github-actions bot commented Dec 1, 2023

Documentation preview will be available shortly at https://litestar-org.github.io/litestar-docs-preview/2810

@peterschutt peterschutt merged commit 1cfde0c into main Dec 1, 2023
17 checks passed
@peterschutt peterschutt deleted the 2809-catch-event-listener-exceptions branch December 1, 2023 04:42
await self._run_listener_in_task_group(*item)

@staticmethod
async def _run_listener_in_task_group(fn: Any, args: tuple[Any], kwargs: dict[str, Any]) -> None:
Copy link
Member

Choose a reason for hiding this comment

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

This solution is a bit of an issue unfortunately, as creating a new task group for every received item will prevent them running concurrently. I think the proper fix here would be to wrap the listeners in an exception handler and then run those in the task group

Copy link
Member

Choose a reason for hiding this comment

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

@peterschutt I can cook up a PR for this later unless you want to fix it :)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

OK, I'll leave it to you - thanks.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Actually, I got it - my mess, I'll clean it up.

peterschutt added a commit that referenced this pull request Dec 1, 2023
This PR corrects an implementation made in #2810 that prevented listeners from running concurrently.

For #2809
provinzkraut pushed a commit that referenced this pull request Dec 1, 2023
This PR corrects an implementation made in #2810 that prevented listeners from running concurrently.

For #2809
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug 🐛 This is something that is not working as expected
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Bug: Exception in event listener breaks listener
4 participants