Donkie / Spoolman

Keep track of your inventory of 3D-printer filament spools.
MIT License
1.03k stars 93 forks source link

Docker : upgrade 0.12.2 to 0.13.0, external MariaDB10 migration fail. #161

Closed phcay closed 1 year ago

phcay commented 1 year ago

I use SpoolMan in a container, with an external database in MariaDB10. I wanted to migrate SpoolMan from version 0.12.2 to 0.13.0. But it no longer starts because it is stuck on "Performing migration...". Adding SPOOLMAN_LOGGING_LEVEL=DEBUG does not provide more information. I had to revert to version 0.12.2 to make it functional again.

Here is the log: 2023-10-21 16:21:00:INFO:Starting Spoolman v0.12.2 (commit: 8ade10d) (built: 2023-10-08 09:55:33+00:00) 2023-10-21 16:21:00:INFO:Setting up database... 2023-10-21 16:21:00:INFO:Connecting to database of type "DatabaseType.MYSQL" at "10.0.3.1:3306" 2023-10-21 16:21:01:INFO:Performing migrations... 2023-10-21 16:21:08:INFO:Startup complete. 2023-10-21 16:52:59:INFO:Starting Spoolman v0.13.0 (commit: aa2e79b) (built: 2023-10-21 10:06:17+00:00) 2023-10-21 16:52:59:INFO:Setting up database... 2023-10-21 16:52:59:INFO:Connecting to database of type "DatabaseType.MYSQL" at "10.0.3.1:3306" 2023-10-21 16:52:59:INFO:Performing migrations... 2023-10-21 16:55:19:INFO:Starting Spoolman v0.13.0 (commit: aa2e79b) (built: 2023-10-21 10:06:17+00:00) 2023-10-21 16:55:19:INFO:Setting up database... 2023-10-21 16:55:19:INFO:Connecting to database of type "DatabaseType.MYSQL" at "10.0.3.1:3306" 2023-10-21 16:55:19:INFO:Performing migrations... 2023-10-21 16:57:35:INFO:Starting Spoolman v0.13.0 (commit: aa2e79b) (built: 2023-10-21 10:06:17+00:00) 2023-10-21 16:57:35:INFO:Setting up database... 2023-10-21 16:57:35:INFO:Connecting to database of type "DatabaseType.MYSQL" at "10.0.3.1:3306" 2023-10-21 16:57:35:INFO:Performing migrations...

Donkie commented 1 year ago

I tried your configuration locally but could not reproduce it. I will see if I can get the migrations system to produce some more detailed logs. It's weird that it happens now. I haven't done any database updates so migrations shouldn't be affected at all.

Donkie commented 1 year ago

Could you try the following things for me?

  1. Go back to 0.13.0
  2. Verify that it's still not working
  3. Open up a shell inside the docker container, see https://stackoverflow.com/a/30173220
  4. CD to the spoolman folder, cd /home/app/spoolman
  5. Run the command: source .venv/bin/activate
  6. Run the command: alembic upgrade head
  7. See if this command runs or if it also gets stuck.
phcay commented 1 year ago

I reverted to version 0.13.0 without changing anything else, and it works.

I tried to recreate it several times, and on the 3rd the problem reappeared. In this state, container restarts have no effect. By recreating again, the problem disappears, and after multiple restarts of the container, it still remains functional.

The first time I assumed there was a problem with the database because it crashed after the "Migration in progress..." message, maybe there was, but not a data point of view, but rather a connection. For information, I am on a QNAP NAS, with Docker management under "Container Station".

I think the anomaly comes from my environment. There must be a problem with the network link during some creation via composer.

I think we can close this incident, because obviously SpoolMan is out of the blame.

Sorry if there are any weird terms in my sentences, I don't speak English and I use automatic translation.

Here is what appeared on the console following the commands you gave me:

