I'm trying to get the performance statistics on queries executed by psycopg2, but the documentation / examples still seem fuzzy and not as clear as it could be.
I've at least got debugging working through the logger. What would I need to do to access the performance data for the query? I'm wanting to get the number for query execution time.
Is there a method I can access, or something else I need to initialize to output the query execution time?
Here's a pieced together extract of what I have so far:
import psycopg2
import psycopg2.extensions
from psycopg2.extras import LoggingConnection
import logging
logging.basicConfig(level=logging.DEBUG)
logger = logging.getLogger(__name__)
# set higher up in script
db_settings = {
"user": user,
"password": password,
"host": host,
"database": dbname,
}
query_txt = "[query_txt_from file]"
conn = psycopg2.connect(connection_factory=LoggingConnection, **db_settings)
conn.initialize(logger)
cur = conn.cursor()
cur.execute(query_txt)
and I get
DEBUG:__main__: [the query executed]
In PostgreSQL, execution time for this query is 3.4 seconds, so optimization is required.
Asynchronous notificationsPsycopg allows asynchronous interaction with other database sessions using the facilities offered by PostgreSQL commands LISTEN and NOTIFY.
The Cursor class of the psycopg library provide methods to execute the PostgreSQL commands in the database using python code. Using the methods of it you can execute SQL statements, fetch data from the result sets, call procedures. You can create Cursor object using the cursor() method of the Connection object/class.
Thread and process safetyThe Psycopg module and the connection objects are thread-safe: many threads can access the same database either using separate sessions and creating a connection per thread or using the same connection and creating separate cursors.
Easy enough to set timestamp at start of execution and calculate duration at end. You'll need your own simple subclasses of LoggingConnection and LoggingCursor. See my example code.
This is based on source of MinTimeLoggingConnection you can find in psycopg2/extras.py
source.
import time
import psycopg2
import psycopg2.extensions
from psycopg2.extras import LoggingConnection, LoggingCursor
import logging
logging.basicConfig(level=logging.DEBUG)
logger = logging.getLogger(__name__)
# MyLoggingCursor simply sets self.timestamp at start of each query
class MyLoggingCursor(LoggingCursor):
def execute(self, query, vars=None):
self.timestamp = time.time()
return super(MyLoggingCursor, self).execute(query, vars)
def callproc(self, procname, vars=None):
self.timestamp = time.time()
return super(MyLoggingCursor, self).callproc(procname, vars)
# MyLogging Connection:
# a) calls MyLoggingCursor rather than the default
# b) adds resulting execution (+ transport) time via filter()
class MyLoggingConnection(LoggingConnection):
def filter(self, msg, curs):
return msg + " %d ms" % int((time.time() - curs.timestamp) * 1000)
def cursor(self, *args, **kwargs):
kwargs.setdefault('cursor_factory', MyLoggingCursor)
return LoggingConnection.cursor(self, *args, **kwargs)
db_settings = {
....
}
query_txt = "[query_text_from file]"
conn = psycopg2.connect(connection_factory=MyLoggingConnection, **db_settings)
conn.initialize(logger)
cur = conn.cursor()
cur.execute(query_text)
and you'll get:
DEBUG: __main__:[query] 3 ms
within your filter()
you can change the formatting, or choose to not display, if less than some value.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With