Анализ некоторых python ORM на непроизводительные расходы
Введение
При разработке приложения на python django, я столкнулся с его неадекватным торможением.
После нескольких попыток улучшить довольно сложные алгоритмы расчетов, я обратил внимание, что существенные улучшения этих алгоритмов приводили к весьма скромному результату — из чего я сделал вывод, что узкое место вовсе не в алгоритмах.
Последующий анализ показал, что действительно, основным непроизводительным потребителем ресурсов процессора оказался django ORM, который был использован для доступа к данным, необходимым при расчетах.
Заинтересовавшись этим вопросом, я решил проверить, каковы непроизводительные расходы при использовании ORM. Для получения результата, я использовал самую элементарную операцию: получение username первого и единственного пользователя в только что созданной новой базе данных.
В качестве базы данных, использовался MySQL, расположенный на localhost (таблицы MyISAM).
В качестве исходного “примера для подражания”, я использовал код, минимально использующий специфику django и почти оптимально получающий необходимое значение:
def test_native():
from django.db import connection, transaction
cursor = connection.cursor()
t1 = datetime.datetime.now()
for i in range(10000):
cursor.execute("select username from auth_user limit 1")
f = cursor.fetchone()
u = f[0][0]
t2 = datetime.datetime.now()
print "native req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
t1 = datetime.datetime.now()
for i in range(10000):
cursor.execute("select username,first_name,last_name,email,password,is_staff,is_active,is_superuser,last_login,date_joined from auth_user limit 1")
f = cursor.fetchone()
u = f[0][0]
t2 = datetime.datetime.now()
print "native (1) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
t1 = datetime.datetime.now()
for i in range(10000):
cursor = connection.cursor()
cursor.execute("select username,first_name,last_name,email,password,is_staff,is_active,is_superuser,last_login,date_joined from auth_user limit 1")
f = cursor.fetchone()
u = f[0][0]
t2 = datetime.datetime.now()
print "native (2) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
Результат выполнения данного кода:
>>> test_native() native req/seq: 8873.05935101 req time (ms): 0.1127007 native (1) req/seq: 5655.73751948 req time (ms): 0.1768116 native (2) req/seq: 3815.78751558 req time (ms): 0.2620691
Таким образом, оптимальный “образец” дает около 8 с половиной тысяч обращений к БД в секунду.
Обычно, django и другие ORM тянут за собой получение других атрибутов объекта при получении его из БД. Как легко заметить, получение “паровоза” из остальных полей таблицы довольно сильно ухудшило результат: до 5 с половиной тысяч запросов в секунду. Впрочем, это ухудшение относительно, поскольку часто для получения результата расчетов требуется более одного поля данных.
Довольно тяжелой оказалась операция получения нового курсора — она занимает около 0.1ms и ухудшает скорость выполнения кода почти в 1.5 раза.
Возьмем например второй результат за образец и посмотрим, какие потери добавляет ORM к полученным показателям.
Django ORM
Выполним несколько вариантов запросов, начиная от самых простых, и пытаясь последовательно использовать средства django для оптимизации запросов.
Вначале выполним самый неприхотливый код получения нужного атрибута, начав непосредственно с типа User.
Затем попробуем улучшить результат, предварительно сохранив объект запроса.
Затем вспомним об использовании метода only() и попробуем еще улучшить результат.
И наконец, еще один вариант попытки улучшить положение — использование метода values() который исключает необходимость создания целевого объекта.
Вот итоговый код, проверяющий результат наших усилий:
def test_django():
t1 = datetime.datetime.now()
for i in range(10000):
u = User.objects.all()[0].username
t2 = datetime.datetime.now()
print "django req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
t1 = datetime.datetime.now()
q = User.objects.all()
for i in range(10000):
u = q[0].username
t2 = datetime.datetime.now()
print "django (1) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
t1 = datetime.datetime.now()
q = User.objects.all().only('username')
for i in range(10000):
u = q[0].username
t2 = datetime.datetime.now()
print "django (2) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
t1 = datetime.datetime.now()
q = User.objects.all().values('username')
for i in range(10000):
u = q[0]['username']
t2 = datetime.datetime.now()
print "django (3) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
Результаты выполнения обескураживают:
>>> test_django() django req/seq: 1106.3929598 req time (ms): 0.903838 django (1) req/seq: 1173.20686476 req time (ms): 0.8523646 django (2) req/seq: 695.949871009 req time (ms): 1.4368851 django (3) req/seq: 1383.74156246 req time (ms): 0.7226783
Во-первых, использование ORM само по себе ухудшило производительность более чем в 5 раз (!) по сравнению даже с неоптимальным “образцом”. Перенос подготовки запроса за пределы цикла не сильно (менее чем на 10%) улучшило результат. А вот использование only() и вовсе испортило картину — мы видим ухудшение результата почти в 2 раза, вместо ожидаемого улучшения. При этом, что интересно, исключение создания объекта помогло увеличить производительность на 20%.
Таким образом, django ORM дает увеличение непроизводительных расходов приблизительно на 0.7226783-0.1768116=0.5458667ms на получение одного объекта.
Опуская дальнейшие эксперименты, потребовавшие создания дополнительных объектов и таблиц, сообщаю, что данные результаты также верны и для получения списка объектов: получение каждого отдельного объекта коллекции объектов, которая является результатом выполнения одного запроса, приводит к потерям порядка полумиллисекунды и более на каждом объекте.
В случае использования MySQL, эти потери составляют замедление выполнения кода более чем в 5 раз.
SQLAlchemy
Для SQLAlchemy я создал класс AUser, декларативно объявляющий структуру данных, соответствующую стандартному классу django.contrib.auth.models.User.
Для достижения максимальной производительности, после вдумчивого чтения документации и некоторых экспериментов, был использован простой кэш запросов:
query_cache = {}
engine = create_engine('mysql://testalchemy:testalchemy@127.0.0.1/testalchemy', execution_options={'compiled_cache':query_cache})
Тестирование производительности выполняется сначала на “лобовом” варианте доступа к объекту.
Затем производится попытка оптимизации за счет выноса подготовки запроса за пределы цикла.
Затем производится попытка оптимизации за счет исключения создания целевого объекта.
Затем мы еще оптимизируем запрос, ограничивая набор запрашиваемых полей.
def test_alchemy():
t1 = datetime.datetime.now()
for i in range(10000):
u = session.query(AUser)[0].username
t2 = datetime.datetime.now()
print "alchemy req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
q = session.query(AUser)
t1 = datetime.datetime.now()
for i in range(10000):
u = q[0].username
t2 = datetime.datetime.now()
print "alchemy (2) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
from sqlalchemy.sql import select
table = AUser.__table__
sel = select([table],limit=1)
t1 = datetime.datetime.now()
for i in range(10000):
u = sel.execute().first()['username']
t2 = datetime.datetime.now()
print "alchemy (3) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
table = AUser.__table__
sel = select(['username'],from_obj=table,limit=1)
t1 = datetime.datetime.now()
for i in range(10000):
u = sel.execute().first()['username']
t2 = datetime.datetime.now()
print "alchemy (4) req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
Вот результаты тестирования:
>>> test_alchemy() alchemy req/seq: 512.719730527 req time (ms): 1.9503833 alchemy (2) req/seq: 526.34332554 req time (ms): 1.8999006 alchemy (3) req/seq: 1341.40897306 req time (ms): 0.7454848 alchemy (4) req/seq: 1995.34167532 req time (ms): 0.5011673
В первых двух случаях, алхимия не кешировала запросы, несмотря на их идентичность (я нашел — почему именно, но разработчики пока предлагают заглушить это какой-то затычкой, которую потом обещают воткнуть в код, я не стал этого делать). Кешированные запросы позволяют алхимии на 30%-35% превзойти django ORM по производительности.
Сразу отмечу, что SQL, сгенерированный django ORM и SQLAlchemy практически идентичный и вносит минимум искажений в тест.
ORM на коленке
Естественно, после таких результатов мы переделали весь наш код, получавший данные в алгоритмах обработки, на прямые запросы. Работать с кодом, осуществляющим прямые запросы, неудобно — поэтому мы обернули наиболее часто выполняемые операции в простенький класс, выполняющий задачи, сходные с ORM:
class S:
def __init__(self,**kw):
self.__dict__.update(kw)
@classmethod
def list_from_cursor(cls,cursor):
return [cls(**dict(zip([col[0] for col in cursor.description],row))) for row in cursor.fetchall()]
@classmethod
def from_cursor(cls,cursor):
row = cursor.fetchone()
if row:
return cls(**dict(zip([col[0] for col in cursor.description],row)))
def __str__(self):
return str(self.__dict__)
def __repr__(self):
return str(self)
def __getitem__(self,ind):
return getattr(self,ind)
Померяем потери производительности, вносимые использованием данного класса.
def test_S():
from django.db import connection, transaction
import util
cursor = connection.cursor()
t1 = datetime.datetime.now()
for i in range(10000):
cursor.execute("select * from auth_user limit 1")
u = util.S.from_cursor(cursor).username
t2 = datetime.datetime.now()
print "S req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
t1 = datetime.datetime.now()
for i in range(10000):
cursor.execute("select username from auth_user limit 1")
u = util.S.from_cursor(cursor).username
t2 = datetime.datetime.now()
print "S opt req/seq:",10000/(t2-t1).total_seconds(),'req time (ms):',(t2-t1).total_seconds()/10.
Результаты тестирования:
>>> test_S() S req/seq: 4714.92835902 req time (ms): 0.2120923 S opt req/seq: 7473.3388636 req time (ms): 0.133809
Как видим, потери весьма скромны: 0.2120923-0.1768116=0.0352807ms в неоптимальном случае и 0.133809-0.1127007=0.0211083ms в оптимальном. Замечу, что в нашем ORM, сделанном на коленке, создается полноценный объект python.
Общий вывод
Использование мощных универсальных ORM приводит к очень заметным потерям производительности. В случае использования быстрых движков СУБД, таких как MySQL — производительность доступа к данным снижается более чем в 3-5 раз. Потери производительности составляют около 0.5ms и более на обращение к одному объекту на платформе Intel® Pentium® Dual CPU E2200 @ 2.20GHz.
Существенную часть потерь составляет создание объекта из строки данных, полученных из БД: примерно 0.1ms. Еще 0.1ms отъедает создание курсора, избавиться от которого в ORM довольно сложно.
Происхождение остальных потерь осталось неизвестным. Можно лишь предположить, что достаточно большой объем потерь может быть вызван количеством вызовов при обработке результата — за счет абстрагирования слоев обработки данных.
Для достижения адекватной производительности, разработчики ORM должны иметь в виду потери на прохождении кода слоев абстракции, на конструировании запроса и на других операциях, специфических для ORM. Действительно производительный ORM должен предусматривать возможность для разработчика, использующего этот ORM, единожды подготовить параметризованный запрос и затем использовать его с различными параметрами с минимальным влиянием на общую производительность. Одним из способов реализации такого подхода является использование некоторого кэша для сгенерированных выражений SQL и хендлов подготовленных запросов, специфических для нижележащей СУБД. К моему удивлению, несмотря на то, что такая оптимизация сделана в SQLAlchemy, производительность все равно страдает, хотя и несколько менее сильно.
Для меня лично — осталось загадкой, откуда берутся еще 0.3-0.4ms потерь при чтении одного объекта на обоих ORM. Характерным является то, что оба ORM практически одинаково непроизводительно тратят ресурсы процессора. Это заставляет думать, что потери вызваны не какими-то локальными проблемами ORM (как отсутствие кеша подготовленных запросов у django), а архитектурными элементами, которые вероятно одинаковы у обоих ORM. Буду благодарен сообществу за профессиональные комментарии.
Автор: nnseva
