Move some log lines from default logger to sql/transaction loggers

changelog.d/7952.misc

@@ -0,0 +1 @@
+Move some database-related log lines from the default logger to the database/transaction loggers.

synapse/storage/database.py

@@ -49,8 +49,6 @@
 from synapse.storage.types import Connection, Cursor
 from synapse.types import Collection
 
-logger = logging.getLogger(__name__)
-
 # python 3 does not have a maximum int value
 MAX_TXN_ID = 2 ** 63 - 1
 
@@ -233,7 +231,7 @@ def _do_execute(self, func, sql, *args):
         try:
             return func(sql, *args)
         except Exception as e:
-            logger.debug("[SQL FAIL] {%s} %s", self.name, e)
+            sql_logger.debug("[SQL FAIL] {%s} %s", self.name, e)
             raise
         finally:
             secs = time.time() - start
@@ -352,7 +350,7 @@ def _check_safe_to_upsert(self):
 
         for table, update_name in UNIQUE_INDEX_BACKGROUND_UPDATES.items():
             if update_name not in updates:
-                logger.debug("Now safe to upsert in %s", table)
+                sql_logger.debug("Now safe to upsert in %s", table)
                 self._unsafe_to_upsert_tables.discard(table)
 
         # If there's any updates still running, reschedule to run.
@@ -419,26 +417,28 @@ def new_transaction(
                 except self.engine.module.OperationalError as e:
                     # This can happen if the database disappears mid
                     # transaction.
-                    logger.warning(
+                    transaction_logger.warning(
                         "[TXN OPERROR] {%s} %s %d/%d", name, e, i, N,
                     )
                     if i < N:
                         i += 1
                         try:
                             conn.rollback()
                         except self.engine.module.Error as e1:
-                            logger.warning("[TXN EROLL] {%s} %s", name, e1)
+                            transaction_logger.warning("[TXN EROLL] {%s} %s", name, e1)
                         continue
                     raise
                 except self.engine.module.DatabaseError as e:
                     if self.engine.is_deadlock(e):
-                        logger.warning("[TXN DEADLOCK] {%s} %d/%d", name, i, N)
+                        transaction_logger.warning(
+                            "[TXN DEADLOCK] {%s} %d/%d", name, i, N
+                        )
                         if i < N:
                             i += 1
                             try:
                                 conn.rollback()
                             except self.engine.module.Error as e1:
-                                logger.warning(
+                                transaction_logger.warning(
                                     "[TXN EROLL] {%s} %s", name, e1,
                                 )
                             continue
@@ -478,7 +478,7 @@ def new_transaction(
                     # [2]: https://github.com/python/cpython/blob/v3.8.0/Modules/_sqlite/cursor.c#L236
                     cursor.close()
         except Exception as e:
-            logger.debug("[TXN FAIL] {%s} %s", name, e)
+            transaction_logger.debug("[TXN FAIL] {%s} %s", name, e)
             raise
         finally:
             end = monotonic_time()
@@ -512,7 +512,7 @@ def runInteraction(self, desc: str, func: Callable, *args: Any, **kwargs: Any):
         exception_callbacks = []  # type: List[_CallbackListEntry]
 
         if not current_context():
-            logger.warning("Starting db txn '%s' from sentinel context", desc)
+            sql_logger.warning("Starting db txn '%s' from sentinel context", desc)
 
         try:
             result = yield self.runWithConnection(
@@ -550,7 +550,7 @@ def runWithConnection(self, func: Callable, *args: Any, **kwargs: Any):
         """
         parent_context = current_context()  # type: Optional[LoggingContextOrSentinel]
         if not parent_context:
-            logger.warning(
+            sql_logger.warning(
                 "Starting db connection from sentinel context: metrics will be lost"
             )
             parent_context = None
@@ -564,7 +564,7 @@ def inner_func(conn, *args, **kwargs):
                 context.add_database_scheduled(sched_duration_sec)
 
                 if self.engine.is_connection_closed(conn):
-                    logger.debug("Reconnecting closed database connection")
+                    sql_logger.debug("Reconnecting closed database connection")
                     conn.reconnect()
 
                 return func(conn, *args, **kwargs)
@@ -737,7 +737,7 @@ def simple_upsert(
                     raise
 
                 # presumably we raced with another transaction: let's retry.
-                logger.warning(
+                sql_logger.warning(
                     "IntegrityError when upserting into %s; retrying: %s", table, e
                 )