История поиска бага в ядре Linux длиной в год, или нежданные нули из XFS'а / Хабр

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

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

В этой статье описано наше исследование длиною в год, из которого вы узнаете, почему PostgreSQL(и любое другое приложение) может падать из-за бага в ядре Linux, причём тут XFS и почему очистка памяти может быть не так полезна, как вы о ней думали.

Как всё начиналось

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

Итак, к нам иногда приходили клиенты, и не только они, с описанием проблемы на уровне «Оно всё работало, а потом без видимой причины упало. Мы кое-как подняли, оно продолжает работать, но хочется понять что это было». Не массово, не часто, а просто иногда приходили. Никто толком не понимал, что именно сломалось, потому что видимых причин не было. И всё было бы хорошо, пока таких обращений не накопилось некоторое количество, после чего стало очевидно, что пора уже разобраться и с этой тайной мироздания.

Итак, что имеем на входе в первый момент времени, после такого типового обращения от не слишком довольных клиентов:

с грохотом падающие кластеры (и отдельные инсталляции) постгреса разных версий, ванильные и не только. Где сегфолт (segfault), где просто процесс схлопнулся;
серверы с разными версиями ядра Linux;
зоопарк установленного софта c самыми разными настройками, полями и флагами, включая настройки ядра ОС;
в логах — ошибки об обращениях к некорректным адресам памяти;
попытки передать управление в защищённые сегменты памяти;
попытки выполнения недопустимых инструкций;
софт падаёт в рандомный момент времени, без каких-то очевидных причин, которые можно систематизировать каким-то очевидным образом. Хоть начинай искать связь с фазами Луны или положением планет Солнечной системы

И ещё была очень важная общая для всех особенность: анализ дампов и диагностических данных указывал на что угодно, кроме постгреса. А мы хоть и разработчики СУБД, но профессиональное любопытство взяло верх, поэтому приняли решение идти до конца.

Ищем зацепки

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

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

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

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

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

Так и что же случилось?

Про конкретные сценарии для воспроизведения поговорим чуть ниже, а пока разберёмся с тем, что случилось. Мы смогли подтвердить версию, что суть проблемы заключается в получении некорректных нулевых данных со страниц памяти для отображаемых в них файлов (mmap). Не важно, читаем ли мы просто данные или исполняемый код. То есть баг был именно на уровне ядра ОС.

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

Вообще mmap — это механизм отображения файлов в память, и он появился ещё в UNIX где-то в начале 1990-х и тогда же был реализован в ядре Linuх. Его история начиналась с BSD-систем из 1980-х, так что это абсолютно базовая функциональность линуксов, а не что-то новопридуманное. Поэтому mmap используется крайне активно как в самом ядре, так и для нужд обычных приложений. Если даже наше приложение не использует явным образом конкретный вызов, оно всё равно может поймать эту ошибку, потому что сама ОС использует его для загрузки исполняемого кода в память. И если исполняемый код или просто подгружаемая динамическая библиотека (даже баналь��ый libc) располагается на поаффекченной файловой системе, в момент воспроизведения процессор может прочитать из памяти вместо реальной инструкции набор нулевых байтов, что приведёт к краху приложения.

В ходе тестирования мы проверили разные гипотезы, и оказалось, что проблема воспроизводится при использовании различных параметров отображения сегментов: как для Read-Only-, так и для Read-Write-отображений, как для Shared-, так и для Private-сегментов. Словом, полная корзинка счастья.

Также для воспроизведения требуется, чтобы был включён механизм обнуления содержимого освобождаемых страниц памяти. В обычном режиме содержимое физических страниц очищается, когда они выделяются для приложения, однако если речь только про освобождение, то их содержимое будет сохранено. Ясное дело, что такое требование возникает в системах с высокими требованиями относительно возможности компрометации данных, которые так любят устанавливать разнообразные регуляторы по всему миру. Поэтому начиная с ядра версии 5.3 был введён параметр init_on_free, дефолтное значение которого задаётся параметром сборки ядра CONFIG_INIT_ON_FREE_DEFAULT_ON. Хозяйке на заметку: если доступа к загрузчику нет, про факт загрузки этого механизма можно узнать, поискав в логах mem auto-init:

mem auto-init: stack:off, heap alloc:off, heap free:on
mem auto-init: clearing system memory may take some time…

Теперь поговорим про обозначеннй в заголовке статьи XFS и про то, почему всё начинается с файловой системы. С ней не всё так просто: найти однозначную причину возникновения бага не получилось. Однако наиболее вероятная причина, почему баг стреляет, если файлы расположены именно на XFS, — это page folio, наследник struct page. Если кто не сталкивался, то это концепция управления памятью, призванная упростить работу с huge pages и составными страницами. В подверженных проблеме версиях ядра она ещё не была поддержана в других файловых системах, а приведённые ниже коммиты связаны именно с реализацией механизма page folio.

Наконец, последний фактор, приводящий к краху, — наличие большой нагрузки на подсистему памяти. Когда система активно занимается выделением свободной памяти, может произойти выгрузка из памяти кэшированных страниц. Нам удалось повторить это состояние путём последовательного запроса памяти небольшими блоками до исчерпания свободного места. Причём дальше не важно, сработает ли OOM Killer или процесс будет просто остановлен. Таким образом была доказана невиновность самого OOM Killer.

В общем, и баг сложный, и поведение ОС непредсказуемое. Любое приложение может аварийно завершиться при попытке модифицировать защищённую область памяти или если попытается выполнить код из сегмента, не имеющего статуса исполняемого.

Наш путь к воспроизведению

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

Итак, наш тестовый стенд это Debian 11/12 с установленными gcc и xfsprogs. Виртуальной машине выделялось 4 процессора, 4ГБ оперативки и 20 ГБ на жестком диске. Системный раздел отформатирован под ext4. Системный загрузчик grub с добавленными опциями init_on_free=1 и transparent_hugepage=never (чтобы исключить влияние механизма ТНР).

~# grep GRUB_CMDLINE_LINUX_DEFAULT /etc/default/grub
GRUB_CMDLINE_LINUX_DEFAULT="quiet init_on_free=1 transparent_hugepage=never"
~# update-grub
<restart>
~# cat /proc/cmdline
BOOT_IMAGE=/boot/vmlinuz-6.1.114 root=UUID=56af771d-b0a2-45af-bc53-66f4ca792577 ro quiet init_on_free=1 transparent_hugepage=never

Для теста монтируется тестовый раздел XFS размером 384 Мб поверх размещённого на системном разделе файла:

~# dd if=/dev/zero of=xfs.file bs=1M count=384
~# mkfs.xfs -f xfs.file
~# mkdir xfs.mnt
~# mount -t xfs xfs.file xfs.mnt

Баг было решено воспроизводить двумя путями:

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

В обоих случаях триггером для срабатывания является параллельный запуск тестовой программы, которая в цикле запрашивает у системы память по 1 КБ, пока его не грохнет OOM Killer.

Прямолинейный, как шпала, код:

#include <stdlib.h>
#include <stdio.h>
int main(int argc, char* argv[]) {
  for (;;) {
    if (malloc(1024) == NULL) {
      printf("Could not allocate memory\n");
      return 1;
    }
  }
}

Но, само-собой, нам ещё нужно отобразить файлик, лежащий на XFS в оперативку. Для чего подготавливаем подопытного размером 100*4096 байт ибо удобно:

~# dd if=/dev/zero bs=4096 count=100 | tr '\0' '\1' > xfs.mnt/test_file

И ещё одну бесхитростную программу для его отображения в память по следующему алгоритму: в цикле выполнять обращение к каждому блоку по 4 КБ, проверяя что из файла читается единица.

#include <fcntl.h>
#include <stdio.h>
#include <stdlib.h>
#include <sys/mman.h>
#include <unistd.h>

