Отладка и логирование

Немного теории

Отладка PHP

В мире веб-разработки существует несколько устоявшихся практик отладки приложений. Разработчики платформы «1С-Битрикс: Управление сайтом» учли это и вам не придется самим печатать var_dump в файл через fwrite.

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

Помимо стандартных функций PHP print_r, var_dump, var_export в API платформы доступны функция mydump и метод Debug::dump.

Трейс

В обработчиках событий или API-вызовах бывает важно, в целях отладки, узнать, как интерпретатор PHP пришел к выполнению текущей строки. Для этой цели подойдут стандартная функция PHP debug_backtrace и метод платформы \Bitrix\Main\Diag\Helper::getBackTrace. Метод возвращает массив, описывающий все предыдущие вызовы методов и функций, предшествовавшие текущей позиции в коде.

Данные из трейса читаются с конца массива к его началу (при распечатке на экране — снизу вверх). У каждого шага трейса указывается путь к файлу file, номер строки line и функция function, которая была там вызвана.

Лог-файлы

Для случаев, когда отладить нужно код, исполняемый для другого пользователя, а также при работе на боевой версии сайта, используют печать отладочной информации в лог-файлы. Системные методы для этой операции: Debug::writeToFile (печать в файл функцией print_r), Debug::dumpToFile (печать в файл функцией var_dump) и AddMessage2Log.

Методам класса Debug можно сообщить, в какой файл вести печать, а если пропустить этот аргумент, печать будет произведена в файл __bx_log.log в корне сайта. Поэтому всегда проверяйте, чтобы файлы __bx_log.log были закрыты от просмотра средствами браузера.

Функция AddMessage2Log не принимает путь к файлу, он задается константой LOG_FILENAME в файле конфигурации dbconn.php. Если константа не будет объявлена, отладочная печать будет отменена.

Созданные файлы хранят важную техническую информацию о работе сервера и сайта, и должны быть защищены от просмотра средствами браузера, чтобы не выдать информацию злоумышленнику, который случайным образом попробует получить доступ через протокол HTTP ко всем распространенным вариантам наименований лог-файлов. Для сервера Apache ограничение доступа нужно установить с помощью файла .htaccess в корне сайта.

Тогда доступ к лог-файлам будет либо через административный раздел сайта и функции работы с файловой системой, либо через панель управления хостингом, либо по SSH/SFTP.

Также нужно помнить, что отладочную информацию иногда может выводить и сама платформа. Для предотвращения этого всегда выключайте режим отладки в .settings.php по ключу “exception_handling > debug”.

Для удобства разработчика рекомендуем всегда добавлять в лог-файл следующие данные:

• __FILE__ — путь к файлу, откуда происходит логирование
• __LINE__ — номер строки в файле, откуда происходит логирование
• Текущие дата и время

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

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

• microtime — функция PHP, возвращает системное время с миллисекундами
• hrtime — функция PHP, возвращает системное время повышенной точности
• Helper::getCurrentMicrotime — возвращает текущую метку времени Unix с микросекундами
• Debug::startTimeLabel — определяет начало именованного периода отладки
• Debug::endTimeLabel — определяет конец именованного периода отладки
• Debug::getTimeLabels — возвращает перечень всех периодов отладки с указанием продолжительности

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

Для контроля за памятью PHP можно использовать функцию memory_get_usage. Функция возвращает текущее количество выделенной для PHP-скрипта памяти. Возьмите за правило при проблемах с выделением памяти делать замеры с помощью memory_get_usage незадолго до места предполагаемой ошибки.

Обработка исключений

По ключу “exception_handling > log” в файле .settings.php можно задать механизм обработки исключительных ситуаций. В простом случае это массив с настройками file (путь к файлу лога исключений) и log_size (размер файла лога для ротации).

Если в корне сайта лежит файл error.php и отключен вывод ошибок на экран, то этот файл будет подключен в случае возникновения необработанного исключения.

Можно изменить файловый лог на произвольный, если задать в ключе class_name название класса-наследника ExceptionHandlerLog.

Журналирование ошибок

Лог-файлы — самый простой способ накопления отладочной информации для ее дальнейшего использования. В платформе «1С-Битрикс: Управление сайтом» в БД существует Журнал событий для регистрации всех нештатных или важных ситуаций. Если речь не идет о частой записи больших объемов данных, то можно воспользоваться методом CEventLog::Add или CEventLog::Log (обертка над CEventLog::Add).

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

• ID пользователя
• User agent-информацию о браузере
• IP-адрес пользователя
• URL страницы

Прямо в интерфейсе Журнала событий можно настроить правила оповещения по E-mail и СМС для администратора сайта, чтобы сразу узнавать о проблемах на сайте.

Отладка с помощью Xdebug

В сложных случаях, когда возможностей логирования недостаточно и хочется отлаживать работу PHP-скрипта построчно, в решении проблемы поможет дополнительное расширение Xdebug.

Xdebug нельзя устанавливать на боевом сервере, т.к. он вмешивается в работу PHP и замедляет его. Используйте его только на копии сайта для разработчика.

Выполнив настройку, можно подключить свою IDE и использовать привычные для десктопной разработки пошаговые действия отладчика.

Отладка SQL

Особый вид отладочных ситуаций — работа с SQL-запросами к БД. Даже если не использовать собственные запросы, а ограничиться готовыми методами ORM, иногда запросы выдают, на первый взгляд, некорректную информацию. Чтобы узнать, какой запрос сформировал API платформы, используйте пару методов \Bitrix\Main\DB\Connection::startTracker и \Bitrix\Main\DB\Connection::stopTracker.

Метод startTracker запустит сбор SQL-запросов. По его окончании, после вызова stopTracker вы сможете получить текст выполненных запросов методом \Bitrix\Main\Diag\SqlTracker::getQueries. Например, для сохранения его в лог-файл или Журнал событий.

При включении трекера, каждый запрос, осуществленный методом \Bitrix\Main\DB\Connection::queryInternal() (ядро D7) будет записываться, также будут записаны время начала и окончания запроса. Поэтому не все запросы осуществленные через старое ядро можно будет отследить таким образом.

Схожие возможности дает Монитор производительности. Запустить монитор можно вручную в административном разделе в двух режимах — полный сбор всех SQL-запросов в течение часа или сбор только медленных запросов в течение недели. Все собранные запросы сохраняются в БД модуля и будут доступны к просмотру администратором сайта на странице “Настройки > Производительность > Запросы SQL”.

Если объявить в dbconn.php переменную $DBDebugToFile как true, все SQL запросы к базе данных и время их выполнения будут записываться в лог-файл /mysql_debug.sql. Ведение такого лога может серьезно замедлить работу сайта, поэтому пользоваться этим стоит кратковременно.