Эта статья выбрана из серии статей «Практика инфраструктуры Byte Beat».
Серия статей «ByteDance Infrastructure Practice» представляет собой техническую галантерею, созданную техническими командами и экспертами отдела инфраструктуры ByteDance, в которой мы делимся с вами практическим опытом и уроками команды в процессе развития и эволюции инфраструктуры, а также всеми техническими студентами. общаться и расти вместе.
Мы часто сталкиваемся с coredump в нашей повседневной разработке, что может помочь нам найти проблемы, но если coredump усекается, это доставляет неудобства при устранении неполадок. В этой статье в качестве примера рассматриваются онлайн-проблемы.С помощью этого кейса мы получим глубокое понимание идей по устранению таких проблем и как использовать некоторые инструменты отладки, прочитаем исходный код ядра и получим более четкое представление о процесс обработки дампа памяти. Я надеюсь, что это может предоставить четкий контекст для всех при устранении таких проблем.
фон проблемы
Во время разработки таких программ, как c/cpp, процесс сталкивается с дампом памяти, и иногда возникает проблема усечения дампа памяти, которая влияет на устранение неполадок после core. усечения coredump в основном вызваны ограничениями ядра и оставшимся дисковым пространством. Это лучше исследовать и решить. Частный случай мы сегодня разберем.
С помощью этого случая у нас есть глубокое понимание идей по устранению неполадок такого рода проблем.Использование некоторых инструментов отладки и чтение исходного кода ядра могут более четко понять процесс обработки coredump. При устранении таких проблем можно иметь четкий контекст.
Одноклассники по бизнесу сообщили, что отладка gdb сообщила об ошибке после того, как служба в контейнере вышла за пределы ядра. Служба бизнеса работает в среде K8S+Docker, и в конечном итоге служба управляется системой в контейнере. Файл coredump на некоторых машинах содержит следующее предупреждение, когда работает gdb, что влияет на устранение неполадок. Сообщение об ошибке выглядит следующим образом:
BFD: Warning: /tmp/coredump.1582242674.3907019.dp-b9870a84ea-867bccccdd-5hb7h is truncated: expected core file size >= 89036038144, found: 31395205120.
В результате gdb не может продолжать отладку. После входа в машину проверяем, что это не проблема с дисковым пространством и ядром ulimit. Требуется дальнейшее расследование.
Соглашение о существительных:
GDB: Двоичный инструмент отладки под UNIX и UNIX-подобный,
Дамп ядра:Дамп ядра — это файл на диске, в который операционная система записывает содержимое адресного пространства процесса и другую информацию о состоянии процесса, когда процесс получает определенные сигналы и завершает свою работу. Эта информация часто используется для отладки.
ЭЛЬФ:Executable and Linkable Format, стандартный формат файлов для исполняемых файлов, объектных файлов, общих библиотек и дампов ядра. Стандарт формата двоичных файлов для Unix-подобных операционных систем на архитектуре x86.
БФД:Библиотека дескрипторов двоичных файлов — это основной механизм проекта GNU для обеспечения переносимости объектных файлов в различных форматах.
VMA:Область виртуальной памяти (Virtual Memory Area), VMA — блок виртуального адресного пространства в пользовательском процессе, ядро использует VMA для отслеживания карты памяти процесса.
Процесс устранения неполадок
Проверка пользовательского режима
Я начал подозревать, что проблема в программе-обработчике coredump собственной разработки. Поэтому восстановите исходный дамп системы.
Запустите Coredump вручную. В результате проблема осталась. Теперь устраните неполадки в обработчике coredump. Указывает, что проблема может возникнуть на уровне ядра или gdb.
Необходимо определить, является ли это проблемой gdb или проблемой ядра ядра. Начните с gdb и загрузите исходный код gdb, чтобы найти место ошибки (для удобства чтения скорректирован отступ исходного кода).
На данный момент это не проблема с gdb. Файл coredump был записан не полностью. Запись в coredump выполняется ядром. Это нужно проверить со стороны ядра.
Использование памяти, используемое программой для наблюдения за этим дампом ядра перед устранением неполадок, очень велико, с масштабом в десятки гигабайт. Сомневаетесь, связано ли это с тем, что он слишком большой, так что проведите эксперимент. Напишите симуляцию программы с памятью 50G и создайте ее дамп.
#include <unistd.h>
#include <stdlib.h>
#include <string.h>
int main(void){
for( int i=0; i<1024; i++ ){
void* test = malloc(1024*1024*50); // 50MB
memset(test, 0, 1);
}
sleep(3600);
}
После тестирования плюнул ядро нормально. gdb в норме, временно исключите проблему большого объема ядра.
Таким образом, первоначальная оценка состоит в том, что ядро само выплевывает основной файл. Нужно следить дальше.
Посмотрев код ядра нашел подозрительный момент:
/*
* Ensures that file size is big enough to contain the current file
* postion. This prevents gdb from complaining about a truncated file
* if the last "write" to the file was dump_skip.
*/
void dump_truncate(struct coredump_params *cprm)
{
struct file *file = cprm->file;
loff_t offset;
if (file->f_op->llseek && file->f_op->llseek != no_llseek) {
offset = file->f_op->llseek(file, 0, SEEK_CUR);
if (i_size_read(file->f_mapping->host) < offset)
do_truncate(file->f_path.dentry, offset, 0, file);
}
}
Комментарии к этому коду привлекли наше внимание.
Теперь есть подозрение, что в этом случае не выполняется функция dump_truncate. Поэтому попробуйте переместить dump_truncate во второе место. Попробуйте перекомпилировать ядро. После перезапуска тестового ядра test проблема сохраняется.
Итак, продолжайте смотреть на код:
Это поколение привлекло внимание. Есть подозрение, что при выполнении get_dump_page в какой-то момент возвращался NULL. Затем я перешел к функции dump_skip, dump_skip вернул 0, что привело к переходу к end_coredump. Так стэп поймал.
Как и ожидалось, coredump останавливается после того, как dump_skip возвращает 0.То есть второй этап только сбрасывает часть vma и останавливается.Вызывает неполную запись дампа ядра.
Анализ частичного дампа VMA
Посмотрите еще раз на функцию dump_skip:
int dump_skip(struct coredump_params *cprm, size_t nr)
{
static char zeroes[PAGE_SIZE];
struct file *file = cprm->file;
if (file->f_op->llseek && file->f_op->llseek != no_llseek) {
if (dump_interrupted() ||
file->f_op->llseek(file, nr, SEEK_CUR) < 0)
return 0;
cprm->pos += nr;
return 1;
} else {
while (nr > PAGE_SIZE) {
if (!dump_emit(cprm, zeroes, PAGE_SIZE))
return 0;
nr -= PAGE_SIZE;
}
return dump_emit(cprm, zeroes, nr);
}
}
Поскольку coredump — это канал, здесь нет операции llseek, поэтому он перейдет к ветке else. То есть dump_emit возвращает 0. Итак, stap захватывает функцию dump_emit:
function func:string(task:long)
%{
snprintf(STAP_RETVALUE, MAXSTRINGLEN, "%s", signal_pending(current) ? "true" : "false");
%}
probe kernel.function("dump_emit").return
{
printf("return: %d, cprm->limit:%d, cprm->written: %d, signal: %s\n", $return, @entry($cprm->limit), @entry($cprm->written), func($return));
}
Результат выглядит следующим образом:
return: 1, cprm->limit:-1, cprm->written: 0, signal: false
return: 1, cprm->limit:-1, cprm->written: 64, signal: false
return: 1, cprm->limit:-1, cprm->written: 120, signal: false
... 省略9221238行 ...
return: 1, cprm->limit:-1, cprm->written: 37623402496, signal: false
return: 1, cprm->limit:-1, cprm->written: 37623406592, signal: false
return: 1, cprm->limit:-1, cprm->written: 37623410688, signal: false
return: 0, cprm->limit:-1, cprm->written: 37623414784, signal: true
Неудивительно и подозрительно, что dump_emit возвращает 0, а в основной файл записано 37623414784 байта. Главным образом потому, что условие теста dump_interrupted истинно. (cprm->limit = -1 не войдет в логику if, а kernrel_wirte записывает канал без ошибок).
Далее мы рассмотрим функцию dump_interrupted. Для удобства чтения родственные функции рассортированы:
static bool dump_interrupted(void){
/*
* SIGKILL or freezing() interrupt the coredumping. Perhaps we
* can do try_to_freeze() and check __fatal_signal_pending(),
* but then we need to teach dump_write() to restart and clear
* TIF_SIGPENDING.
*/
return signal_pending(current);
}
static inline int signal_pending(struct task_struct *p){
return unlikely(test_tsk_thread_flag(p,TIF_SIGPENDING));
}
static inline int test_tsk_thread_flag(struct task_struct *tsk, int flag){
return test_ti_thread_flag(task_thread_info(tsk), flag);
}
static inline int test_ti_thread_flag(struct thread_info *ti, int flag){
return test_bit(flag, (unsigned long *)&ti->flags);
}
/**
* test_bit - Determine whether a bit is set
* @nr: bit number to test
* @addr: Address to start counting from
*/
static inline int test_bit(int nr, const volatile unsigned long *addr){
return 1UL & (addr[BIT_WORD(nr)] >> (nr & (BITS_PER_LONG-1)));
}
Связанные макросы:
#ifdef CONFIG_64BIT
#define BITS_PER_LONG 64
#else
#define BITS_PER_LONG 32
#endif /* CONFIG_64BIT */
#define TIF_SIGPENDING 2 /* signal pending */ 平台相关。以X64架构为例。
Из приведенного выше кода становится ясно, что функция dump_interrupted предназначена для определения того, установлены ли для thread_info->flags задачи значение TIF_SIGPENDING.
В настоящее время есть подозрение, что это все еще связано с памятью пользователя vma. Но вопрос в том, какой сценарий вызовет установку TIF_SIGPENDING. Это было объяснено в комментариях к функции dump_interrupted, одно из них — получен сигнал KILL, а другое — замораживание(). замораживание () обычно связано с контрольными группами и обычно используется докером. KILL может быть выдан systemd. Итак, я провел 2 эксперимента:
эксперимент первый:
systemd启动实例，bash裸起服务，不接流量。
测试结果gdb正常...
然后再用systemd起来，不接流量。测试结果也是正常的。
这就奇怪了。但是不能排除systemd。
回想接流量和不接流量的区别是coredump的压缩后的体积大小不同，不接流
量vma大都是空，空洞比较多，因此coredump非常快，有流量vma不是空
的，coredump比较慢。因此怀疑和coredump时间有关系，超过某个时间就
有TIF_SIGPENDING被置位。
Эксперимент 2:
是产生一个50G的内存。代码如最上方。
在容器内依然使用systemd启动一个测试程序
（直接在问题容器内替换这个bin。然后systemctl重启服务）
然后发送SEGV信号。stap抓一下。
coredump很漫长。等待结果
结果很意外。core正常，gdb也正常。
Этот источник сигнала TIF_SIGPENDING является проблемой.
Еще одно направление устранения неполадок — почему get_dump_page возвращает NULL. Итак, теперь есть 2 направления устранения неполадок:
- Необходимо определить источник сигнала TIF_SIGPENDING.
- Причина, по которой get_dump_page возвращает NULL.
get_dump_page возвращает анализ NULL
Сначала рассмотрим случай, когда get_dump_page возвращает NULL:
* Returns NULL on any kind of failure - a hole must then be inserted into
* the corefile, to preserve alignment with its headers; and also returns
* NULL wherever the ZERO_PAGE, or an anonymous pte_none, has been found -
* allowing a hole to be left in the corefile to save diskspace.
Посмотрите на комментарии и верните NULL, одна из них — страница ZERO_PAGE, а другая — проблема pte_none.
Сначала посмотрите на проблему ZREO, поэтому создайте программу ZERO_PAGE для тестирования:
#include <stdio.h>
#include <unistd.h>
#include <sys/mman.h>
const int BUFFER_SIZE = 4096 * 1000;
int main(void){
int i = 0;
unsigned char* buffer;
for( int n=0; n<10240; n++ ){
buffer = mmap(NULL, BUFFER_SIZE, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0);
for (i = 0; i < BUFFER_SIZE - 3 * 4096; i += 4096){
buffer[i] = 0;
}
}
// zero page
for (i=0; i < BUFFER_SIZE - 4096; i += 4096) {
char dirty = buffer[i];
printf("%c", dirty);
}
printf("ok...\n");
sleep(3600);
}
Результатом теста является то, что coredump является нормальным и отслеживает возвращаемое значение get_dump_page. Результат немного отличается от ожидаемого, и возвращается много значений NULL. Описание и функция get_dump_page не имеют большого значения.
Итак, обратитесь к источнику сигнала TIF_SIGPENDING.
Анализ источника сигнала TIF_SIGPENDING
Взгляните на bpftrace:
#!/usr/bin/env bpftrace
#include <linux/sched.h>
kprobe:__send_signal
{
$t = (struct task_struct *)arg2;
if ($t->pid == $1) {
printf("comm:%s(pid: %d) send sig: %d to %s\n", comm, pid, arg0, $t->comm);
}
}
Результат выглядит следующим образом:
Результаты интереснее. kill и systemd прерывают процесс дампа ядра. И сигнала 2 (SIGINT), и сигнала 9 (SIGKILL) достаточно, чтобы прервать процесс. Теперь возникает вопрос, почему kill и systemd отправляют эти 2 сигнала. Одно подозрение - тайм-аут. Если процесс coredump не выполняется слишком долго, вызовет ли он systemd?
Поэтому я проверил документ службы systemd и нашел этот абзац:
TimeoutAbortSec=
This option configures the time to wait for the service to terminate when it was aborted due to a watchdog timeout (see WatchdogSec=). If the service has a short TimeoutStopSec= this option can be used to give the system more time to write a core dump of the service. Upon expiration the service will be forcibly terminated by SIGKILL (see KillMode= in systemd.kill(5)). The core file will be truncated in this case. Use TimeoutAbortSec= to set a sensible timeout for the core dumping per service that is large enough to write all expected data while also being short enough to handle the service failure in due time.
Takes a unit-less value in seconds, or a time span value such as "5min 20s". Pass an empty value to skip the dedicated watchdog abort timeout handling and fall back TimeoutStopSec=. Pass "infinity" to disable the timeout logic. Defaults to DefaultTimeoutAbortSec= from the manager configuration file (see systemd-system.conf(5)).
Если служба Type=notify сама обрабатывает SIGABRT (вместо того, чтобы полагаться на ядро для записи дампа ядра), она может отправить «EXTEND_TIMEOUT_USEC=…», чтобы продлить время прерывания за пределы TimeoutAbortSec=. Первое получение этого сообщения должно произойти до TimeoutAbortSec. = превышено, и как только время прерывания превысит значение TimeoutAbortSec=, диспетчер службы разрешит прерывание службы, если служба повторяет «EXTEND_TIMEOUT_USEC=…» в течение указанного интервала или завершает работу (см. sd_notify(3) ).
Слова, выделенные красным, привлекли внимание, поэтому я немного увеличил громкость (TimeoutAbortSec="10min") и попробовал еще раз. неверный...
Очень странно после того, как он недействителен, не система ли является инициатором сигнала, а "передатчиком" сигнала?
Теперь есть два сомнения, одно в том, что systemd является инициатором сигнала, а другое в том, что systemd не инициатор сигнала, а "передатчик" сигнала. Итак, на этот раз взгляните на бизнес-процесс и процесс systemd одновременно.
Результат выглядит следующим образом:где 3533840 — это процесс инициализации контейнера systemd. 3533916 — это бизнес-процесс. Как и ожидалось, systemd не является первым источником сигнала. systemd останавливается, когда получает сигнал 15 (SIGTERM) runc, и дочерний процесс будет уничтожен перед остановкой. Это последний системный сигнал отправки.
Есть вопрос.Использовал программу 1 для тестирования сценария system+docker,но она не воспроизвелась.Напомню,что процесс coredump должен быть таким.Программа 1 не писала в каждую страницу,а писала только одну после malloc. Первый байт первой страницы. coredump проходит через каждую виртуальную машину намного быстрее, чем записывает все страницы (поскольку дыр не так много, виртуальные машины менее фрагментированы). Хотя coredump имеет большой размер, времени мало, поэтому эта проблема не срабатывает, что вносит определенные повороты в решение этой проблемы.
Таким образом, направление устранения неполадок обращается к команде kill и runc. После расследования было обнаружено, что сценарий prestop в жизненном цикле K8S имеет поведение kill. Остановите этот скрипт и снова возьмите его:
На этот раз нет поведения уничтожения, но systemd по-прежнему уничтожается runc, отправляя 2 сигнала, один SIGTERM, а другой SIGKILL. Теперь, когда источник сигнала уничтожения объяснен, это также объясняет источник сигнала уничтожения. На самом деле сигнальные корни kill и systemd запускаются как косвенно, так и напрямую. Инструкция уничтожения runc исходит от k8s.
Так что продолжайте расследование в соответствии с журналом K8S. После расследования выясняется, что последней логикой триггера является вытеснение загрузки из внутренней реализации байтов. Этот механизм удалит этот экземпляр, когда загрузка контейнера слишком высока, чтобы не влиять на другие экземпляры. Потому что во время дампа ядра ЦП надолго упадет в состояние ядра, что приведет к увеличению нагрузки. Поэтому я запускаю стручок выселения.
Нагрузка экземпляра во время дампа ядра очень высока, что приводит к тому, что kubelet, компонент k8s, запускает поведение вытеснения экземпляра при высокой нагрузке. Удалить капсулы. Остановить системд. Уничтожение процесса, выполняющего создание дампа ядра, в конечном итоге приведет к тому, что второй этап создания дампа ядра запишет неполные данные vma.
проблема проверки
Выполнив простую проверку, остановите kubelet компонента K8S, а затем инициируйте ядро для службы. Наконец ГДБ. Проверка проходит нормально, и gdb нормально читает данные. На данный момент проблема изучена. Наконец, после изменения внутренней реализации функции сбора cgroup-level Load (план сбора данных, аналогичной загрузке всей машины) и фильтрации процесса в состоянии D (процесс coredump находится в состоянии D в пользовательском режиме ), эта проблема полностью решена.
Суммировать
На этот раз файл coredump усекается из-за того, что процесс coredump был завершен (сигнал SIGKILL), в результате чего VMA не была записана полностью (была записана только его часть). Решите эту проблему, прочитав исходный код ядра и используя утилиту bpftrace, systemtap для отслеживания процесса дампа ядра. Распечатайте нужные вам данные и, наконец, проанализируйте причину проблемы с помощью исходного кода. В то же время у нас есть определенное понимание процесса coredump ядра.
Наконец, добро пожаловать в команду инфраструктуры ByteDance, чтобы вместе обсуждать, решать проблемы и становиться сильнее!
Приложение: простой анализ файла coredump
Во время исследования этой проблемы я также прочитал соответствующий исходный код ядра, обрабатывающего coredump, и кратко резюмирую:
Файл coredump на самом деле представляет собой урезанный файл ELF. Процесс coredump не сложен. Процесс coredump делится на два этапа.На одном этапе записывается заголовок программы (первый заголовок программы — Note Program Header).Каждый заголовок программы содержит размер VMA и смещение в файле. Таким же образом gdb определяет местоположение каждого VMA. Другой этап — запись данных vma, проходящих через все vma процесса. Потом пиши в файл. Структуру файла дампа памяти можно просто представить структурой, показанной ниже.
использованная литература
- Binary_File_Descriptor_library
- systemd.service — Конфигурация сервисного модуля
- Kubernets Pod Lifecycle
поделиться больше
Практика улучшения ByteDance на движке хранения RocksDB
Глубокое понимание перегрузки TLB и оптимизации, вызванной jemalloc в ядре Linux.
Команда инфраструктуры ByteDance
Команда инфраструктуры ByteDance — это важная команда, которая поддерживает бесперебойную работу множества пользовательских продуктов ByteDance, включая Douyin, Today's Toutiao, Xigua Video и Volcano Small Video.Стабильная разработка обеспечивает гарантию и импульс.
В компании команда инфраструктуры в основном отвечает за построение частного облака ByteDance, управление кластерами из десятков тысяч серверов, а также отвечает за десятки тысяч гибридных развертываний вычислений/хранилищ и гибридных развертываний онлайн/офлайн, поддерживая стабильное хранилище. нескольких массивных данных ЭП.
В культурном плане команда активно использует открытый исходный код и инновационные аппаратные и программные архитектуры. Мы давно набираем студентов по направлению инфраструктура, подробнее см.job.bytedance.com ("Читать исходный текст" в конце статьи), при заинтересованности можно обращаться на эл. guoxinyu.0372@bytedance.com.
Добро пожаловать в техническую команду ByteDance