int main(int argc, char* argv[]) {
  char* filename="xfs.mnt/test_file";
  int fd = open(filename, O_RDONLY);
  if (fd == -1) {
    printf("Could not open file %s\n", filename);
    exit(EXIT_FAILURE);
  }
  char* map = mmap(NULL, 4096 * 100, PROT_READ, MAP_PRIVATE, fd, 0);
  if (map == MAP_FAILED) {
    close(fd);
    printf("Could not map file content %s\n", filename);
    exit(EXIT_FAILURE);
  }

  printf("Starting test...\n");
  /* Test body */
  for(;;) {
    for (int i = 0; i < 100; i++) {
      char c = map[i*4096];
      if (c != 1) {
        printf("Got invalid value on page %i = %i\n", i, c);
      }
    }
  }

  munmap(map, 4096 * 100);
  close(fd);
  return EXIT_SUCCESS;
}

Теперь запускаем все программы, до тех пор пока тест не начнёт выдавать нули вместо единиц. Это значит, что первичный успех достигнут и следующая задача — получить сегфолт. Для этого напишем ещё один тест, который будет сыпать вызовами «пустых» функций, проверяя получаемый результат:

#include <stdio.h>
#include <stdlib.h>

#define FUNC_HERE(FUNC_NAME, RET_VAL) int FUNC_NAME() {\
  return RET_VAL;\
}

#define CHECK_FUNC(FUNC_NAME, RET_VAL) { \
  int check_val = FUNC_NAME();\
  if (check_val != RET_VAL) {\
    printf("Erroneous value from " #FUNC_NAME ", expected %d, received %d\n", RET_VAL, check_val);\
    exit(1);\
  }\
}

FUNC_HERE(func0,   0)
FUNC_HERE(func1,   1)
FUNC_HERE(func2,   2)
FUNC_HERE(func3,   3)
FUNC_HERE(func4,   4)
FUNC_HERE(func5,   5)
FUNC_HERE(func6,   6)
FUNC_HERE(func7 ,  7)
FUNC_HERE(func8,   8)
FUNC_HERE(func9,   9)
FUNC_HERE(func10, 10)
FUNC_HERE(func11, 11)
FUNC_HERE(func12, 12)
FUNC_HERE(func13, 13)
FUNC_HERE(func14, 14)
FUNC_HERE(func15, 15)
FUNC_HERE(func16, 16)
FUNC_HERE(func17, 17)
FUNC_HERE(func18, 18)
FUNC_HERE(func19, 19)
FUNC_HERE(func20, 20)
FUNC_HERE(func21, 21)
FUNC_HERE(func22, 22)
FUNC_HERE(func23, 23)
FUNC_HERE(func24, 24)
FUNC_HERE(func25, 25)
FUNC_HERE(func26, 26)
FUNC_HERE(func27, 27)
FUNC_HERE(func28, 28)
FUNC_HERE(func29, 29)

int main(int argc, char* argv[]) {
  printf("Program start\n");

  for(;;) {
    // Check functions
    CHECK_FUNC(func0,   0)
    CHECK_FUNC(func1,   1)
    CHECK_FUNC(func2,   2)
    CHECK_FUNC(func3,   3)
    CHECK_FUNC(func4,   4)
    CHECK_FUNC(func5,   5)
    CHECK_FUNC(func6,   6)
    CHECK_FUNC(func7,   7)
    CHECK_FUNC(func8,   8)
    CHECK_FUNC(func9,   9)
    CHECK_FUNC(func10, 10)
    CHECK_FUNC(func11, 11)
    CHECK_FUNC(func12, 12)
    CHECK_FUNC(func13, 13)
    CHECK_FUNC(func14, 14)
    CHECK_FUNC(func15, 15)
    CHECK_FUNC(func16, 16)
    CHECK_FUNC(func17, 17)
    CHECK_FUNC(func18, 18)
    CHECK_FUNC(func19, 19)
    CHECK_FUNC(func20, 20)
    CHECK_FUNC(func21, 21)
    CHECK_FUNC(func22, 22)
    CHECK_FUNC(func23, 23)
    CHECK_FUNC(func24, 24)
    CHECK_FUNC(func25, 25)
    CHECK_FUNC(func26, 26)
    CHECK_FUNC(func27, 27)
    CHECK_FUNC(func28, 28)
    CHECK_FUNC(func29, 29)
  }

  printf("Program end\n");
}

