Перейти к содержимому
BXWiki

Ошибка сайта изнутри - слои запроса и их ответы

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

Механика

Запрос проходит слои строго по очереди. Фронтенд nginx принимает соединение, отдаёт статику и композитный HTML прямо из файлового кэша. Всё динамическое он проксирует на бэкенд: Apache на внутреннем порту 8090 либо пул PHP-FPM.

Бэкенд запускает интерпретатор и передаёт ему точку входа. Точкой входа служит физическая страница сайта или /bitrix/routing_index.php у проектов с роутингом. До этого момента платформа ещё не участвует в обработке вообще никак.

Дальше начинается платформа, и её пролог сам состоит из десятка стадий. Ядро читает dbconn.php, соединяется с базой, определяет сайт, подключает init.php, открывает сессию и авторизует посетителя. Только после проверки прав доступа стартует буферизация и управление уходит странице.

Каждый слой умеет ответить сам, не спрашивая следующий. Nginx отдаёт 502 и 504, когда бэкенд не ответил вовремя, и 403 по правилу запрета из своих конфигов. Такой ответ рождается за два слоя от кода, который винят по привычке.

Ответы слоёв различаются внешне, и это главный признак при разборе. Веб-сервер печатает собственную страницу, где в подвале стоят его имя и версия. Платформа отвечает шаблоном сайта, ставит куки сессии и добавляет свои заголовки.

Пятисотая ошибка приходит с двух разных слоёв, и здесь путаница возникает чаще всего. Директива php_value в .htaccess под FastCGI даёт 500 от веб-сервера, хотя интерпретатор при этом не запускался ни на секунду.

Журналы у слоёв тоже свои. Веб-сервер пишет в собственный error.log, обработчик PHP в журнал своего пула, платформа в файл из секции exception_handling. Один сбой оставляет след не во всех четырёх файлах сразу.

Записи об одном запросе расходятся по времени по трём причинам. Веб-сервер отмечает завершение запроса, обработчик PHP момент падения процесса, платформа момент перехвата исключения. Плюс журналы сервера ведутся по времени машины, а платформа пишет по времени сайта.

Обработку исключений задаёт секция exception_handling файла настроек ядра. Она хранит флаг подробностей, наборы перехватываемых типов ошибок и класс журнала. При выключенном флаге посетитель видит скупую страницу, а полный текст уходит в файл.

Исключение и фатальная ошибка расходятся по последствиям. Исключение всплывает по стеку, его ловит try/catch или обработчик ядра, и хит доигрывает эпилог до конца. Фатальная останавливает интерпретатор: буфер теряется, а тело ответа приходит пустым или обрезанным на середине.

Шаги

  1. Снять заголовки и первые строки тела ответа, чтобы понять, какой слой его сформировал.
  2. Найти запись про тот же запрос в журнале веб-сервера и сверить её время с ответом.
  3. Прочитать журнал обработчика PHP: фатальные ошибки лежат там с файлом и номером строки.
  4. Проверить журнал платформы и убедиться, что перехваченное исключение вообще туда попало.
  5. Определить стадию обрыва внутри платформы по меткам событий пролога и эпилога.

Код

Смотрим, кто сформировал ответ:

Окно терминала
curl -sI https://example.com/catalog/ | head -6    # код ответа, Server, куки
curl -s  https://example.com/catalog/ | head -20   # чей это шаблон страницы
curl -s  https://example.com/catalog/ | wc -c      # пустое тело при коде 200
# подвал с именем и версией сервера - ответ веб-сервера, платформа не работала
# куки сессии в заголовках означают, что пролог дошёл до её открытия
# заголовок Retry-After или страница шлюза - ответ фронтенда, а не приложения

Проверка делит слои надвое ещё до чтения журналов. Фирменная страница сервера без единой куки означает, что запрос до платформы не добрался и разбирать код решения бессмысленно.

Сверяем журналы слоёв по одному запросу:

Окно терминала
grep 'GET /catalog/' /var/log/nginx/access.log | tail -3   # завершение запроса
tail -50 /var/log/nginx/error.log                          # 502, 504 и отказы
tail -50 /var/log/httpd/error_log | grep -i 'php\|htaccess' # бэкенд Apache
tail -50 /var/log/php-fpm/bx0-error.log | grep -i fatal    # обрыв интерпретатора
tail -50 /home/bitrix/www/bitrix/modules/error.log         # перехват платформой
date; date -u                                              # сдвиг часового пояса

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

Читаем действующие настройки обработчика:

use Bitrix\Main\Config\Configuration;
print_r(Configuration::getValue('exception_handling'));
// debug - показ подробностей на экране, на боевом сайте только false
// handled_errors_types - какие типы ошибок попадают в журнал платформы
// exception_errors_types - какие типы превращаются в исключение

Настройки читают из кода, а не по памяти о содержимом файла. Секция приезжает и из .settings_extra.php, поэтому сам .settings.php показывает не то, что действует на сайте прямо сейчас.

Задаём вид ошибки на боевом сайте:

/bitrix/.settings.php
'exception_handling' => ['value' => [
    'debug' => false,          // посетитель видит скупую страницу без путей
    'handled_errors_types' => E_ALL & ~E_NOTICE & ~E_DEPRECATED,
    'exception_errors_types' => E_ALL & ~E_NOTICE & ~E_STRICT & ~E_DEPRECATED,
    'log' => [
        'settings' => ['file' => 'bitrix/modules/error.log'],
        'level' => E_ALL,      // порог записи, отдельный от показа на экране
    ],
]],

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

