У нас есть консьюмер очереди на PHP, который раньше раз в пять-шесть часов падал по OOMKilled на лимите 2 ГиБ. Сообщения при этом не терялись: Kubernetes поднимал под, и консьюмер дочитывал очередь, так что снаружи проблема была почти незаметна. Но регулярное падение по памяти — не норма, и мы решили докопаться до причины.

Спойлер: виноват оказался не наш код и не библиотеки, а поведение самого PHP после одной из ошибок расширения ext-soap. Баг известен с 2016 года, issue в php-src открыт с 2022-го, но описания того, как он выглядит в живом проекте и как его найти, я не нашёл. Поэтому пишу.

PHP 8.4, Symfony 6.4, RabbitMQ, Kubernetes. Примеры кода упрощены.

Симптом

На каждое сообщение консьюмер обращается во внешний сервис. Сервис отдаёт API по SOAP, поэтому вызов выглядит так:

$client = new SoapClient('https://partner.example/ws/service?wsdl', $options);
$result = $client->checkStatus($request);

Несколько сообщений в секунду на под. Память растёт линейно, около 120 МиБ в час, через 5–6 часов — OOMKilled.

Странности, которые мы заметили не сразу:

  • локально утечка не воспроизводилась никак — ни на стенде, ни при прогоне того же кода на записанных ответах сервиса, ни на настоящем RabbitMQ в течение пары часов;

  • в проде после старта пода память иногда стояла ровно 20–120 минут, а потом начинала расти — резко, в пределах пары минут;

  • соседние консьюмеры на том же коде и с тем же окружением не текли.

Попытка первая: обычные подозреваемые

Сначала проверили всё, что принято проверять в долгоживущих PHP-процессах: статические свойства, накопительные кеши в сервисах, EntityManager Doctrine, буферы логгера, буфер ошибок libxml. Сделали обход графа объектов от контейнера и стека — граф не растёт.

gc_collect_cycles() возвращал 0, gc_status()['roots'] всё время был 0. Мы прочитали это как «циклического мусора нет, значит, дело не в циклах» — и пошли дальше. Это была ошибка, к которой я ещё вернусь.

Попытка вторая: открытые каталоги

Зашли в под и посмотрели на дескрипторы процесса:

ls -l /proc/1/fd | awk '{print $NF}' | sort | uniq -c | sort -rn | head

Тысячи открытых дескрипторов на три каталога с классами внутри проекта. Нашлась фабрика такого вида:

final class HandlerFactory
{
    private static function classes(): \Generator
    {
        foreach (new \DirectoryIterator(__DIR__ . '/Handler') as $file) {
            if (!$file->isDot()) {
                yield __NAMESPACE__ . '\\Handler\\' . $file->getBasename('.php');
            }
        }
    }

    public static function create(string $name): Handler
    {
        foreach (self::classes() as $class) {
            if ($class::NAME === $name) {
                return new $class();
            }
        }

        throw new \InvalidArgumentException($name);
    }
}

Ранний return бросает генератор недоитерированным, внутри него остаётся DirectoryIterator с открытым каталогом. В норме генератор уничтожается, как только на него не остаётся ссылок, и каталог закрывается. В нашем проде — нет: каждый вызов фабрики оставлял открытый каталог, около 11 КБ памяти. Несколько вызовов на сообщение — и вот наши 120 МиБ в час.

Мы переписали фабрики на константы со списком классов, рост упал примерно в десять раз. Но не до нуля: осталось около 2 КБ на сообщение. И главный вопрос остался без ответа: почему генератор не уничтожается? Локально тот же код каталоги закрывал.

Попытка третья: memprof в проде

Поставили в прод memprof и сравнивали снимки memprof_dump_array() каждые 3000 сообщений. Рост давали ровно те места, где создаются генераторы:

  • замыкание, которое Symfony генерирует для !tagged_iterator (RewindableGenerator) — примерно по 176 байт на каждый вызов, около шести вызовов на сообщение;

  • замыкания, переданные в GuzzleHttp\Promise\Coroutine::of().

