From bf46a3a712bdf42ea52d8817c483414b68cd6c1a Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Tue, 5 Mar 2024 20:36:24 -0500 Subject: [PATCH 01/10] Add graceful error handling for database outages --- server/lobbyconnection.py | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/server/lobbyconnection.py b/server/lobbyconnection.py index ad87aeca7..529f0f2ba 100644 --- a/server/lobbyconnection.py +++ b/server/lobbyconnection.py @@ -14,7 +14,7 @@ import aiohttp from sqlalchemy import and_, func, select -from sqlalchemy.exc import DBAPIError +from sqlalchemy.exc import DBAPIError, OperationalError import server.metrics as metrics from server.db import FAFDatabase @@ -216,6 +216,13 @@ async def on_message_received(self, message): self.get_user_identifier(), cmd ) + except OperationalError: + # When the database goes down, SqlAlchemy will throw an OperationalError + await self.send({ + "command": "notice", + "style": "error", + "text": "Unable to connect to database. Please try again later." + }) except Exception as e: # pragma: no cover await self.send({"command": "invalid"}) self._logger.exception(e) From af7dbde16a601b2fa4311ef366c9cad345d469ac Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Tue, 5 Mar 2024 20:52:03 -0500 Subject: [PATCH 02/10] Add abort to OperationalError handling --- server/lobbyconnection.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/server/lobbyconnection.py b/server/lobbyconnection.py index 529f0f2ba..4f38c0d10 100644 --- a/server/lobbyconnection.py +++ b/server/lobbyconnection.py @@ -223,6 +223,8 @@ async def on_message_received(self, message): "style": "error", "text": "Unable to connect to database. Please try again later." }) + # Make sure to abort here to avoid a thundering herd problem. + await self.abort('Error connecting to database') except Exception as e: # pragma: no cover await self.send({"command": "invalid"}) self._logger.exception(e) From 45894a5d321f2f3762d050144a84e099592e1b7d Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Tue, 5 Mar 2024 20:53:23 -0500 Subject: [PATCH 03/10] Add unit tests for OperationalError handling in lobbyconnection --- tests/unit_tests/test_lobbyconnection.py | 21 +++++++++++++++++++++ 1 file changed, 21 insertions(+) diff --git a/tests/unit_tests/test_lobbyconnection.py b/tests/unit_tests/test_lobbyconnection.py index b3977531f..4a5451fc1 100644 --- a/tests/unit_tests/test_lobbyconnection.py +++ b/tests/unit_tests/test_lobbyconnection.py @@ -5,6 +5,7 @@ import pytest from aiohttp import web from sqlalchemy import and_, select +from sqlalchemy.exc import OperationalError from server.config import config from server.db.models import ban, friends_and_foes @@ -159,6 +160,26 @@ async def test_bad_command_calls_abort(lobbyconnection): lobbyconnection.abort.assert_called_once_with("Error processing command") +async def test_database_outage_error_responds_cleanly(lobbyconnection): + lobbyconnection.send = mock.AsyncMock() + lobbyconnection.abort = mock.AsyncMock() + + with pytest.raises(OperationalError): + await lobbyconnection.on_message_received({ + "command": "hello", + "login": "test", + "password": sha256(b"test_password").hexdigest(), + "unique_id": "blah" + }) + + lobbyconnection.send.assert_called_once_with({ + "command": "notice", + "style": "error", + "text": "Unable to connect to database. Please try again later." + }) + lobbyconnection.abort.assert_called_once_with("Error connecting to database") + + async def test_command_pong_does_nothing(lobbyconnection): lobbyconnection.send = mock.AsyncMock() From 37626aa6438bad9477c3cfabb2b800c7008f51e3 Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Tue, 5 Mar 2024 20:54:01 -0500 Subject: [PATCH 04/10] Replace apostrophe string with double quotes string --- server/lobbyconnection.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/lobbyconnection.py b/server/lobbyconnection.py index 4f38c0d10..887966f60 100644 --- a/server/lobbyconnection.py +++ b/server/lobbyconnection.py @@ -224,7 +224,7 @@ async def on_message_received(self, message): "text": "Unable to connect to database. Please try again later." }) # Make sure to abort here to avoid a thundering herd problem. - await self.abort('Error connecting to database') + await self.abort("Error connecting to database") except Exception as e: # pragma: no cover await self.send({"command": "invalid"}) self._logger.exception(e) From 1de3e7221582e0523dd686622ac709b58cfb4915 Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Tue, 5 Mar 2024 22:19:57 -0500 Subject: [PATCH 05/10] Fix unit test to pass --- tests/unit_tests/test_lobbyconnection.py | 22 ++++++++++++++-------- 1 file changed, 14 insertions(+), 8 deletions(-) diff --git a/tests/unit_tests/test_lobbyconnection.py b/tests/unit_tests/test_lobbyconnection.py index 4a5451fc1..623046ba1 100644 --- a/tests/unit_tests/test_lobbyconnection.py +++ b/tests/unit_tests/test_lobbyconnection.py @@ -161,22 +161,28 @@ async def test_bad_command_calls_abort(lobbyconnection): async def test_database_outage_error_responds_cleanly(lobbyconnection): - lobbyconnection.send = mock.AsyncMock() lobbyconnection.abort = mock.AsyncMock() + lobbyconnection.check_policy_conformity = mock.AsyncMock(return_value=True) + lobbyconnection.send = mock.AsyncMock() + + def mock_ensure_authenticated(cmd): + raise OperationalError(statement='', params=[], orig=None) + + lobbyconnection.ensure_authenticated = mock_ensure_authenticated - with pytest.raises(OperationalError): - await lobbyconnection.on_message_received({ - "command": "hello", - "login": "test", - "password": sha256(b"test_password").hexdigest(), - "unique_id": "blah" - }) + await lobbyconnection.on_message_received({ + "command": "hello", + "login": "test", + "password": sha256(b"test_password").hexdigest(), + "unique_id": "blah" + }) lobbyconnection.send.assert_called_once_with({ "command": "notice", "style": "error", "text": "Unable to connect to database. Please try again later." }) + lobbyconnection.abort.assert_called_once_with("Error connecting to database") From 6c78a83b61428c1c64852b194169b21ff0924ff1 Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Tue, 5 Mar 2024 22:23:27 -0500 Subject: [PATCH 06/10] Fix Flake8 warnings --- tests/unit_tests/test_lobbyconnection.py | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/tests/unit_tests/test_lobbyconnection.py b/tests/unit_tests/test_lobbyconnection.py index 623046ba1..248102f7c 100644 --- a/tests/unit_tests/test_lobbyconnection.py +++ b/tests/unit_tests/test_lobbyconnection.py @@ -166,23 +166,19 @@ async def test_database_outage_error_responds_cleanly(lobbyconnection): lobbyconnection.send = mock.AsyncMock() def mock_ensure_authenticated(cmd): - raise OperationalError(statement='', params=[], orig=None) - + raise OperationalError(statement="", params=[], orig=None) lobbyconnection.ensure_authenticated = mock_ensure_authenticated - await lobbyconnection.on_message_received({ "command": "hello", "login": "test", "password": sha256(b"test_password").hexdigest(), "unique_id": "blah" }) - lobbyconnection.send.assert_called_once_with({ "command": "notice", "style": "error", "text": "Unable to connect to database. Please try again later." }) - lobbyconnection.abort.assert_called_once_with("Error connecting to database") From e4da03f7c5466fae466e0542c386924eba1a1627 Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Tue, 5 Mar 2024 22:30:34 -0500 Subject: [PATCH 07/10] Rerun actions From 2b37232d55f60f1b504ebd598627c6f4ef455b04 Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Mon, 25 Mar 2024 11:37:09 -0400 Subject: [PATCH 08/10] Add logging when OperationalError is raised --- server/lobbyconnection.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/server/lobbyconnection.py b/server/lobbyconnection.py index 887966f60..ffebd516e 100644 --- a/server/lobbyconnection.py +++ b/server/lobbyconnection.py @@ -216,8 +216,9 @@ async def on_message_received(self, message): self.get_user_identifier(), cmd ) - except OperationalError: + except OperationalError as e: # When the database goes down, SqlAlchemy will throw an OperationalError + self._logger.error(f'Encountered OperationalError on message received. This could indicate DB is down.') await self.send({ "command": "notice", "style": "error", From 9691791c1d3fc25ce1a7ace77e537da00e3ca303 Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Mon, 25 Mar 2024 12:06:54 -0400 Subject: [PATCH 09/10] Fix linting issues --- server/lobbyconnection.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/server/lobbyconnection.py b/server/lobbyconnection.py index ffebd516e..8d121fe86 100644 --- a/server/lobbyconnection.py +++ b/server/lobbyconnection.py @@ -216,9 +216,9 @@ async def on_message_received(self, message): self.get_user_identifier(), cmd ) - except OperationalError as e: + except OperationalError: # When the database goes down, SqlAlchemy will throw an OperationalError - self._logger.error(f'Encountered OperationalError on message received. This could indicate DB is down.') + self._logger.error(f"Encountered OperationalError on message received. This could indicate DB is down.") await self.send({ "command": "notice", "style": "error", From 71d517723114ad87c68c0b667805c0580fe15084 Mon Sep 17 00:00:00 2001 From: benjamin-lawson Date: Mon, 25 Mar 2024 12:12:52 -0400 Subject: [PATCH 10/10] Fix linting issues pt2 --- server/lobbyconnection.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/lobbyconnection.py b/server/lobbyconnection.py index 8d121fe86..c50c10964 100644 --- a/server/lobbyconnection.py +++ b/server/lobbyconnection.py @@ -218,7 +218,7 @@ async def on_message_received(self, message): ) except OperationalError: # When the database goes down, SqlAlchemy will throw an OperationalError - self._logger.error(f"Encountered OperationalError on message received. This could indicate DB is down.") + self._logger.error("Encountered OperationalError on message received. This could indicate DB is down.") await self.send({ "command": "notice", "style": "error",