From: Michael Tremer <michael.tremer@ipfire.org>
Date: Mon, 15 May 2023 17:03:59 +0000 (+0000)
Subject: database: Log runtime of SQL queries
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=f73b433c7d016f40bf96094274db40f76238a9d7;p=pbs.git

database: Log runtime of SQL queries

Signed-off-by: Michael Tremer <michael.tremer@ipfire.org>
---

diff --git a/src/buildservice/database.py b/src/buildservice/database.py
index ec474200..27db3806 100644
--- a/src/buildservice/database.py
+++ b/src/buildservice/database.py
@@ -11,6 +11,7 @@
 import itertools
 import logging
 import psycopg2
+import time
 
 # Setup logging
 log = logging.getLogger("pbs.database")
@@ -166,15 +167,30 @@ class Connection(object):
 		return self._db.cursor()
 
 	def _execute(self, cursor, query, parameters, kwparameters):
-		#log.debug("Executing SQL: %s" % (query % (kwparameters or parameters)))
+		log.debug(
+				"Executing query: %s" % \
+						cursor.mogrify(query, kwparameters or parameters).decode(),
+		)
+
+		# Store the time when the query started
+		t = time.monotonic()
 
 		try:
 			return cursor.execute(query, kwparameters or parameters)
+
+		# Catch any errors
 		except OperationalError:
 			log.error("Error connecting to database on %s", self.host)
 			self.close()
 			raise
 
+		# Log how long the query took
+		finally:
+			# Determine duration the query took
+			d = time.monotonic() - t
+
+			log.debug("Query took %.2fms" % (d * 1000.0))
+
 	def transaction(self):
 		return Transaction(self)