Причём генераторы полностью проходились до конца — не брошенные, не в циклах. Мы убрали генераторы из горячего пути, и рост упал ещё в несколько раз. Но вопрос «почему» стал только острее: соседний консьюмер создавал те же генераторы метрик (они срабатывают на каждый исходящий HTTP-запрос), делал это в четыре раза реже и всю ночь держал память ровно, с точностью до мегабайта. По нашей арифметике он должен был набрать 15 МиБ.

Значит, генераторы текут не везде. Что-то ломается в конкретном процессе.

Разгадка: gc_status()['protected']

Вернёмся к нулю в gc_status()['roots']. В здоровом процессе это число постоянно колеблется: каждый раз, когда счётчик ссылок объекта уменьшается, но не до нуля, объект попадает в буфер кандидатов на сборку. Ноль держится, только если сборщик отказывается принимать кандидатов. За это отвечает поле protected, которое мы раньше не выводили.

Механизм такой. Часть ошибок ext-soap поднимает как фатальные (E_ERROR) через свою функцию soap_error. Расширение оборачивает работу в zend_try/zend_catch, перехватывает фатальную ошибку и превращает её в обычный SoapFault. Процесс живёт дальше, следующие вызовы SOAP проходят нормально.

Но фатальная ошибка в движке заканчивается вызовом zend_bailout(), а он перед прыжком в zend_catch выставляет два глобальных флага, рассчитанных на то, что процесс сейчас завершится:

gc_protect(1);
CG(unclean_shutdown) = 1;

ext-soap после перехвата восстанавливает часть состояния, но эти два флага не сбрасывает. Результат:

  • gc_protect(1) — сборщик циклического мусора выключен до конца жизни процесса;

  • CG(unclean_shutdown) = 1 — движок считает, что процесс аварийно завершается, и не дочищает генераторы.

Это известная проблема: php-src#10026 «Garbage collection stops after exception in SoapClient» открыт в ноябре 2022 года для PHP 8.1, помечен как Verified. А в комментарии 2016 года к bug #66151 уже написано: «Looks like after SoapFault happens GC stops to work at all». На PHP 8.4.19 поведение то же.

Минимальное воспроизведение

Достаточно WSDL, который импортирует недоступную схему:

<?php

$wsdl = <<<'XML'
<?xml version="1.0" encoding="UTF-8"?>
<definitions xmlns="http://schemas.xmlsoap.org/wsdl/"
             xmlns:xsd="http://www.w3.org/2001/XMLSchema"
             xmlns:tns="urn:example" targetNamespace="urn:example">
    <types>
        <xsd:schema>
            <xsd:import namespace="urn:example" schemaLocation="http://127.0.0.1:1/schema.xsd"/>
        </xsd:schema>
    </types>
</definitions>
XML;

function report(string $label): void
{
    $before = memory_get_usage();
    $generator = function () { yield 1; };
    for ($i = 0; $i < 100_000; $i++) {
        foreach ($generator() as $value) {
        }
    }
    printf("%s: protected=%s, +%.1f MiB\n", $label,
        var_export(gc_status()['protected'], true),
        (memory_get_usage() - $before) / 1048576);
}

report('до ошибки');

try {
    new SoapClient('data://text/plain;base64,' . base64_encode($wsdl));
} catch (SoapFault $e) {
    echo $e->getMessage(), PHP_EOL;
}

report('после SoapFault');
gc_enable();
report('после gc_enable()');

до ошибки: protected=false, +0.0 MiB
SOAP-ERROR: Parsing Schema: can't import schema from 'http://127.0.0.1:1/schema.xsd'
после SoapFault: protected=true, +9.2 MiB
после gc_enable(): protected=true, +9.2 MiB

