Любопытное поведение модуля syslog в шестом Друпале (баг?)

Submitted by Ромка on Втр, 13/03/2012 - 13:21

Ромка аватар
7875
Vote up!

Описание проблемы

На сайте используется 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, он пишет свои сообщения в системный журнал.

Небольшое отступление

Загрузка ядра Друпала выглядит примерно так:

  1. Много нужных, но неинтересных сейчас действий,
  2. загрузка модулей,
  3. выполнение всех hook_init (в том числе и themekey_init()),
  4. опять много нужных, но непринципиальных сейчас действий,
  5. вызов функции 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'ов),
  • исправить все ошибки, чтобы в лог нечего было писать.