500 Error when authenticating #68
Description
When running our tests first thing in the morning, we consistently get a 500 error first ime authenticating to SCOT. SCOT is not being used over night.
2025-05-20T13:19:22.446209228Z stdout F INFO: 10.42.0.1:53264 - "GET /api/v1/health/ HTTP/1.1" 200 OK
2025-05-20T13:19:23.931011128Z stdout F INFO: 10.42.0.46:56636 - "POST /api/v1/login/access-token HTTP/1.1" 500 Internal Server Error
2025-05-20T13:19:23.934567593Z stderr F ERROR: Exception in ASGI application
2025-05-20T13:19:23.934591901Z stderr F Traceback (most recent call last):
2025-05-20T13:19:23.934597118Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1815, in _execute_context
2025-05-20T13:19:23.934600567Z stderr F context = constructor(
2025-05-20T13:19:23.934604006Z stderr F ^^^^^^^^^^^^
2025-05-20T13:19:23.934608035Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 1418, in _init_compiled
2025-05-20T13:19:23.934611475Z stderr F self.cursor = self.create_cursor()
2025-05-20T13:19:23.934614756Z stderr F ^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934618257Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 1752, in create_cursor
2025-05-20T13:19:23.934621353Z stderr F return self.create_default_cursor()
2025-05-20T13:19:23.934624721Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934628366Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 1758, in create_default_cursor
2025-05-20T13:19:23.934631705Z stderr F return self._dbapi_connection.cursor()
2025-05-20T13:19:23.934635061Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934638562Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1485, in cursor
2025-05-20T13:19:23.934641829Z stderr F return self.dbapi_connection.cursor(*args, **kwargs)
2025-05-20T13:19:23.934645158Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934648362Z stderr F File "/usr/local/lib/python3.11/site-packages/mysql/connector/connection_cext.py", line 773, in cursor
2025-05-20T13:19:23.934651651Z stderr F raise OperationalError("MySQL Connection not available.")
2025-05-20T13:19:23.934655393Z stderr F mysql.connector.errors.OperationalError: MySQL Connection not available.
2025-05-20T13:19:23.934658311Z stderr F
2025-05-20T13:19:23.934661957Z stderr F The above exception was the direct cause of the following exception:
2025-05-20T13:19:23.934665266Z stderr F
2025-05-20T13:19:23.934668859Z stderr F Traceback (most recent call last):
2025-05-20T13:19:23.934672063Z stderr F File "/usr/local/lib/python3.11/site-packages/uvicorn/protocols/http/h11_impl.py", line 403, in run_asgi
2025-05-20T13:19:23.934675647Z stderr F result = await app( # type: ignore[func-returns-value]
2025-05-20T13:19:23.93469624Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934698805Z stderr F File "/usr/local/lib/python3.11/site-packages/uvicorn/middleware/proxy_headers.py", line 60, in __call__
2025-05-20T13:19:23.934700669Z stderr F return await self.app(scope, receive, send)
2025-05-20T13:19:23.934702476Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934704312Z stderr F File "/usr/local/lib/python3.11/site-packages/fastapi/applications.py", line 1054, in __call__
2025-05-20T13:19:23.934706105Z stderr F await super().__call__(scope, receive, send)
2025-05-20T13:19:23.93470784Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/applications.py", line 113, in __call__
2025-05-20T13:19:23.934709763Z stderr F await self.middleware_stack(scope, receive, send)
2025-05-20T13:19:23.934711638Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/errors.py", line 187, in __call__
2025-05-20T13:19:23.934713401Z stderr F raise exc
2025-05-20T13:19:23.934715224Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/errors.py", line 165, in __call__
2025-05-20T13:19:23.934716965Z stderr F await self.app(scope, receive, _send)
2025-05-20T13:19:23.934718682Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/base.py", line 185, in __call__
2025-05-20T13:19:23.934720426Z stderr F with collapse_excgroups():
2025-05-20T13:19:23.934722225Z stderr F File "/usr/local/lib/python3.11/contextlib.py", line 158, in __exit__
2025-05-20T13:19:23.934723935Z stderr F self.gen.throw(typ, value, traceback)
2025-05-20T13:19:23.934725679Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/_utils.py", line 83, in collapse_excgroups
2025-05-20T13:19:23.934727414Z stderr F raise exc
2025-05-20T13:19:23.934729092Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/base.py", line 187, in __call__
2025-05-20T13:19:23.934730876Z stderr F response = await self.dispatch_func(request, call_next)
2025-05-20T13:19:23.93473264Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934734422Z stderr F File "/code/app/api/__init__.py", line 18, in db_middleware
2025-05-20T13:19:23.934736186Z stderr F response = await call_next(request)
2025-05-20T13:19:23.934737883Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934739552Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/base.py", line 163, in call_next
2025-05-20T13:19:23.934741634Z stderr F raise app_exc
2025-05-20T13:19:23.934743439Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/base.py", line 149, in coro
2025-05-20T13:19:23.934745207Z stderr F await self.app(scope, receive_or_disconnect, send_no_error)
2025-05-20T13:19:23.934746871Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/cors.py", line 85, in __call__
2025-05-20T13:19:23.934748689Z stderr F await self.app(scope, receive, send)
2025-05-20T13:19:23.93475101Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/middleware/exceptions.py", line 62, in __call__
2025-05-20T13:19:23.93475351Z stderr F await wrap_app_handling_exceptions(self.app, conn)(scope, receive, send)
2025-05-20T13:19:23.934755877Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/_exception_handler.py", line 62, in wrapped_app
2025-05-20T13:19:23.934758086Z stderr F raise exc
2025-05-20T13:19:23.934760333Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/_exception_handler.py", line 51, in wrapped_app
2025-05-20T13:19:23.934762792Z stderr F await app(scope, receive, sender)
2025-05-20T13:19:23.93476515Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/routing.py", line 715, in __call__
2025-05-20T13:19:23.934767374Z stderr F await self.middleware_stack(scope, receive, send)
2025-05-20T13:19:23.93478484Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/routing.py", line 735, in app
2025-05-20T13:19:23.934791915Z stderr F await route.handle(scope, receive, send)
2025-05-20T13:19:23.934793721Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/routing.py", line 288, in handle
2025-05-20T13:19:23.934795474Z stderr F await self.app(scope, receive, send)
2025-05-20T13:19:23.934797305Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/routing.py", line 76, in app
2025-05-20T13:19:23.93479938Z stderr F await wrap_app_handling_exceptions(app, request)(scope, receive, send)
2025-05-20T13:19:23.934801131Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/_exception_handler.py", line 62, in wrapped_app
2025-05-20T13:19:23.934803013Z stderr F raise exc
2025-05-20T13:19:23.934804766Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/_exception_handler.py", line 51, in wrapped_app
2025-05-20T13:19:23.93480933Z stderr F await app(scope, receive, sender)
2025-05-20T13:19:23.93481123Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/routing.py", line 73, in app
2025-05-20T13:19:23.934812959Z stderr F response = await f(request)
2025-05-20T13:19:23.934814839Z stderr F ^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934816583Z stderr F File "/usr/local/lib/python3.11/site-packages/fastapi/routing.py", line 278, in app
2025-05-20T13:19:23.934818311Z stderr F raw_response = await run_endpoint_function(
2025-05-20T13:19:23.934820065Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.93482212Z stderr F File "/usr/local/lib/python3.11/site-packages/fastapi/routing.py", line 193, in run_endpoint_function
2025-05-20T13:19:23.934823869Z stderr F return await run_in_threadpool(dependant.call, **values)
2025-05-20T13:19:23.934825589Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934827246Z stderr F File "/usr/local/lib/python3.11/site-packages/starlette/concurrency.py", line 39, in run_in_threadpool
2025-05-20T13:19:23.934853141Z stderr F return await anyio.to_thread.run_sync(func, *args)
2025-05-20T13:19:23.934858131Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934860652Z stderr F File "/usr/local/lib/python3.11/site-packages/anyio/to_thread.py", line 56, in run_sync
2025-05-20T13:19:23.934863287Z stderr F return await get_async_backend().run_sync_in_worker_thread(
2025-05-20T13:19:23.934865843Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934868522Z stderr F File "/usr/local/lib/python3.11/site-packages/anyio/_backends/_asyncio.py", line 2461, in run_sync_in_worker_thread
2025-05-20T13:19:23.934871039Z stderr F return await future
2025-05-20T13:19:23.934873675Z stderr F ^^^^^^^^^^^^
2025-05-20T13:19:23.934876108Z stderr F File "/usr/local/lib/python3.11/site-packages/anyio/_backends/_asyncio.py", line 962, in run
2025-05-20T13:19:23.934878632Z stderr F result = context.run(func, *args)
2025-05-20T13:19:23.934881059Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934883537Z stderr F File "/code/app/api/endpoints/login.py", line 98, in login_access_token
2025-05-20T13:19:23.934886062Z stderr F return login_password(response, db, form_data, None, audit_logger)
2025-05-20T13:19:23.934888602Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.934890667Z stderr F File "/code/app/api/endpoints/login.py", line 28, in login_password
2025-05-20T13:19:23.934893571Z stderr F user = crud.user.authenticate(
2025-05-20T13:19:23.935003088Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935006779Z stderr F File "/code/app/crud/crud_user.py", line 112, in authenticate
2025-05-20T13:19:23.93500904Z stderr F result = self.authenticate_password(
2025-05-20T13:19:23.935011375Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935020498Z stderr F File "/code/app/crud/crud_user.py", line 138, in authenticate_password
2025-05-20T13:19:23.935022941Z stderr F auth_methods = auth_setting.get_auth_methods(db_session)
2025-05-20T13:19:23.935025233Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935029877Z stderr F File "/code/app/crud/crud_auth_setting.py", line 66, in get_auth_methods
2025-05-20T13:19:23.935032417Z stderr F return db_session.query(self.model).order_by(AuthSettings.id).all()
2025-05-20T13:19:23.935035049Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935037599Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/query.py", line 2673, in all
2025-05-20T13:19:23.935040226Z stderr F return self._iter().all() # type: ignore
2025-05-20T13:19:23.935042827Z stderr F ^^^^^^^^^^^^
2025-05-20T13:19:23.935045594Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/query.py", line 2827, in _iter
2025-05-20T13:19:23.935047958Z stderr F result: Union[ScalarResult[_T], Result[_T]] = self.session.execute(
2025-05-20T13:19:23.935050418Z stderr F ^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935053386Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
2025-05-20T13:19:23.935055387Z stderr F return self._execute_internal(
2025-05-20T13:19:23.935057119Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935059011Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2207, in _execute_internal
2025-05-20T13:19:23.935060766Z stderr F fn_result: Optional[Result[Any]] = fn(orm_exec_state)
2025-05-20T13:19:23.935062487Z stderr F ^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935064375Z stderr F File "/code/app/db/session.py", line 42, in statement_catch
2025-05-20T13:19:23.935066204Z stderr F return state.invoke_statement(params=session_vars)
2025-05-20T13:19:23.935068124Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935069942Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 479, in invoke_statement
2025-05-20T13:19:23.935071726Z stderr F return self.session._execute_internal(
2025-05-20T13:19:23.935074195Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935091965Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/session.py", line 2247, in _execute_internal
2025-05-20T13:19:23.935093857Z stderr F result: Result[Any] = compile_state_cls.orm_execute_statement(
2025-05-20T13:19:23.935095652Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935097633Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/orm/context.py", line 293, in orm_execute_statement
2025-05-20T13:19:23.935099539Z stderr F result = conn.execute(
2025-05-20T13:19:23.935101668Z stderr F ^^^^^^^^^^^^^
2025-05-20T13:19:23.935103429Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1418, in execute
2025-05-20T13:19:23.935105338Z stderr F return meth(
2025-05-20T13:19:23.93510716Z stderr F ^^^^^
2025-05-20T13:19:23.935108891Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/sql/elements.py", line 515, in _execute_on_connection
2025-05-20T13:19:23.935110604Z stderr F return connection._execute_clauseelement(
2025-05-20T13:19:23.93511237Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.93511423Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1640, in _execute_clauseelement
2025-05-20T13:19:23.935116021Z stderr F ret = self._execute_context(
2025-05-20T13:19:23.935117794Z stderr F ^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935119538Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1821, in _execute_context
2025-05-20T13:19:23.935124965Z stderr F self._handle_dbapi_exception(
2025-05-20T13:19:23.935127558Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 2355, in _handle_dbapi_exception
2025-05-20T13:19:23.935129356Z stderr F raise sqlalchemy_exception.with_traceback(exc_info[2]) from e
2025-05-20T13:19:23.935131121Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/base.py", line 1815, in _execute_context
2025-05-20T13:19:23.935132807Z stderr F context = constructor(
2025-05-20T13:19:23.935134608Z stderr F ^^^^^^^^^^^^
2025-05-20T13:19:23.93513638Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 1418, in _init_compiled
2025-05-20T13:19:23.935138095Z stderr F self.cursor = self.create_cursor()
2025-05-20T13:19:23.935139907Z stderr F ^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935141946Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 1752, in create_cursor
2025-05-20T13:19:23.935143671Z stderr F return self.create_default_cursor()
2025-05-20T13:19:23.935145407Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935147127Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/engine/default.py", line 1758, in create_default_cursor
2025-05-20T13:19:23.935148926Z stderr F return self._dbapi_connection.cursor()
2025-05-20T13:19:23.935150637Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935152344Z stderr F File "/usr/local/lib/python3.11/site-packages/sqlalchemy/pool/base.py", line 1485, in cursor
2025-05-20T13:19:23.935154275Z stderr F return self.dbapi_connection.cursor(*args, **kwargs)
2025-05-20T13:19:23.93515624Z stderr F ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-05-20T13:19:23.935158034Z stderr F File "/usr/local/lib/python3.11/site-packages/mysql/connector/connection_cext.py", line 773, in cursor
2025-05-20T13:19:23.935159779Z stderr F raise OperationalError("MySQL Connection not available.")
2025-05-20T13:19:23.935161523Z stderr F sqlalchemy.exc.OperationalError: (mysql.connector.errors.OperationalError) MySQL Connection not available.
2025-05-20T13:19:23.93516506Z stderr F [SQL: SELECT auth_settings.auth_settings_id AS auth_settings_auth_settings_id, auth_settings.auth AS auth_settings_auth, auth_settings.auth_properties AS auth_settings_auth_properties, auth_settings.auth_active AS auth_settings_auth_active, auth_settings.created_date AS auth_settings_created_date, auth_settings.modified_date AS auth_settings_modified_date
2025-05-20T13:19:23.935166924Z stderr F FROM auth_settings ORDER BY auth_settings.auth_settings_id]
2025-05-20T13:19:23.935168613Z stderr F (Background on this error at: https://sqlalche.me/e/20/e3q8)
2025-05-20T13:19:24.267631047Z stdout F INFO: 10.42.0.46:56638 - "POST /api/v1/login/access-token HTTP/1.1" 200 OK
2025-05-20T13:19:24.304928104Z stdout F INFO: 10.42.0.46:56638 - "GET /api/v1/settings/ HTTP/1.1" 200 `