From c4b6c9539d0456ca9edfe5357183366544adf454 Mon Sep 17 00:00:00 2001 From: David Robertson Date: Wed, 30 Aug 2023 13:44:16 +0100 Subject: [PATCH 1/3] Log the details of background update failures Would have been useful for https://github.com/matrix-org/synapse/issues/16192 --- synapse/storage/background_updates.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/synapse/storage/background_updates.py b/synapse/storage/background_updates.py index ddca0af1da39..7619f405fa09 100644 --- a/synapse/storage/background_updates.py +++ b/synapse/storage/background_updates.py @@ -405,14 +405,14 @@ async def run_background_updates(self, sleep: bool) -> None: try: result = await self.do_next_background_update(sleep) back_to_back_failures = 0 - except Exception: + except Exception as e: + logger.exception("Error doing update: %s", e) back_to_back_failures += 1 if back_to_back_failures >= 5: self._aborted = True raise RuntimeError( "5 back-to-back background update failures; aborting." ) - logger.exception("Error doing update") else: if result: logger.info( From d9b49f50e18c471bc7d9f5053ef343e21de6bff5 Mon Sep 17 00:00:00 2001 From: David Robertson Date: Wed, 30 Aug 2023 14:19:13 +0100 Subject: [PATCH 2/3] Test case gold star please --- tests/storage/test_background_update.py | 24 +++++++++++++++++++++++- 1 file changed, 23 insertions(+), 1 deletion(-) diff --git a/tests/storage/test_background_update.py b/tests/storage/test_background_update.py index 52beb4e89d94..abf7d0564d81 100644 --- a/tests/storage/test_background_update.py +++ b/tests/storage/test_background_update.py @@ -11,7 +11,7 @@ # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. - +import logging from unittest.mock import AsyncMock, Mock import yaml @@ -330,6 +330,28 @@ async def update_short(progress: JsonDict, count: int) -> int: self.update_handler.side_effect = update_short self.get_success(self.updates.do_next_background_update(False)) + def test_failed_update_logs_exception_details(self) -> None: + needle = "RUH ROH RAGGY" + + def failing_update(progress: JsonDict, count: int) -> int: + raise Exception(needle) + + self.update_handler.side_effect = failing_update + self.update_handler.reset_mock() + + self.get_success( + self.store.db_pool.simple_insert( + "background_updates", + values={"update_name": "test_update", "progress_json": "{}"}, + ) + ) + + with self.assertLogs(level=logging.ERROR) as logs: + # Expect a back-to-back RuntimeError to be raised + self.get_failure(self.updates.run_background_updates(False), RuntimeError) + + self.assertTrue(any(needle in log for log in logs.output), logs.output) + class BackgroundUpdateControllerTestCase(unittest.HomeserverTestCase): def prepare(self, reactor: MemoryReactor, clock: Clock, hs: HomeServer) -> None: From e17b5c59337f1bce8df1139779cea5e0d9449dca Mon Sep 17 00:00:00 2001 From: David Robertson Date: Wed, 30 Aug 2023 14:20:56 +0100 Subject: [PATCH 3/3] Changelog --- changelog.d/16212.misc | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog.d/16212.misc diff --git a/changelog.d/16212.misc b/changelog.d/16212.misc new file mode 100644 index 000000000000..19cf9b102d37 --- /dev/null +++ b/changelog.d/16212.misc @@ -0,0 +1 @@ +Log the details of background update failures.