Не очевидные проблемы с быстродействием в Doctrine, связанные с гидрацией объектов

Недавно я реализовал функции API в проекте с бэк-эндом Symfony2, использущем Doctrine в качестве ORM.

И, как это иногда бывает, скороость отрабатывания не вполне меня устроила. На несложный запрос ответ генерировался аж 7,2 сек.

Первое предположение, где-то запускаются какие-то тяжелые запросы. Но через профайлер не видно ничего такого, что могло бы
навести на мысль о том, где скрылась проблема. SQL-запросов многовато, но все быстрые, и общее их время выполнения всего 223 милисекунды.

Иду в закладку Timeline — видно, что проблема возникает во время работы контроллера (там буквально 5 строк), но где именно — яснее не стало.

Что оказалось в итоге.

Оказалось, что для генерации данных некоторые модели (в глубине давно написанных сервисов) требовали связанные one-to-many объекты. Объект нужен был один, но для доступа к нему поднимался весь ArrayCollection из сотен объектов.

Т.е. некоторые из тех быстрых запросов возвращали сотни строк, на основе которых Doctrine поднимал сотни объектов, и на это уходила уйма ресурсов.

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

Хорошо бы все-таки это как-то контролировать.

Поэтому я сделал бандл, который собирает данные о времени гидрации объектов внутри Doctrine.

Думаю, может быть полезным для любого проекта, использующего связку Symfony2+Doctrine2.
debesha/DoctrineProfileExtraBundle (гитхаб)

После установки бандла в панели профайлера появляется дополнительный бадж, в котором видно, сколько было выполнено гидраций и сколько на это было потрачено времени:

Соответственно, профайлер в примере, который я привел в начале, выглядит уже более красноречиво — на гидрацию объектов потрачено 5,5 секунд.

И тоже самое, но после оптимизации (которая, как я уже сказал, была очень простой. Самое сложное было локализовать проблему).
Гидрация заняла 0.4 секунды (на моем медленном рабочем компе).

Надеюсь своим бандлом я сэкономлю кому-то из коллег кучу времени.

This entry passed through the Full-Text RSS service - if this is your content and you're reading it on someone else's site, please read the FAQ at http://ift.tt/jcXqJW.