Любопытное поведение модуля syslog в шестом Друпале (баг?)
Описание проблемы
На сайте используется Drupal 6 и модуль theme key, который позволяет задавать разный дизайн для разных страниц. Столкнулся с неприятной и трудноуловимой проблемой: есть 2 полностью идентично настроенных (как казалось изначально) сервера, на одном из которых theme key отрабатывает корректно, а на втором нет — все время отображает контент в дефолтной теме оформления. Похожая проблема также встречалась в другом проекте, не использующем theme key, на странице управления блоками.
После некоторых экспериментов удалось выяснить, что сервера отличаются настройкой PHP error_reporting. На глючащем сервере она была задана так:
error_reporting = E_ALL & ~E_DEPRECATED
на работающем так:
error_reporting = E_ALL & ~E_DEPRECATED & ~E_NOTICE
Обновление этой настройки на некорректно работающем сервере решало проблему. Может показаться что это магия какая-то, мне так изначально и показалось: ну какое отношение имеют сообщения, выводимые в лог, к работе модулей и выбору темы оформления Друпала? В итоге, оказалось, имеют самое непосредственное отношение. Ниже описание причины проблемы и её решение.
В Друпале с помощью PHP-шной функции set_error_handler задается собственный обработчик ошибок — функция drupal_error_handler. Эта функция, получив сообщение об ошибке, решает писать его в лог или нет, и, для записи в лог, вызывает функцию watchdog. Функция watchdog, в свою очередь, вызывает все зарегистрированные в системе хуки hook_watchdog.
По умолчанию в Друпале включен модуль dblog, реализующий этот хук, в нашем случае этот модуль был выключен, так как он пишет лог в БД, и при высокой посещаемости создает большую нагрузку на базу. Вместо dblog мы использовали другой ядерный модуль — syslog, он пишет свои сообщения в системный журнал.
Небольшое отступление
Загрузка ядра Друпала выглядит примерно так:
- Много нужных, но неинтересных сейчас действий,
- загрузка модулей,
- выполнение всех hook_init (в том числе и
themekey_init()), - опять много нужных, но непринципиальных сейчас действий,
- вызов функции
theme(), для отображения сгенерированной страницы.
В Друпале определяется переменная $theme, в которой хранится имя темы оформления, которая должна использоваться для отображения текущей страницы. По умолчанию, эта переменная определяется при первом вызове функции theme(), однако если к первому вызову этой функции переменная уже определена, то она не переопределяется. Этим и пользуется модуль themekey, определяя переменную $theme в своем hook_init до первого вызова функции theme(). При этом если переменная $theme уже определана до вызова themekey_init(), то модуль theme key её не переопределяет. В случае если Друпал работает без ошибок такая ситуация (определение переменной $theme до вызова themekey_init()) невозможна.
Причина и решение
Причина проблемы, с которой столкнулся я, состояла в том, что на этапе загрузки модулей возникала ошибка (даже не ошибка, а notice). Недостаток модуля syslog состоит в том, что он формирует строку, записываемую в лог, при помощи функции theme() (модуль dblog этого недостатка лишен), таким образом, если ошибка возникает до вызова themekey_init(), устанавливается дефолтная тема оформления, которую theme key уже не переопределяет.
У проблемы оказалось 3 решения (в порядке от худшего к лучшему):
- отключить syslog — не очень хорошее решение, так как лог таки нужен, а писать его в БД модулем dblog на больших объемах данных это очень дорогая операция,
- отключить вывод в лог некоторых типов ошибок (в моем случае notice’ов),
- исправить все ошибки, чтобы в лог нечего было писать.