search

twisted / twisted

Event-driven networking engine written in Python.
https://twisted.org
Other
5.6k stars 1.18k forks source link

Exception in AsyncioSelectorReactor: `RuntimeError: this event loop is already running.` #12006

Open ThinksFast opened 1 year ago

ThinksFast commented 1 year ago

Describe the incorrect behavior you saw I am running Scrapy inside an ASGI framework called Litestar and using Uvicorn as the server. Scrapy is built on top of Twisted.

When I run a scrapy crawler from inside Litestar, I get the following exception: 

  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/twisted/internet/asyncioreactor.py", line 255, in run
    self._asyncioEventloop.run_forever()
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 518, in uvloop.loop.Loop._run
RuntimeError: this event loop is already running.

I verified scrapy is correctly passing twisted the same instance of the event loop created by Uvicorn. In this case, it's uvloop, although I tried the standard asyncio loop with uvicorn and got the same result.

The line of code causing this exception is self._asyncioEventloop.run_forever(), in the AsyncioSelectorReactor run() function. Commenting it out kills the exception and the scrapy crawl runs without issue.

def run(self, installSignalHandlers=True):
    self.startRunning(installSignalHandlers=installSignalHandlers)
    self._asyncioEventloop.run_forever()
    if self._justStopped:
        self._justStopped = False

There is also an issue on shutdown, but I haven't investigated this yet. Here's what the logs look like on shutdown:

2023-09-27 13:32:37 [scrapy.core.engine] INFO: Spider closed (finished)
INFO - 2023-09-27 13:32:37,235 - scrapy.core.engine - engine - Spider closed (finished)
^C2023-09-27 13:32:41 [scrapy.crawler] INFO: Received SIGINT, shutting down gracefully. Send again to force 
INFO - 2023-09-27 13:32:41,581 - scrapy.crawler - crawler - Received SIGINT, shutting down gracefully. Send again to force 
INFO:     ASGI 'lifespan' protocol appears unsupported.
Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/bin/litestar", line 8, in <module>
    sys.exit(run_cli())
             ^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/__main__.py", line 6, in run_cli
    litestar_group()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/rich_click/rich_group.py", line 21, in main
    rv = super().main(*args, standalone_mode=False, **kwargs)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
         ^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/click/decorators.py", line 33, in new_func
    return f(get_current_context(), *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/cli/_utils.py", line 263, in wrapped
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/cli/commands/core.py", line 138, in run_command
    uvicorn.run(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/main.py", line 587, in run
    server.run()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/server.py", line 61, in run
    return asyncio.run(self.serve(sockets=sockets))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/asyncio/runners.py", line 190, in run
    return runner.run(main)
           ^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/asyncio/runners.py", line 118, in run
    return self._loop.run_until_complete(task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "uvloop/loop.pyx", line 1515, in uvloop.loop.Loop.run_until_complete
RuntimeError: Event loop stopped before Future completed.

Describe how to cause this behavior

What did you do to get it to happen? Running a scrapy crawl (using Twisted) from inside an ASGI framework.

Does it happen every time you follow these steps, sometimes, or only one time? Happens every every time. Here is the full traceback. 

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/routes/http.py", line 83, in handle
    await response(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 198, in __call__
    await self.after_response()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 145, in after_response
    await self.background()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/background_tasks.py", line 40, in __call__
    await self.fn(*self.args, **self.kwargs)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/utils/sync.py", line 65, in __call__
    return await self.ref.value(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/libre/Documents/GitHub/litestar-mre/litestar-scrapy/app.py", line 17, in run_crawl
    process.start(stop_after_crawl=False)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/scrapy/crawler.py", line 427, in start
    reactor.run(installSignalHandlers=False)  # blocking call
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/twisted/internet/asyncioreactor.py", line 255, in run
    self._asyncioEventloop.run_forever()
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 518, in uvloop.loop.Loop._run
RuntimeError: this event loop is already running.
Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/routes/http.py", line 83, in handle
    await response(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 198, in __call__
    await self.after_response()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 145, in after_response
    await self.background()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/background_tasks.py", line 40, in __call__
    await self.fn(*self.args, **self.kwargs)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/utils/sync.py", line 65, in __call__
    return await self.ref.value(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/libre/Documents/GitHub/litestar-mre/litestar-scrapy/app.py", line 17, in run_crawl
    process.start(stop_after_crawl=False)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/scrapy/crawler.py", line 427, in start
    reactor.run(installSignalHandlers=False)  # blocking call
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/twisted/internet/asyncioreactor.py", line 255, in run
    self._asyncioEventloop.run_forever()
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 518, in uvloop.loop.Loop._run
RuntimeError: this event loop is already running.
ERROR - 2023-09-27 14:16:00,473 - litestar - config - exception raised on http connection to route /

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/routes/http.py", line 83, in handle
    await response(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 198, in __call__
    await self.after_response()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 145, in after_response
    await self.background()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/background_tasks.py", line 40, in __call__
    await self.fn(*self.args, **self.kwargs)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/utils/sync.py", line 65, in __call__
    return await self.ref.value(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/libre/Documents/GitHub/litestar-mre/litestar-scrapy/app.py", line 17, in run_crawl
    process.start(stop_after_crawl=False)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/scrapy/crawler.py", line 427, in start
    reactor.run(installSignalHandlers=False)  # blocking call
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/twisted/internet/asyncioreactor.py", line 255, in run
    self._asyncioEventloop.run_forever()
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 518, in uvloop.loop.Loop._run
RuntimeError: this event loop is already running.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.
Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/routes/http.py", line 83, in handle
    await response(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 198, in __call__
    await self.after_response()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 145, in after_response
    await self.background()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/background_tasks.py", line 40, in __call__
    await self.fn(*self.args, **self.kwargs)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/utils/sync.py", line 65, in __call__
    return await self.ref.value(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/libre/Documents/GitHub/litestar-mre/litestar-scrapy/app.py", line 17, in run_crawl
    process.start(stop_after_crawl=False)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/scrapy/crawler.py", line 427, in start
    reactor.run(installSignalHandlers=False)  # blocking call
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/twisted/internet/asyncioreactor.py", line 255, in run
    self._asyncioEventloop.run_forever()
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 518, in uvloop.loop.Loop._run
RuntimeError: this event loop is already running.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.
ERROR - 2023-09-27 14:16:00,474 - litestar - config - exception raised on http connection to route /

Traceback (most recent call last):
RuntimeError: this event loop is already running.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/_asgi/asgi_router.py", line 84, in __call__
    await asgi_app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.
Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/routes/http.py", line 83, in handle
    await response(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 198, in __call__
    await self.after_response()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 145, in after_response
    await self.background()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/background_tasks.py", line 40, in __call__
    await self.fn(*self.args, **self.kwargs)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/utils/sync.py", line 65, in __call__
    return await self.ref.value(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/libre/Documents/GitHub/litestar-mre/litestar-scrapy/app.py", line 17, in run_crawl
    process.start(stop_after_crawl=False)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/scrapy/crawler.py", line 427, in start
    reactor.run(installSignalHandlers=False)  # blocking call
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/twisted/internet/asyncioreactor.py", line 255, in run
    self._asyncioEventloop.run_forever()
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 518, in uvloop.loop.Loop._run
RuntimeError: this event loop is already running.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/_asgi/asgi_router.py", line 84, in __call__
    await asgi_app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.
ERROR:    Exception in ASGI application
Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/routes/http.py", line 83, in handle
    await response(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 198, in __call__
    await self.after_response()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 145, in after_response
    await self.background()
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/background_tasks.py", line 40, in __call__
    await self.fn(*self.args, **self.kwargs)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/utils/sync.py", line 65, in __call__
    return await self.ref.value(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/libre/Documents/GitHub/litestar-mre/litestar-scrapy/app.py", line 17, in run_crawl
    process.start(stop_after_crawl=False)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/scrapy/crawler.py", line 427, in start
    reactor.run(installSignalHandlers=False)  # blocking call
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/twisted/internet/asyncioreactor.py", line 255, in run
    self._asyncioEventloop.run_forever()
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 518, in uvloop.loop.Loop._run
RuntimeError: this event loop is already running.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 191, in __call__
    await self.app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/_asgi/asgi_router.py", line 84, in __call__
    await asgi_app(scope, receive, send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 426, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__
    return await self.app(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/app.py", line 517, in __call__
    await self.asgi_handler(scope, receive, self._wrap_send(send=send, scope=scope))  # type: ignore[arg-type]
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 205, in __call__
    await self.handle_request_exception(
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/middleware/exceptions/middleware.py", line 235, in handle_request_exception
    await response.to_asgi_response(app=None, request=request)(scope=scope, receive=receive, send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 190, in __call__
    await self.start_response(send=send)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/litestar/response/base.py", line 161, in start_response
    await send(event)
  File "/opt/homebrew/Caskroom/miniforge/base/envs/litestar/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 578, in send
    raise RuntimeError(msg % message_type)
RuntimeError: Unexpected ASGI message 'http.response.start' sent, after response already completed.
2023-09-27 14:16:00 [scrapy.core.engine] DEBUG: Crawled (404) <GET https://example.com/robots.txt> (referer: None)
DEBUG - 2023-09-27 14:16:00,748 - scrapy.core.engine - engine - Crawled (404) <GET https://example.com/robots.txt> (referer: None)

How to Reproduce A complete MRE is located here: https://github.com/ThinksFast/litestar-scrapy/tree/main

Describe the correct behavior you'd like to see There should not be an exception thrown when Twisted is passed an existing loop. Shutdown should also be graceful.

Testing environment

Additional context Add any other context about the problem here.

ThinksFast commented 1 year ago

Just to clarify, I'm not suggesting to remove self._asyncioEventloop.run_forever() to resolve the issue. Only that my observation was commenting it out, in my MRE, did not seem to cause any obvious side effects.

I'm not sure what the right solution is here, but the two I can think of is:

  1. Suppress the error, so long as there are not ill side effects of calling .run_forever() on a loop thats already running
  2. Check if the loop is already set to run_forever() (is that the same as loop.is_running()?)
glyph commented 5 months ago

It sounds like you are trying to load Twisted in to an already-running mainloop, start Twisted's reactor asynchronously, and have it continue running.

I think that the thing you want to call is reactor.startRunning() which is like a … partially-official API for doing this, but it should mostly work. There's an open question about how to test this so that we can support it more fully.