13g10n
Напишите мне
На главную

Профайлинг запросов SQLAlchemy

•2 минуты

Сегодня мы рассмотрим важнейшую для качественной разработки тему — профайлинг запросов в базу данных.

Я нарочно буду игнорировать flask debug toolbar и подобное (там ещё и полная зависимость от flask-sqlalchemy), т.к. целью ставлю не указать на конкретную затычку, а показать общее решение под алхимию для любой архитектуры и фреймворков.

В идеальном мире (особенно глазами джунов и людей прошедших курс "от кассира до веб-разработчика за 5 дней 🤑") наши страницы или API эндпоинты делают один-два запроса, которые выполняются 0 миллисекунд и отдают данные украшенные ленточкой написанных БД моделей.

В действительности же тема достаточно обширная и требует куда больше внимания (которое я конечно же буду уделять по мере выхода нового материала). А первым шагом на пути предотвращения ситуации, где ленточка на ваших запросах становится чёрно-золотой, и будет перехват и логирование данных о запросах.

В первую очередь, нас интересует количество и время этих самых запросов (посмотреть сформированный SQL можно и простейшим дебагом). Перехватываем ивенты алхимии до и после выполнения запроса, добавляем туда контекст с временем старта и считаем дельту на финише:

import time
import logging

from sqlalchemy import event
from sqlalchemy.engine import Engine


logging.basicConfig()
logger = logging.getLogger('SQL Profiler')
logger.setLevel(logging.DEBUG)


@event.listens_for(Engine, 'before_cursor_execute')
def before_cursor_execute(conn, cursor, statement, parameters, context, executemany):
    conn.info.setdefault('query_start_time', []).append(time.time())


@event.listens_for(Engine, 'after_cursor_execute')
def after_cursor_execute(conn, cursor, statement, parameters, context, executemany):
    total = time.time() - conn.info['query_start_time'].pop(-1)
    logger.debug(f'Time: {total:.5f}')

Причем данных у нас действительно достаточно, мы можем даже выводить сам запрос или его часть (Боже, храни стандартную библиотеку python!)

logger.debug(f'Time: {total:.5f} — {textwrap.shorten(statement.replace("\n", " "), width=128, placeholder="...")}')

Я сейчас готовлю достаточно объёмный материал о настройке мультиязычного контента в Iles, да и основной работы мягко говоря не мало, поэтому посты будут выходить не так часто, как мне бы того хотелось.

Python
SQLAlchemy