Move scoreboard calculation to its own thread

Co-authored-by: Simon Ruderich <simon@ruderich.org>

src/ctf_gameserver/controller/controller.py

@@ -1,5 +1,6 @@
 import datetime
 import logging
+from threading import Lock, Thread
 import time
 import os
 
@@ -71,10 +72,12 @@ def main():
     metrics = make_metrics(db_conn)
     metrics['start_timestamp'].set_to_current_time()
 
+    scoring_lock = Lock()
+
     daemon.notify('READY=1')
 
     while True:
-        main_loop_step(db_conn, metrics, args.nonstop)
+        main_loop_step(db_conn, metrics, scoring_lock, args.nonstop)
 
 
 def make_metrics(db_conn, registry=prometheus_client.REGISTRY):
@@ -144,7 +147,7 @@ def collect(self):
     return metrics
 
 
-def main_loop_step(db_conn, metrics, nonstop):
+def main_loop_step(db_conn, metrics, scoring_lock, nonstop):
 
     def sleep(duration):
         logging.info('Sleeping for %d seconds', duration)
@@ -199,11 +202,25 @@ def sleep(duration):
     if get_sleep_seconds(control_info, metrics, now) <= 0:
         logging.info('After tick %d, increasing tick to the next one', control_info['current_tick'])
         database.increase_tick(db_conn)
+        calculate_scoreboard_in_thread(db_conn, metrics, scoring_lock)
 
-        scoring_start_time = time.monotonic()
-        scoring.calculate_scoreboard(db_conn)
-        metrics['scoreboard_update_seconds'].observe(time.monotonic() - scoring_start_time)
-        logging.info('New scoreboard calculated')
+
+def calculate_scoreboard_in_thread(db_conn, metrics, lock):
+
+    def calculate():
+        if not lock.acquire(blocking=False):
+            logging.warning('Skipping scoreboard calculation because previous run is stil ongoing')
+            return
+
+        try:
+            scoring_start_time = time.monotonic()
+            scoring.calculate_scoreboard(db_conn)
+            metrics['scoreboard_update_seconds'].observe(time.monotonic() - scoring_start_time)
+            logging.info('New scoreboard calculated')
+        finally:
+            lock.release()
+
+    Thread(target=calculate, daemon=True).start()
 
 
 def get_sleep_seconds(control_info, metrics, now=None):

src/ctf_gameserver/lib/database.py

@@ -21,6 +21,9 @@ def transaction_cursor(db_conn, always_rollback=False):
     cursor = db_conn.cursor()
 
     if isinstance(cursor, sqlite3.Cursor):
+        if sqlite3.threadsafety < 2:
+            raise Exception('SQLite must be built with thread safety')
+
         cursor = _SQLite3Cursor(cursor)
 
     try:

tests/controller/test_main_loop.py

@@ -1,4 +1,5 @@
 from collections import defaultdict
+from threading import Lock
 from unittest.mock import Mock, patch
 
 from ctf_gameserver.lib.database import transaction_cursor
@@ -14,7 +15,7 @@ class MainLoopTest(DatabaseTestCase):
     @patch('time.sleep')
     @patch('logging.warning')
     def test_null(self, warning_mock, sleep_mock):
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
 
         warning_mock.assert_called_with('Competition start and end time must be configured in the database')
         sleep_mock.assert_called_once_with(60)
@@ -25,7 +26,7 @@ def test_before_game(self, sleep_mock):
             cursor.execute('UPDATE scoring_gamecontrol SET start = datetime("now", "+1 hour"), '
                            '                               end = datetime("now", "+1 day")')
 
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
 
         sleep_mock.assert_called_once_with(60)
 
@@ -45,7 +46,7 @@ def test_first_tick(self, sleep_mock):
             cursor.execute('UPDATE scoring_gamecontrol SET start = datetime("now"), '
                            '                               end = datetime("now", "+1 day")')
 
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
         sleep_mock.assert_called_once_with(0)
 
         with transaction_cursor(self.connection) as cursor:
@@ -85,7 +86,7 @@ def test_next_tick_undue(self, sleep_mock):
                            '                               end = datetime("now", "+85370 seconds"), '
                            '                               current_tick=5')
 
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
 
         sleep_mock.assert_called_once()
         sleep_arg = sleep_mock.call_args[0][0]
@@ -109,7 +110,7 @@ def test_next_tick_overdue(self, sleep_mock):
                            '                               end=datetime("now", "+1421 minutes"), '
                            '                               current_tick=5, cancel_checks=true')
 
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
 
         sleep_mock.assert_called_once_with(0)
 
@@ -135,7 +136,7 @@ def test_last_tick(self, sleep_mock):
                            '                               end = datetime("now", "+3 minutes"), '
                            '                               current_tick=479')
 
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
         sleep_mock.assert_called_once_with(0)
 
         with transaction_cursor(self.connection) as cursor:
@@ -155,7 +156,7 @@ def test_shortly_after_game(self, sleep_mock):
                            '                               end = datetime("now"), '
                            '                               current_tick=479')
 
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
         self.assertEqual(sleep_mock.call_count, 2)
         self.assertEqual(sleep_mock.call_args_list[0][0][0], 0)
         self.assertEqual(sleep_mock.call_args_list[1][0][0], 60)
@@ -182,7 +183,7 @@ def test_long_after_game(self, sleep_mock):
                            '                               end = datetime("now", "-25 minutes"), '
                            '                               current_tick=479')
 
-        controller.main_loop_step(self.connection, self.metrics, False)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), False)
         self.assertEqual(sleep_mock.call_count, 2)
         self.assertEqual(sleep_mock.call_args_list[0][0][0], 0)
         self.assertEqual(sleep_mock.call_args_list[1][0][0], 60)
@@ -209,7 +210,7 @@ def test_after_game_nonstop(self, sleep_mock):
                            '                               end = datetime("now"), '
                            '                               current_tick=479')
 
-        controller.main_loop_step(self.connection, self.metrics, True)
+        controller.main_loop_step(self.connection, self.metrics, Lock(), True)
         sleep_mock.assert_called_once_with(0)
 
         with transaction_cursor(self.connection) as cursor: