[FastAPI] SqlAlchemy Connection time out Error

발단

갑자기 프론트엔드 개발자에게서 이런 카톡이 왔다.

500이 나오다가 갑자기 제대로 된 응답을 받는 이유가 뭘까. 생전 처음 보는 에러라서 우선 에러 로그를 확인해 보기로 했다.

 

 

원인

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1963, in _exec_single_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 920, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/local/lib/python3.10/site-packages/pymysql/cursors.py", line 153, in execute
    result = self._query(query)
  File "/usr/local/lib/python3.10/site-packages/pymysql/cursors.py", line 322, in _query
    conn.query(q)
  File "/usr/local/lib/python3.10/site-packages/pymysql/connections.py", line 557, in query
    self._execute_command(COMMAND.COM_QUERY, sql)
  File "/usr/local/lib/python3.10/site-packages/pymysql/connections.py", line 861, in _execute_command
    self._write_bytes(packet)
  File "/usr/local/lib/python3.10/site-packages/pymysql/connections.py", line 806, in _write_bytes
    raise err.OperationalError(
pymysql.err.OperationalError: (2006, "MySQL server has gone away (TimeoutError(110, 'Connection timed out'))")

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/uvicorn/protocols/http/h11_impl.py", line 428, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
  File "/usr/local/lib/python3.10/site-packages/uvicorn/middleware/proxy_headers.py", line 78, in __call__
    return await self.app(scope, receive, send)
  File "/usr/local/lib/python3.10/site-packages/fastapi/applications.py", line 276, in __call__
    await super().__call__(scope, receive, send)
  File "/usr/local/lib/python3.10/site-packages/starlette/applications.py", line 122, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in __call__
    raise exc
  File "/usr/local/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in __call__
    await self.app(scope, receive, _send)
  File "/usr/local/lib/python3.10/site-packages/starlette/middleware/cors.py", line 92, in __call__
    await self.simple_response(scope, receive, send, request_headers=headers)
  File "/usr/local/lib/python3.10/site-packages/starlette/middleware/cors.py", line 147, in simple_response
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in __call__
    raise exc
  File "/usr/local/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in __call__
    await self.app(scope, receive, sender)
  File "/usr/local/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
    raise e
  File "/usr/local/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.10/site-packages/starlette/routing.py", line 718, in __call__
    await route.handle(scope, receive, send)
  File "/usr/local/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.10/site-packages/starlette/routing.py", line 66, in app
    response = await func(request)
  File "/usr/local/lib/python3.10/site-packages/fastapi/routing.py", line 237, in app
    raw_response = await run_endpoint_function(
  File "/usr/local/lib/python3.10/site-packages/fastapi/routing.py", line 163, in run_endpoint_function
    return await dependant.call(**values)
  File "/main.py", line 41, in start_interview
    account = crud.find_account_by_email(db=db, email=jwt_util.decode_jwt(access_token=Authorization))
  File "/crud.py", line 16, in find_account_by_email
    for acc in db_account:
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2828, in __iter__
    result = self._iter()
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2842, in _iter
    result: Union[ScalarResult[_T], Result[_T]] = self.session.execute(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2231, in execute
    return self._execute_internal(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 2126, in _execute_internal
    result: Result[Any] = compile_state_cls.orm_execute_statement(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/context.py", line 292, in orm_execute_statement
    result = conn.execute(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1413, in execute
    return meth(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/sql/elements.py", line 483, in _execute_on_connection
    return connection._execute_clauseelement(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1637, in _execute_clauseelement
    ret = self._execute_context(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1841, in _execute_context
    return self._exec_single_context(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1982, in _exec_single_context
    self._handle_dbapi_exception(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 2339, in _handle_dbapi_exception
    raise sqlalchemy_exception.with_traceback(exc_info[2]) from e
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1963, in _exec_single_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 920, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/local/lib/python3.10/site-packages/pymysql/cursors.py", line 153, in execute
    result = self._query(query)
  File "/usr/local/lib/python3.10/site-packages/pymysql/cursors.py", line 322, in _query
    conn.query(q)
  File "/usr/local/lib/python3.10/site-packages/pymysql/connections.py", line 557, in query
    self._execute_command(COMMAND.COM_QUERY, sql)
  File "/usr/local/lib/python3.10/site-packages/pymysql/connections.py", line 861, in _execute_command
    self._write_bytes(packet)
  File "/usr/local/lib/python3.10/site-packages/pymysql/connections.py", line 806, in _write_bytes
    raise err.OperationalError(
sqlalchemy.exc.OperationalError: (pymysql.err.OperationalError) (2006, "MySQL server has gone away (TimeoutError(110, 'Connection timed out'))")
[SQL: SELECT account.id AS account_id, account.email AS account_email, account.name AS account_name 
FROM account 
WHERE account.email = %(email_1)s]
[parameters: {'email_1': 'abcde@abcd.com'}]
(Background on this error at: https://sqlalche.me/e/20/e3q8)

마지막 에러를 자세히 살펴보면

sqlalchemy.exc.OperationalError: 
(pymysql.err.OperationalError) 
(2006, "MySQL server has gone away (TimeoutError(110, 'Connection timed out'))")

fastapi와 mysql 서버 간의 connection이 timeout == 종료되었음을 확인할 수 있다.

 

해결

- Before : 원래 sql을 연결할 때 다음과 같은 형태였는데, connection pool을 일정 시간이 지날 때마다 재연결하는 옵션을 달아 준다.

load_dotenv()
SQLALCHEMY_DATABASE_URL = os.environ.get("DB_URL")

engine = create_engine(
    SQLALCHEMY_DATABASE_URL,
)
SessionLocal = sessionmaker(autocommit=False, autoflush=False, bind=engine)

Base = declarative_base()

- After:

load_dotenv()
SQLALCHEMY_DATABASE_URL = os.environ.get("DB_URL")

engine = create_engine(
    SQLALCHEMY_DATABASE_URL,
    pool_recycle=500,
    pool_size=5,
    max_overflow=20,
    echo=False,
    echo_pool=True
)
SessionLocal = sessionmaker(autocommit=False, autoflush=False, bind=engine)

Base = declarative_base()