Старое ядро отвечает по своим правилам:

/bitrix/php_interface/dbconn.php
$DBDebug = false;              // подробный текст ошибки базы на экран
$DBDebugToFile = false;        // тот же текст в файл вместо экрана
// свои страницы отказа лежат рядом: dbconn_error.php при обрыве соединения
// и dbquery_error.php при отклонённом запросе к базе данных

Ошибки базы идут мимо секции обработки исключений целиком. Их вид задают эти две переменные и два файла страниц, поэтому сообщение про соединение с базой выглядит иначе, чем любое исключение ядра.

Ловим исключение и не ловим фатальную ошибку:

try {
    \Bitrix\Main\Loader::requireModule('vendor.crm');   // бросает LoaderException
} catch (\Throwable $e) {
    AddMessage2Log($e->getMessage(), 'vendor.crm');     // хит продолжается дальше
}
\CVendorCrm::send();          // класса нет: фатальная, перехват уже не поможет
// исключение попадает в журнал платформы, фатальная - ещё и в журнал обработчика

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

Отмечаем стадии пролога и эпилога:

/local/php_interface/init.php
function TraceStage($stage) { AddMessage2Log($stage . ' ' . $_SERVER['REQUEST_URI'], 'trace'); }
function TraceStart()  { TraceStage('OnPageStart'); }
function TraceProlog() { TraceStage('OnBeforeProlog'); }
function TraceEpilog() { TraceStage('OnEpilog'); }
AddEventHandler('main', 'OnPageStart', 'TraceStart');
AddEventHandler('main', 'OnBeforeProlog', 'TraceProlog');
AddEventHandler('main', 'OnEpilog', 'TraceEpilog');

Последняя дошедшая метка называет стадию обрыва внутри платформы. Метка пролога без метки эпилога означает падение в теле страницы, а полное отсутствие меток - обрыв ещё до подключения init.php.

Отдаём свой код ответа из прикладного кода:

\CHTTP::SetStatus('404 Not Found');                    // старое ядро
include $_SERVER['DOCUMENT_ROOT'] . '/404.php';       // тело рисует шаблон сайта
// D7: $response = \Bitrix\Main\Application::getInstance()->getContext()->getResponse();
//     $response->setStatus('404 Not Found');

Код ответа платформы виден снаружи так же, как код веб-сервера. Разбор путает их постоянно: тело рисует шаблон сайта, а сама цифра приходит из строки прикладного кода на несколько слоёв ниже.

Ограничения

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

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

Ошибка в самом файле настроек кладёт систему целиком и сразу. Платформа не стартует, обработчик ошибок не подключается, и разбирать приходится уже по журналу обработчика PHP.

Фоновые задания выполняются после отдачи ответа посетителю. Их записи ложатся в журнал позже строки веб-сервера про тот же запрос и выглядят следом чужого обращения.

Композитный кэш отдаётся напрямую фронтендом, минуя PHP и платформу. Свежая ошибка в коде тогда не воспроизводится с первого раза: посетителю пришёл готовый HTML из файлового кэша.

Типичные проблемы

Админка работает, а публичная часть отдаёт 500.

Ошибка живёт в коде шаблона сайта или в обработчике события публичной части. Раздел управления идёт мимо шаблона сайта, поэтому тот же сбой там не проявляется.

Один адрес отдаёт 404 сервера, другой - 404 платформы.

Правило переадресации на обработчик ЧПУ настроено не для всех несуществующих путей. Запрос без такого правила обрывается на веб-сервере и до платформы вообще не доходит.

В журнале платформы пусто, а сайт падает.

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

Время в журналах расходится на несколько часов.

Журналы сервера ведутся по времени машины, а платформа пишет по времени сайта. Записи об одном запросе разъезжаются, и единый сбой выглядит как два независимых.

Пятисотая появилась сразу после правки .htaccess.

Директивы php_value и php_flag работают только при PHP как модуле Apache. Под FastCGI и PHP-FPM тот же файл даёт 500 от веб-сервера, а не от платформы.

Страница обрывается на середине с кодом 200.

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

Частые вопросы

Как понять, кто отдал ошибку - сервер или Битрикс?

По заголовкам и телу ответа: веб-сервер печатает свою страницу с именем и версией в подвале. Платформа отвечает шаблоном сайта и ставит куки сессии.

Почему в одном журнале ошибка есть, а в другом нет?

Каждый слой пишет только про то, что видел сам. Обрыв до запуска PHP не оставит следа у платформы, а исключение внутри кода не попадёт в журнал веб-сервера.

Чем фатальная ошибка отличается от исключения?

Исключение всплывает по стеку, его ловит try/catch или обработчик ядра, и хит доигрывает эпилог. Фатальная останавливает интерпретатор: буфер теряется, тело ответа приходит пустым.

Что видит посетитель вместо текста ошибки?

Скупую страницу без путей и стека вызовов: за это отвечает выключенный флаг подробностей. Полный текст в это же время уходит в журнал платформы.

Включил показ ошибок, а на экране ничего не изменилось - почему?

Флаг платформы влияет только на перехваченные ею ошибки. Фатальная ошибка печатается по настройкам самого интерпретатора, а обрыв до ядра не её забота вовсе.

Смежное

Первоисточник