Spoolman icon indicating copy to clipboard operation
Spoolman copied to clipboard

500 Internal Server Error

Open BenGeba opened this issue 1 year ago • 3 comments

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:

  1. 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.

BenGeba avatar Nov 12 '24 22:11 BenGeba

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.

Donkie avatar Nov 25 '24 18:11 Donkie

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? image

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

BenGeba avatar Nov 25 '24 21:11 BenGeba

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?

Disane87 avatar Dec 16 '24 14:12 Disane87