Почему страница долго открывается?

14.04.2014

Про производительность уже говорилось много, но всегда есть, что сказать. Сегодня хочу показать, как можно относительно просто отловить достаточно сложную проблему через профилирование. Этот пост является продолжением повествования о модуле bitrix.xdebug, где я обещал рассказать о профилировщике.

Положим, ваш сайт или корпоративный портал работает на хорошем железе, оценка производительности нормальная. Конфигурация сервера правильная (хорошо, если это наша виртуальная машина или rpm). Но какая-то страница или сайт в целом работает неудовлетворительно. Куда двигаться в такой ситуации?

Сначала включаем режим отладки:


После обновления страницы увидим суммарную отладочную информацию внизу страницы:


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

По клику на "Время создания страницы" получим детальную раскладку:


Что делать, если основное торможение создает php код?
(как на моём примере выше)

Тогда поможет профилирование. Здесь я снова оговорюсь, что мы говорим о ситуации, когда система настроена хорошо.

Вот скриншот с этой же тестовой установки:


Если у вас на там есть что оптимизировать, говорить о профилировании рано.

Теперь нам потребуется модуль xdebug, который уже установлен на нашей виртуальной машине. Как включить этот модуль, написано тут.

Модуль xdebug умеет работать в режиме профилировщика, но для bitrix.xdebug нужен именно трейс!
Итак, ставим из marketplace бесплатный модуль bitrix.xdebug и получаем трейс проблемной страницы.
Все это делается в несколько кликов мышкой, весь процесс зафиксировал на скриншотах.

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


Потом включаем сбор трейсов, обновляем страницу, нажимаем Stop.



Получаем результат:


К слову сказать, для получения трейсов совсем не обязательно использовать bitrix.xdebug. Это можно сделать вручную вставив перед проблемным кодом или в самом начале проблемой страницы вызов:
Либо можно включить режим xdebug.auto_trace в php.ini. Подробнее об этом можно почитать в документации (англ.).

Далее выбираем режим профилирования:


При этом при первом открытии профилировщика файл будет индексироваться в базу данных, большие файлы обрабатываются по шагам:


У меня, например, не было проблем с обработкой файла 800 Мб.

Кстати, индексированные данные занимают сильно меньше, чем оригинальный файл. Например, данные из файла 24 Мб уместились в 1,4 Мб в БД. При этом происходит автоматическая очистка таблицы при удалении файла трейса через веб интерфейс модуля.

В результате получаем такую картину:


Каждая строчка завязана на вызов какой-то функции в конкретном месте кода. Если функция вызывалась в разных местах, это будут отдельные строки.
Однако, в фильтре можно включить группировку по имени функции, тогда место вызова функции учитываться не будет:


Здесь собственное время - это время работы самой функции, а интегральное время - это сумма времени выполнения всех вложенных функций.
Если функция вызывалась несколько раз, то обе цифры отражают суммарное время.

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

В моём примере сортировка по собственному времени сразу показывает, что основное время занимает работа функции fgets:

Когда группировка по имени функции не включена, можно нажать на имя функции и перейти в режиме отладки к позиции, где был наиболее долгий вызов.



И уже тут путем несложных умозаключений можно понять, что идет запрос к облаку 1С-Битрикс для получения информации о резервной копии.


И моя проблема решилась установкой лицензионного ключа (до этого стояло DEMO).

Понимая, как работает инструмент, можно решить практически любую задачу, когда торможение происходит на стороне php.
Это проще, чем кажется и может помочь избежать много часов отладки.