Сто тысяч генераторов, каждый пройден до конца, — и 9 МиБ, которые уже не вернуть. gc_enable(), gc_disable() + gc_enable(), ini_set('zend.enable_gc', …) флаг не снимают: они управляют другим состоянием. Функций, которые сняли бы protected или unclean_shutdown, в PHP нет.

Что именно течёт

Замер на PHP 8.4, по 100 000 объектов:

Что создаём

Всё в порядке

После SoapFault

генератор (любой, даже ни разу не запущенный)

0 Б

~100–130 Б на штуку

объект с циклической ссылкой

0 Б

~425 Б на штуку

обычный объект, замыкание

0 Б

0 Б

брошенный генератор с DirectoryIterator

каталог закрыт

каталог открыт

Деструкторы работают, обычные объекты освобождаются по счётчику ссылок. Циклы текут из-за выключенного сборщика. С генераторами сложнее: в цикл они не входят, и сборщик тут ни при чём. Их ломает второй флаг. Вот начало zend_generator_close(), которая вызывается, когда генератор завершается или уничтожается:

zend_free_compiled_variables(execute_data);
/* ... */

/* A fatal error / die occurred during the generator execution.
 * Trying to clean up the stack may not be safe in this case. */
if (UNEXPECTED(CG(unclean_shutdown))) {
    generator->execute_data = NULL;
    return;
}

zend_vm_stack_free_extra_args(execute_data);

if (UNEXPECTED(!finished_execution)) {
    zend_generator_cleanup_unfinished_execution(generator, execute_data, 0);
}

efree(execute_data);

Локальные переменные генератора освобождаются до проверки, поэтому деструкторы объектов в них срабатывают. А дальше функция выходит раньше времени:

  • efree(execute_data) не вызывается — каждый генератор оставляет в памяти свой фрейм, это и есть ~100–130 байт из таблицы;

  • zend_generator_cleanup_unfinished_execution() не вызывается — у брошенного генератора не освобождаются временные значения, в том числе итератор цикла foreach.

Последняя строка таблицы — наши открытые каталоги. new \DirectoryIterator(…) в заголовке foreach — временное значение, а не переменная, и после сбоя оно не освобождается никогда. Тот самый «код, который течёт только в проде», на самом деле не тёк. Он просто не переживал состояние процесса после ошибки SOAP.

Какие ошибки SOAP опасны

Не всякий SoapFault. Проверил локально, с подменённым транспортом (__doRequest):

Ситуация

Что получает код

Процесс

<soap:Fault> от сервера

SoapFault с текстом сервера

в порядке

HTML вместо XML (502 от балансировщика)

SoapFault: looks like we got no XML document

в порядке

пустой или обрезанный ответ

результат или тот же SoapFault

в порядке

xsd:import в WSDL не скачался

SOAP-ERROR: Parsing Schema: can't import schema …

сломан

в ответе неверный тип: элемент в строковом поле, текст в long

SOAP-ERROR: Encoding: Violation of encoding rules

сломан

в запросе нет обязательного поля

SOAP-ERROR: Encoding: object has no '…' property

сломан

Правило простое: опасны ошибки, текст которых начинается с SOAP-ERROR:. Это внутренние ошибки расширения, поднятые как фатальные и перехваченные им самим. Оба флага выставляются вместе, поэтому gc_status()['protected'] годится как индикатор и для второго.

Откуда ошибка бралась в проде

WSDL сервиса не содержал схему, а подключал её:

<types>
    <xsd:schema>
        <xsd:import namespace="urn:partner" schemaLocation="https://partner.example/ws/schema.xsd"/>
    </xsd:schema>
</types>

SoapClient у нас создавался на каждый вызов, WSDL скачивался через Guzzle, а схему ext-soap скачивал сам — через потоки libxml, мимо HTTP-клиента и его логов. Схема скачивалась на каждом вызове. Стоило одному скачиванию сорваться — и процесс до перезапуска жил в сломанном состоянии.