Сие чудо компилируется с опциями -fno-inline -falign-functions=4096, чтобы обеспечить правильное выравнивание функций по различным страницам памяти. То есть каждая функция располагается на своей странице памяти. Собранный бинарь располагается на XFS томе, где и находятся исходные файлы. И если наша теория верна, то после нескольких запусков мы получаем сегфолт. В системном журнале обнаруживается запись такого вида:

~# dmesg
...
[ 1160.680986] test2[590]: segfault at 0 ip 00005645b312e000 sp 00007ffdb8a95758 error 6 in test2[5645b312b000+21000] likely on CPU 1 (core 1, socket 0)
[ 1160.681007] Code: Unable to access opcode bytes at 0x5645b312dfd6.
...

Если всё сделано правильно, то результат не заставит себя ждать и можно идти пить шампанское (или таблетки от бессонницы, чтобы уснуть после увиденного). Ведь вы только что подтвердили баг в ядре Linux, приводящий к потере данных.

Ваши тесты это хорошо, но как мне диагностировать свою систему?

Абсолютно валидный вопрос! Из-за того что проблема может возникнуть в любом участке кода, симптомы могут быть практически любые, а оперативное и глубокое изучение аварийного дампа памяти доступно далеко не каждому инженеру. Да ещё и не у всех включено логирование достаточного уровня, если совсем честно. Однако долой уныние, ибо всё же есть набор неких типичных симптомов, которые облегчают нашу жизнь.

Во-первых, в dmesg скорее всего будет обнаруживаться явный segfault:

~# dmesg
...
[ 1160.680986] test2[590]: segfault at 0 ip 00005645b312e000 sp 00007ffdb8a95758 error 6 in test2[5645b312b000+21000] likely on CPU 1 (core 1, socket 0)
[ 1160.681007] Code: Unable to access opcode bytes at 0x5645b312dfd6.
...

Хотя в некоторых случаях ошибка может фиксироваться не как segmentation error, а как попытка выполнения некорректной инструкции — invalid opcode.

traps: postgres[1923471] trap invalid opcode ip:7f71444c0003 sp:7ffcb3ec4320 error:0 in liblz4.so.1.9.3[7f71444b7000+1b000]

Также к характерным признакам можно отнести наличие в журналах нулевых значений в качестве кода выхода после сегфолта:

[<timestamp>] postgres[24237]: segfault at cb1 ip 00005579a1505130 sp 00007ffe4f32d008 error 6 in postgres[5579a1170000+559000] likely on CPU 49 (core 17, socket 1)
[<date>] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <00> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

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

И насколько всё плохо глобально?

Наши проверки показали, что ошибка существует начиная с версии ядра Linux 5.18 и перестаёт воспроизводиться с версии 6.9. Что, как бы намекает на весьма широкое распространение.

Поиск места где сломалось привёл нас к коммиту: https://github.com/torvalds/linux/commit/56a4d67c264e37014b8392cba9869c7fe904ed1e («mm/readahead: Switch to page_cache_ra_order»).

А починили всё в районе этого обсуждения патчей для 6.9: https://lore.kernel.org/all/20240227174254.710559-12-willy@infradead.org/T/

Конкретно после вот этого коммита: https://github.com/torvalds/linux/commit/bc2ff4cbc3294c01f29449405c42ee26ee0e1f59 («mm: free folios in a batch in shrink_folio_list()»)

Итого

В конце соберём классический чек-лист для самопроверки и несколько дельных советов, как спать чуточку спокойнее:

напасти подвержены ядра Linux от 5.18 до 6.8;
проблема проявляется, если в ядре включена очистка освобождаемых страниц памяти init_on_free;
проблема проявляется, если используется файловая система XFS.

Что делать, если вы нашли у себя три пункта из трёх? Обычно корпоративно советуют обратиться к поставщику вашей ОС, потому что тут объективно только он вам и поможет. Возможно, окажется, что конкретно в вашем ядре от конкретно вашего вендора это уже починили и ничего делать не надо.

Однако если вам не так повезло или пока вы ждёте ответа, привета или патча, то, как вариант, можно мигрировать на другую файловую систему (привет ext4), либо указать init_on_free=0 в аргументах загрузки линукса. Но это всё на свой страх и риск, конечно же.

История поиска бага в ядре Linux длиной в год, или нежданные нули из XFS'а