INFO: Started server process [1] INFO: Waiting for application startup. spoolman.main INFO Starting Spoolman v0.13.0 (commit: aa2e79b) (built: 2023-10-21 10:06:17+00:00) spoolman.main INFO Setting up database... spoolman.database.database INFO Connecting to database of type "DatabaseType.MYSQL" at "10.0.3.1:3306" spoolman.main INFO Performing migrations... Traceback (most recent call last): File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 527, in _connect self._reader, self._writer = await \ ^^^^^^^ File "/usr/local/lib/python3.11/asyncio/tasks.py", line 452, in wait_for return await fut ^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 88, in _openconnection transport, = await loop.create_connection( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 1085, in create_connection raise exceptions[0] File "/usr/local/lib/python3.11/asyncio/base_events.py", line 1069, in create_connection sock = await self._connect_sock( ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 973, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 634, in sock_connect return await fut ^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 674, in _sock_connect_cb raise OSError(err, f'Connect call failed {address}') TimeoutError: [Errno 110] Connect call failed ('10.0.3.1', 3306)

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 145, in init self._dbapi_connection = engine.raw_connection() ^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 3288, in raw_connection return self.pool.connect() ^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 452, in connect return _ConnectionFairy._checkout(self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1267, in _checkout fairy = _ConnectionRecord.checkout(pool) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 716, in checkout rec = pool._do_get() ^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/impl.py", line 169, in _do_get with util.safe_reraise(): File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 147, in exit raise exc_value.with_traceback(exc_tb) File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/impl.py", line 167, in _do_get return self._create_connection() ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 393, in _create_connection return _ConnectionRecord(self) ^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 678, in init self.connect() File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 902, in connect with util.safe_reraise(): File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 147, in exit raise exc_value.with_traceback(exc_tb) File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 898, in __connect self.dbapi_connection = connection = pool._invoke_creator(self) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/create.py", line 637, in connect return dialect.connect(*cargs, cparams) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 615, in connect return self.loaded_dbapi.connect(*cargs, *cparams) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/dialects/mysql/aiomysql.py", line 256, in connect await_only(creator_fn(arg, kw)), ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 125, in await_only return current.driver.switch(awaitable) # type: ignore[no-any-return] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 185, in greenlet_spawn value = await result ^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 75, in _connect await conn._connect() File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 563, in _connect raise OperationalError( pymysql.err.OperationalError: (2003, "Can't connect to MySQL server on '10.0.3.1'")

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/home/app/spoolman/.venv/bin/alembic", line 8, in sys.exit(main()) ^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/alembic/config.py", line 630, in main CommandLine(prog=prog).main(argv=argv) File "/home/app/spoolman/.venv/lib/python3.11/site-packages/alembic/config.py", line 624, in main self.run_cmd(cfg, options) File "/home/app/spoolman/.venv/lib/python3.11/site-packages/alembic/config.py", line 601, in run_cmd fn( File "/home/app/spoolman/.venv/lib/python3.11/site-packages/alembic/command.py", line 382, in upgrade script.run_env() File "/home/app/spoolman/.venv/lib/python3.11/site-packages/alembic/script/base.py", line 578, in run_env util.load_python_file(self.dir, "env.py") File "/home/app/spoolman/.venv/lib/python3.11/site-packages/alembic/util/pyfiles.py", line 93, in load_python_file module = load_module_py(module_id, path) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/alembic/util/pyfiles.py", line 109, in load_module_py spec.loader.exec_module(module) # type: ignore await greenlet_spawn(self.sync_engine.connect) File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 190, in greenlet_spawn result = context.throw(sys.exc_info()) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 3264, in connect return self._connection_cls(self) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 147, in init Connection._handle_dbapi_exception_noconnection( File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2426, in _handle_dbapi_exception_noconnection raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 145, in init self._dbapi_connection = engine.raw_connection() ^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 3288, in raw_connection return self.pool.connect() ^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 452, in connect return _ConnectionFairy._checkout(self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1267, in _checkout fairy = _ConnectionRecord.checkout(pool) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 716, in checkout rec = pool._do_get() ^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/impl.py", line 169, in _do_get with util.safe_reraise(): File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 147, in exit raise exc_value.with_traceback(exc_tb) File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/impl.py", line 167, in _do_get return self._create_connection() ^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 393, in _create_connection return _ConnectionRecord(self) ^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 678, in init self.connect() File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 902, in connect with util.safe_reraise(): File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/langhelpers.py", line 147, in exit raise exc_value.with_traceback(exc_tb) File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 898, in __connect self.dbapi_connection = connection = pool._invoke_creator(self) ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/create.py", line 637, in connect return dialect.connect(cargs, cparams) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 615, in connect return self.loaded_dbapi.connect(*cargs, *cparams) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/dialects/mysql/aiomysql.py", line 256, in connect await_only(creator_fn(arg, kw)), ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 125, in await_only return current.driver.switch(awaitable) # type: ignore[no-any-return] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 185, in greenlet_spawn value = await result ^^^^^^^^^^^^ File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 75, in _connect await conn._connect() File "/home/app/spoolman/.venv/lib/python3.11/site-packages/aiomysql/connection.py", line 563, in _connect raise OperationalError( sqlalchemy.exc.OperationalError: (pymysql.err.OperationalError) (2003, "Can't connect to MySQL server on '10.0.3.1'") (Background on this error at: https://sqlalche.me/e/20/e3q8) ERROR: Traceback (most recent call last): File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 677, in lifespan async with self.lifespan_context(app) as maybe_state: File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 566, in aenter await self._router.startup() File "/home/app/spoolman/.venv/lib/python3.11/site-packages/starlette/routing.py", line 654, in startup await handler() File "/home/app/spoolman/spoolman/main.py", line 81, in startup subprocess.run(["alembic", "upgrade", "head"], check=True, cwd=project_root) # noqa: S603, S607, ASYNC101 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/subprocess.py", line 571, in run raise CalledProcessError(retcode, process.args,

Donkie commented 1 year ago

Yeah this sounds like an issue on your end. Thanks for the investigation though :)