Прямых логов ошибки не было: код выше по стеку ловил \Throwable и превращал его в «попробуйте позже». Поэтому доказательства косвенные, но, по-моему, убедительные:

  • По метрикам памяти с шагом в 2 минуты нашли точные минуты, когда у подов начинался рост.

  • В логах исходящих запросов пода ровно в эти минуты есть вызовы, у которых WSDL скачан (200, полный размер), а POST к сервису так и не ушёл. Однажды — у трёх разных сообщений за 1,6 секунды на одном поде.

  • У тех же сообщений до и после этой минуты вызовы проходят нормально — значит, дело не в данных.

  • Пауза после WSDL такая же, как у нормальных вызовов, где за это время скачивается схема.

Отсюда и «память стоит час, а потом начинает расти»: рост начинался в момент первого сорвавшегося скачивания схемы. И отсюда же «локально не воспроизводится»: стабы отдавали WSDL со встроенной схемой, сбоев загрузки не было, процесс оставался здоровым.

Воспроизвести это на настоящем клиенте оказалось несложно: стаб сервиса, который отдаёт WSDL с xsd:import, и выключенный на один запрос эндпоинт схемы. До исправления — три запроса на вызов (WSDL, схема, POST) и сломанный процесс после сбоя. После — один POST и процесс в порядке.

Что мы сделали

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

$client = new SoapClient(__DIR__ . '/service.wsdl', [
    'location' => $config->serviceEndpoint(),
]);

Это заодно убрало два лишних HTTP-запроса на каждый вызов.

Начали логировать опасные ошибки. Все SoapFault с префиксом SOAP-ERROR: пишутся в лог на уровне error вместе с флагом gc_status()['protected'], на них настроен алерт. Обычные отказы сервера не логируются — это нормальная работа.

if (str_starts_with($fault->getMessage(), 'SOAP-ERROR:')) {
    $logger->error('SOAP internal error: ' . $fault->getMessage(), [
        'gc_disabled' => gc_status()['protected'],
    ]);
}

На будущее — если ошибки Encoding: Violation of encoding rules появятся в логах, у SoapClient есть опция typemap: разбор простых типов XSD можно отдать своим функциям, которые не падают на некорректных данных. На прототипе это убирает фатальную ошибку для ответов с неожиданными типами.

Итог по цифрам

Память контейнера

до всего

+~120 МиБ/ч, OOM каждые 5–6 часов

после исправления фабрик

+~10 МиБ/ч

после того, как убрали генераторы из горячего пути

+~1 МиБ/ч

после того, как убрали скачивание схем

сбоев загрузки схемы больше нет, память ровная

Что я вынес

  1. В долгоживущем PHP-процессе SOAP опасен не только медленными ответами. Одна ошибка SOAP-ERROR: навсегда оставляет процесс в состоянии «аварийного завершения»: сборщик мусора выключен, генераторы не дочищаются, и снаружи это никак не видно.

  2. gc_status() надо читать целиком. roots = 0 и collected = 0 не означают «мусора нет». Смотрите на protected: в рабочем процессе он всегда false.

  3. «Течёт только в проде» — повод искать разницу в состоянии процесса, а не в коде. Наш код был одинаковым; разным было то, случился ли в процессе хотя бы один сбой загрузки схемы.

  4. Не тяните схемы по сети в рантайме. WSDL и XSD внешнего сервиса лучше хранить рядом с кодом — это и быстрее, и надёжнее.

  5. Не глотайте исключения молча. catch (\Throwable) без лога превратил понятную ошибку в долгую загадку.

  6. Генераторы и замыкания в горячем пути долгоживущего процесса — не бесплатны, если что-то однажды сломает процесс. Мы убрали их из тех мест, где они создавались на каждое сообщение.

Если у вас есть долгоживущий PHP-процесс с SoapClient и непонятная утечка — проверьте gc_status()['protected']. Возможно, это сэкономит вам несколько недель.

Ссылки