500 Internal Server Error
Describe the bug
I have a Home Assistant integration which queries the API every 15 minutes and uses the following route: GET /api/v1/spool?allow_archived=False
From time to time (in the last ~24 hours 15x) an internal server error occurs.
The following entries can then be found in the logs:
INFO: 192.168.178.77:38644 - "GET /api/v1/spool?allow_archived=False HTTP/1.1" 500 Internal Server Error
ERROR: Exception in ASGI application
Traceback (most recent call last):
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/uvicorn/protocols/http/httptools_impl.py", line 411, in run_asgi
result = await app( # type: ignore[func-returns-value]
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/uvicorn/middleware/proxy_headers.py", line 69, in __call__
return await self.app(scope, receive, send)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/applications.py", line 123, in __call__
await self.middleware_stack(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/errors.py", line 186, in __call__
raise exc
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/gzip.py", line 24, in __call__
await responder(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/gzip.py", line 44, in __call__
await self.app(scope, receive, self.send_with_gzip)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/exceptions.py", line 65, in __call__
await wrap_app_handling_exceptions(self.app, conn)(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/_exception_handler.py", line 64, in wrapped_app
raise exc
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/_exception_handler.py", line 53, in wrapped_app
await app(scope, receive, sender)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 756, in __call__
await self.middleware_stack(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 776, in app
await route.handle(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 485, in handle
await self.app(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/fastapi/applications.py", line 1054, in __call__
await super().__call__(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/applications.py", line 123, in __call__
await self.middleware_stack(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/errors.py", line 186, in __call__
raise exc
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/errors.py", line 164, in __call__
await self.app(scope, receive, _send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/middleware/exceptions.py", line 65, in __call__
await wrap_app_handling_exceptions(self.app, conn)(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/_exception_handler.py", line 64, in wrapped_app
raise exc
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/_exception_handler.py", line 53, in wrapped_app
await app(scope, receive, sender)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 756, in __call__
await self.middleware_stack(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 776, in app
await route.handle(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 297, in handle
await self.app(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 77, in app
await wrap_app_handling_exceptions(app, request)(scope, receive, send)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/_exception_handler.py", line 64, in wrapped_app
raise exc
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/_exception_handler.py", line 53, in wrapped_app
await app(scope, receive, sender)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 72, in app
response = await func(request)
^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/fastapi/routing.py", line 278, in app
raw_response = await run_endpoint_function(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/fastapi/routing.py", line 191, in run_endpoint_function
return await dependant.call(**values)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/spoolman/api/v1/spool.py", line 277, in find
db_items, total_count = await spool.find(
^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/spoolman/database/spool.py", line 201, in find
rows = await db.execute(stmt)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/ext/asyncio/session.py", line 461, in execute
result = await greenlet_spawn(
^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 201, in greenlet_spawn
result = context.throw(*sys.exc_info())
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2351, in execute
return self._execute_internal(
^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2226, in _execute_internal
conn = self._connection_for_bind(bind)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2095, in _connection_for_bind
return trans._connection_for_bind(engine, execution_options)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "<string>", line 2, in _connection_for_bind
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/orm/state_changes.py", line 139, in _go
ret_value = fn(self, *arg, **kw)
^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 1189, in _connection_for_bind
conn = bind.connect()
^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 3276, in connect
return self._connection_cls(self)
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 146, in __init__
self._dbapi_connection = engine.raw_connection()
^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 3300, in raw_connection
return self.pool.connect()
^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 449, in connect
return _ConnectionFairy._checkout(self)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1362, in _checkout
with util.safe_reraise():
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 146, in __exit__
raise exc_value.with_traceback(exc_tb)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1300, in _checkout
result = pool._dialect._do_ping_w_event(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 715, in _do_ping_w_event
return self.do_ping(dbapi_connection)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/dialects/mysql/pymysql.py", line 107, in do_ping
dbapi_connection.ping(False)
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/dialects/mysql/aiomysql.py", line 186, in ping
return self.await_(self._connection.ping(reconnect))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 132, in await_only
return current.parent.switch(awaitable) # type: ignore[no-any-return,attr-defined] # noqa: E501
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 196, in greenlet_spawn
value = await result
^^^^^^^^^^^^
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 493, in ping
await self._execute_command(COMMAND.COM_PING, "")
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 724, in _execute_command
self._write_bytes(prelude + sql[:chunk_size - 1])
File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 669, in _write_bytes
return self._writer.write(data)
^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.11/asyncio/streams.py", line 332, in write
self._transport.write(data)
File "uvloop/handles/stream.pyx", line 674, in uvloop.loop.UVStream.write
File "uvloop/handles/handle.pyx", line 159, in uvloop.loop.UVHandle._ensure_alive
RuntimeError: unable to perform operation on <TCPTransport closed=True reading=False 0x298f820>; the handler is closed
To Reproduce Steps to reproduce the behavior:
- I have no explicit reproduction
Expected behavior Do not throw an 500
Spoolman Host (please complete the following information):
- Installation type: Docker
- Installed version: 0.20.0 (4f8d5ab)
- OS and Distro: Unraid
- Database type: MariaDb
Desktop (please complete the following information):
- OS: Windows
- Browser: Chrome
Additional context I don't think it has anything to do with each other, but maybe the information is still important. When I adjust a spool in my overview (Adjust Spool Filament), there has been no automatic refresh for some time and I have to reload the page every time. But I can't find anything about this in the logs.
Never seen this myself, from the trace it looks like it drops the connection between Spoolman and your MariaDB server. I highly doubt anything in Spoolman causes this to happen, but more probably it's something with your machine or networking setup.
I don't necessarily think it's a problem in my network. I use the database for a few other applications and only have the problem with Spoolman. Could it be due to the configuration of the Docker image in Unraid?
I also use the Home Assistant integration (with a 15 minute polling interval) and there I can see that the connection regularly drops after 1 hour and 20 minutes and is available again after 1 hour and 10 minutes. Totally weird
I had a similiar setup working for month and never had any problems. But I switched completly to portainer based containers and stacks. Maybe this is better for you?
You can even test with a fresh new instance of spoolman.
Do you have any caching devices in Unraid or do you use only HDDs? Whats your setup there? I figured out that using only the HDDs and the underlying "raid" is pretty slow. Maybe this can be an issue? Did you already checked HTOP on the unraid host?