Отладка злого бага в рантайме Go

Отладка злого бага в рантайме Go

Я большой поклонник Prometheus и Grafana. Поработав SRE в Google, я научился ценить хороший мониторинг и за прошедший год предпочитал пользоваться комбинацией этих инструментов. Я использую их для мониторинга своих личных серверов (black-box и white-box мониторинг), внешних и внутренних событий Euskal Encounter, для мониторинга клиентских проектов и много другого. Prometheus позволяет очень просто писать кастомные модули экспорта для мониторинга моих собственных данных, к тому же вполне можно найти подходящий модуль прямо из коробки. Например, для создания симпатичной панели имеющихся метрик Encounter-событий мы используем sql_exporter.

Панель событий для Euskal Encounter (фальшивые данные стейджинга)

Можно легко закинуть node_exporter на любую машину и натравить экземпляр Prometheus, чтобы получить основные системные метрики (использование процессора, памяти, сети, дисков, файловой системы и т. д.). Я подумал, а почему бы таким образом не мониторить свой ноутбук? У меня «игровой» ноут Clevo, который я использую в качестве основной рабочей станции. Обычно он стоит дома, но иногда ездит со мной на большие мероприятия вроде Chaos Communication Congress. И раз у меня уже есть VPN между ноутом и одним из моих серверов, на котором крутится Prometheus, я могу просто выполнить emerge prometheus-node_exporter , поднять службу и указать её экземпляру Prometheus. Он автоматически сконфигурирует предупреждения, и мой телефон начнёт разрываться, когда я открою слишком много вкладок в Chrome и исчерпаю все 32 Гб оперативки. Замечательно.

На горизонте проблема

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

node_exporter , как и многие компоненты Prometheus, написан на Go. Это относительно безопасный язык: он позволяет вам при желании выстрелить себе в ногу, а его гарантии безопасности несравнимы с Rust, например, но всё же случайно вызвать segfault в Go не так-то легко. Кроме того, node_exporter — довольно простое Go-приложение, по большей части использующее чисто гошные зависимости. Значит, случай с падением будет интересным. Особенно учитывая, что падение произошло в mallocgc , который вообще не должен падать при нормальных условиях.

После нескольких перезапусков стало ещё интереснее:

Так, уже интереснее. В этот раз сломался Sprintf . Шта?

Теперь проблемы начались и у сборщика мусора. Уже другой сбой.

Здесь можно было сделать два логичных вывода: либо у меня серьёзная проблема с оборудованием, либо в бинарнике баг, связанный с повреждением памяти. Сначала я решил, что первое маловероятно, потому что ноутбук обрабатывал одновременно очень разные виды нагрузок и не было ни малейших признаков нестабильной работы, которые можно было бы связать с оборудованием (у меня падало ПО, но это никогда не происходило случайно). Поскольку бинарники Go вроде node_exporter связаны статично и не зависят от каких-то иных библиотек, я скачал официальный релиз бинарника и попробовал сделать так, чтобы большая часть моей системы не представляла собой переменную. Но всё равно получил сбой:

Совершенно новый сбой. Похоже, проблема с node_exporter или одной из его зависимостей, так что я заполнил отчёт о баге на GitHub. Быть может, разработчики уже сталкивались с подобным? Надо привлечь их внимание и послушать, что они скажут.

Не-такой-уж-короткий обходной путь

Неудивительно, что сначала предположили: дело в оборудовании. Вполне обоснованно, ведь я столкнулся с проблемой только на одном компьютере. Все остальные мои машины прекрасно гоняли node_exporter . У меня не было других доказательств железного сбоя на этом хосте и даже объяснений, что именно могло вызвать падение node_exporter . Memtest86+ ещё никому не вредил, поэтому я решил им воспользоваться.

А затем случилось это:

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

Опа! Битая память. Точнее, один бит. Я прогнал тест целиком и нашёл этот бит и несколько ложноположительных в тесте № 7 (в нём перемещаются блоки, что может привести к размножению единственной ошибки).

Дальнейшее тестирование в Memtest86+ показало, что тест № 5 в режиме SMP быстро обнаруживает проблему, но обычно не при первом проходе. Проблема всегда возникала с одним битом по одному и тому же адресу. Похоже, слабая ячейка памяти, которая при нагреве начинает барахлить. Логично: рост температуры увеличивает утечки в ячейках памяти, и повышается вероятность, что какая-нибудь маргинальная ячейка начнёт сбоить.

Чтобы было понятнее: это один плохой бит из 274 877 906 944. Прекрасное соотношение! У жёстких дисков и флеш-памяти коэффициент ошибок гораздо выше — в этих устройствах битые блоки помечаются ещё на заводах, а во время эксплуатации новые битые блоки незаметно для пользователей помечаются и переносятся в резервную зону. У оперативной памяти таких механизмов нет, так что битый блок остаётся навечно.

Увы, вряд ли этот бит приводит к сбоям в моём node_exporter . Приложение использует очень мало памяти, так что вероятность попадания в плохой бит (причём раз за разом) крайне мала. Проблема этого бита проявилась бы, в худшем случае приводя к битому пикселю в изображении, или выпадению одного символа в письме, или невыполнению какой-нибудь инструкции, или редкому segfault, если на плохой бит пришлось что-то серьёзное. Тем не менее это означает долгосрочные проблемы с надёжностью, и поэтому серверы и прочие устройства, для которых важна надёжность, используют ECC RAM — память с коррекцией ошибок.

У меня в ноутбуке такой роскоши нет. Но зато я могу пометить битый блок как плохой и сказать ОС, чтобы она его не использовала. У GRUB 2 есть малоизвестная возможность изменять схему памяти, передающуюся в загруженное ядро ОС. Не стоит покупать новую линейку памяти из-за одного плохого бита (к тому же DDR3 уже устарела, и велика вероятность, что новая память тоже будет со слабыми ячейками).

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

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

Ещё я обнаружил, что расположение ошибок оставалось практически неизменным даже при переставлении модулей: верхние биты адреса были одни и те же. Всё дело в чередовании оперативной памяти: вместо того чтобы каждому модулю присваивать цельную четверть адресного пространства, данные распределяются по всем четырём модулям. Это удобно, потом что на область памяти можно наложить маску, охватывающую все возможные адреса для каждого плохого бита, и не беспокоиться о том, что всё перепутается, если поменять модули местами. Я выяснил, что если наложить маску на сплошную область в 128 Кб, то этого хватит для закрытия всех возможных перестановок адресов для каждого плохого бита. Но округлил до 1 Мб. Получилось три мегабайтных выравненных блока для маскирования (один из них покрывает два плохих бита, а всего я хотел покрыть четыре):

  • 0x36a700000 – 0x36a7fffff
  • 0x460e00000 – 0x460efffff
  • 0x4ea000000 – 0x4ea0fffff

Маски я задал в /etc/default/grub с помощью синтаксиса маскирования адресов:

Затем быстро выполнил grub-mkconfig и выключил 3 Мб памяти с четырьмя плохими битами. Конечно, не ECC RAM, и всё же надёжность моей ширпотребовской памяти должна стать выше, ведь я знаю, что остальные ячейки ведут себя стабильно при нагреве до 100 °C.

Как вы понимаете, node_exporter продолжил падать, но мы же знали, что эта проблема была несерьёзной, верно?

Копаем глубже

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

Сначала я попробовал разделить пополам доступные релизы node_exporter и включать/выключать разные сборщики, но это ничего мне не дало. Пытался запускать экземпляр под strace . Падения прекратились, что свидетельствовало о состоянии гонки. Позднее оказалось, что strace -экземпляр тоже падает, но этого пришлось ждать гораздо дольше. Я предположил, что дело в распараллеливании. Задал GOMAXPROCS=1 , чтобы Go использовал только один системный поток выполнения. Падения снова прекратились, так что у меня появились аргументы в пользу проблемы распараллеливания.

К тому времени я собрал большое количество логов падений и начал подмечать некоторые закономерности. Хотя места и порядок падений сильно менялись, но в целом сообщения об ошибках можно было разделить на три группы, и одна из ошибок возникала чаще одного раза. Я залез в поисковик и наткнулся на проблему в Go № 20427. Вроде бы она относилась к другой части Go, но приводила к таким же segfault и случайным сбоям. Тикет был закрыт без анализа, потому что ситуацию не удалось воспроизвести в Go 1.9. Никто не знал, в чём корень проблемы, она просто прекратилась.

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

Это не приблизило меня к отладке на стороне Go, но позволило тестировать решения гораздо быстрее. Попробуем с другой стороны

Проверяем на машинах

Сбои возникают на моём ноутбуке, но не на других моих компьютерах. Я попробовал воспроизвести баг на всех серверах, к которым был лёгкий доступ, и не столкнулся ни с одним падением. Значит, на моём ноуте есть что-то особенное. Go статично связывает бинарники, так что остальное пользовательское пространство не имеет значения. Остаётся два кандидата: железо или ядро ОС.

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

Я сделал минимальную initramfs (initial ram file system), чтобы очень быстро запускать в виртуальной машине QEMU код воспроизведения сбоев без установки дистрибутива или загрузки полной версии Linux. Моя initramfs была построена на линуксовом scripts/gen_initramfs_list.sh и содержала файлы:

/init — входная точка Linux-initramfs, в моём случае это был простой скрипт оболочки для запуска теста и измерения времени:

/bin/busybox — статично связанная версия BusyBox, обычно используется в минимизированных системах вроде моей для предоставления всех основных утилит Linux-оболочки (включая саму оболочку).

Initramfs можно сделать так (на основе исходного дерева ядра Linux), где list.txt — вышеприведённый список файлов:

А QEMU может напрямую загружать ядро и initramfs:

В консоли ничего не отобразилось… затем я сообразил, что даже не скомпилировал в ядре на моём ноутбуке поддержку серийного порта 8250. Блин. У него же нет физического серийного порта, верно? Ладно, быстренько пересобрал ядро с поддержкой порта (и скрестил пальцы, чтобы не поменять ничего важного), попробовал снова, успешно загрузил и запустил воспроизводящий баг код.

Упал? Ага. Хорошо, сбой можно воспроизвести в виртуальной машине на том же компьютере. Попробовал ту же QEMU-команду на своём домашнем сервере, на его собственном ядре, и… ничего. Затем скопировал ядро с ноутбука, загрузил и… сбой. Всё дело в ядре. Это не железо.

Жонглируя ядрами

Я понимал, что придётся скомпилировать много ядер, чтобы выловить проблему. Решил делать это на своём самом мощном компьютере: довольно старом 12-ядерном Xeon с 24 потоками исполнения (он уже не работает, к сожалению). Скопировал исходный код сбойного ядра, собрал и протестировал.

Поскрёб в голове, проверил, падает ли оригинальный бинарник ядра (упал). Неужели всё-таки железо? Неужели имеет значение, на каком компьютере я собираю ядро? Попробовал собрать на домашнем сервере, вскоре случилось падение. Если собрать одно ядро на двух машинах, то падения есть, а если собрать на третьей — падений нет. Почему так?

На всех трёх машинах стоит Linux Gentoo с изменениями Hardened Gentoo. Но на ноутбуке и домашнем сервере стоит

amd64 (нестабильная версия), а на Xeon-сервере — amd64 (стабильная). То есть GCC разные. На ноуте и домашнем сервере стоял gcc (Gentoo Hardened 6.4.0 p1.0) 6.4.0, а на Xeon — gcc (Gentoo Hardened 5.4.0-r3 p1.3, pie-0.6.5) 5.4.0.

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

Для выяснения я скомпилировал на домашнем сервере точно такое же дерево ядра с моего ноутбука (linux-4.13.9-gentoo), оно падало. Потому скопировал .config с домашнего сервера и скомпилировал его — не падало. Получается, нужно учитывать разницу в конфигурациях и компиляторах:

  • linux-4.13.9-gentoo + gcc 5.4.0-r3 p1.3 + laptop .config — не падает.
  • linux-4.13.9-gentoo + gcc 6.4.0 p1.0 + laptop .config — падает.
  • linux-4.13.9-gentoo + gcc 6.4.0 p1.0 + server .config — не падает.

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

Решил начать с «точно плохого» конфига и стал выкидывать из него разные вещи. Поскольку воспроизводящий сбой код падал через разные промежутки времени, проще было тестировать на «всё ещё падает» (просто дожидаясь падения), чем на «не падает» (сколь придётся ждать, чтобы подтвердить отсутствие сбоя?). На протяжении 22 сборок ядра я настолько упростил конфигурацию, что ядро лишилось поддержки сети, файловой системы, основы блокового устройства и даже поддержки PCI (причём в виртуальной машине продолжало прекрасно работать!). Мои сборки занимали теперь меньше 60 секунд, а ядро стало примерно на 3/4 меньше обычного.

Затем я перешёл к «точно хорошей» конфигурации и убрал всё ненужное барахло, проверяя, не падает ли воспроизводящий код (это было труднее и дольше, чем предыдущий тест). У меня было несколько ложных веток, когда я изменил что-то (не знаю что), рушащее воспроизводящий код. Я ошибочно пометил их как «не падающие», и, когда столкнулся с падениями, пришлось возвращаться к предыдущим собранным ядрам и выяснять, когда же именно появились падения. Я собрал семь ядер.

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

Что дальше? Мы знаем, что к падениям приводит опция CONFIG_OPTIMIZE_INLINING, но она может менять поведение каждой функции inline во всём ядре. Как вычислить корень зла?

Дифференциальная компиляция на основе хешей

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

Вместо перечисления всех файлов объектов и выполнения бинарного поиска и я решил воспользоваться хешами. Написал скрипт-обёртку для GCC:

Он на основе имени файла объекта генерирует хеш SHA-1, затем проверяет один из первых 32 битов хеша (определяются по переменной среды $BIT). Если бит равен 0, собирается без CONFIG_OPTIMIZE_INLINING . Если равен 1, собирается с CONFIG_OPTIMIZE_INLINING . Я выяснил, что ядро содержит около 685 файлов объектов (помогли мои усилия по минимизации), так что для уникальной идентификации требовалось примерно 10 битов. У подхода с использованием хеша есть одна особенность: можно беспокоиться только о сбойных вариантах (бит равен 0), поскольку гораздо сложнее доказать, что данная сборка ядра не падает (падения вероятностны и могут происходить далеко не сразу).

Я собрал 32 ядра, по одному на каждый бит префикса SHA-1, это заняло всего 29 минут. Затем начал тестировать ядра и при каждом падении определял те регулярные выражения возможных хешей SHA-1, что имели на определённых позициях нулевые биты. После восьми падений (и нулевых битов) я вычислил четыре файла объектов, ещё пара оказалась под подозрением. После десяти падений совпадение было одно.

Код vDSO. Ну конечно.

Выходки vDSO

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

Иными словами, vDSO — компилируемый GCC код, собираемый с ядром и в конце концов связываемый с каждым приложением в пользовательском пространстве. Это код пользовательского пространства. Теперь понятно, почему важны версии ядра и компилятора: дело не в самом ядре, а в библиотеке, идущей с ядром! Go использует vDSO для повышения производительности. Также в Go есть (довольно безумная, как я считаю) политика переизобретения собственной стандартной библиотеки, так что для вызова vDSO он не использует код стандартной Linux-библиотеки glibc, а выкатывает собственные вызовы (и системные тоже).

Как переключение CONFIG_OPTIMIZE_INLINING влияет на vDSO? Посмотрим на машинный код.

Любопытно, CONFIG_OPTIMIZE_INLINING=y должен позволять GCC инлайнить меньше, а на деле компилятор инлайнит больше: в этой версии vread_tsc оказалась инлайненной, в отличие от версии с CONFIG_OPTIMIZE_INLINING=n . Но vread_tsc вообще не помечена как inline , так что GCC повёл себя целиком в рамках дозволенного, хотя на первый взгляд это и не так. Но что плохого в инлайнинге функции? В чём проблема? Давайте посмотрим на неинлайненную версию…

Почему GCC выделяет больше 4 Кб в стеке? Это не выделение памяти в стеке, это стековый зонд (stack probe), а точнее — результат свойства GCC -fstack-check .

В Linux Gentoo Hardened -fstack-check включено по умолчанию. Это сделано для закрытия уязвимости Stack Clash. Хотя -fstack-check — старое свойство GCC и не предназначалось для этой задачи, но всё же успешно закрывает уязвимость (мне сказали, что нормальная защита от Stack Clash появится в GCC 8). Но есть побочный эффект: каждая функция, не относящаяся к листьям дерева ядра (функция, вызывающая функции), перед указателем стека размещает 4 Кб стекового зонда. То есть код, скомпилированный с -fstack-check , потребует как минимум 4 Кб памяти в стеке, если это не функция-«лист» (или функция, в которой каждый вызов инлайненный).

Go любит маленькие стеки.

Похоже, 104 байтов на всех не хватит. Уж точно не моему ядру.

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

Заключение

Это полностью объясняет все симптомы. Стековый зонд — это orq , логическое ИЛИ с 0. Холостая инструкция, но эффективно зондирующая целевые адреса (если они не распределены, возникает segfault). Но в коде vDSO не было segfaults, почему же Go ломается? Дело в том, что ИЛИ с 0 не совсем холостая инструкция. Поскольку orq не атомарная инструкция, процессор считывает адрес памяти и записывает в него. Возникает состояние гонки. Если в других процессорах параллельно выполняются другие потоки, orq может в то же время прервать запись в память. Поскольку запись выполнялась вне границ стека, то наверняка она вторглась в стеки других потоков выполнения или в случайные данные, и когда звёзды выстраивались нужным образом, то запись в память прерывалась. В том числе и поэтому GOMAXPROCS=1 имеет отношение к описанной проблеме, этот параметр не позволяет двум потокам выполнения одновременно выполнять код Go.

Как исправить? Я оставил это на усмотрение разработчикам Go. Они решили увеличить стек перед вызовом функций vDSO. Это немножко уменьшило скорость (наносекунды), но вполне приемлемо. После сборки node_exporter с исправленным Go падения прекратились.

📎📎📎📎📎📎📎📎📎📎