[Перевод] Отладка C при помощи пакета Cosmopolitan Libc
Cosmopolitan Libc предоставляет набор отладочных возможностей, повышающих удобство разработки на C: трассировка вызовов функций, интеграция с gdb, среда выполнения ASAN/UBSAN и многое другое! На C написано много быстрого и критически важного кода. Если вы пользуетесь программами, написанными на C, если вам приходится предусматривать интерфейсы для работы с библиотеками на C, исправлять баги в коде на C, либо даже переписывать имеющуюся на С программу на каком-то другом языке, то именно этот инструмент помогает понять, что делается в вашем коде на C. Отладка — это не просто россыпь инструкций printf. В этом посте будет рассмотрено, как Cosmopolitan Libc помогает наверняка и как следует отлаживать код C. Все примеры находятся в этом репозитории.
Программа для примера
Рассмотрим hex16.c: пользователь указывает в командной строке файл, программа открывает этот файл, выводит в консоль (до) 16 первых байт в виде шестнадцатеричных значений, а затем преобразует все считанные байты в ASCII-строку. Весь этот код находится здесь.
#include
#define NUM_CHARS 16
void hex16(const char *filename) {
FILE *fp = fopen(filename, "r");
char res[NUM_CHARS];
int i, c;
printf("hex16.c -- reading file %s\n", filename);
for (i = 0; i < NUM_CHARS; i++) {
c = fgetc(fp);
if (feof(fp) || c == -1) break;
printf("0x%02x ", c);
res[i] = (char)c;
}
res[i] = '\0';
fclose(fp);
printf("\n%s\n", res);
}
int main(int argc, char **argv) {
hex16(argv[1]);
return 0;
}
Давайте соберём вышеприведённую программу при помощи make, а затем протестируем её на файле-примере:
make hex16.com
./hex16.com ./sample1.txt
# hex16.c -- reading file ./sample1.txt
# 0x63 0x6f 0x73 0x6d 0x6f 0x20 0x6c 0x69 0x62 0x63 0x0a
# cosmo libc
Но что произойдёт, если не предоставить файл, либо предоставить несуществующий файл?
./hex16.com
# Ошибка сегментирования
./hex16.com ./missing.txt
# Ошибка сегментирования
Хм, формулировка ошибка сегментирования не слишком информативна. Из-за какой-то части программы происходит аварийное завершение, но где именно?
gdb и обратные цепочки вызовов
Работая с Cosmopolitan Libc, можно обеспечить интеграцию с gdb и заказать подробные обратные цепочки вызовов для вашей программы на C всего в одной строке: добавьте ShowCrashReports (); в самом начале функции main. Давайте соберём hex16-backtrace.c, представляющую собой вот такой код:
make hex16-backtrace.com
# попробуем без аргументов
./hex16-backtrace.com
# или попробуем с несуществующим файлом
./hex16-backtrace.com ./missing.txt
Теперь gdb доступна у вас в $PATH, и вы получите TUI (пользовательский интерфейс командной строки), в котором выводится содержимое регистра и обратная цепочка вызовов, приведших к аварийному завершению — как на следующем скриншоте:
Введите bt и нажмите Enter, чтобы просмотреть обратную цепочку вызовов в gdb, а затем выйдите из программы, нажав Ctrl+D. О том, как задать конфигурацию для gdb, рассказано в файле README по Cosmopolitan Libc здесь.
Если gdb недоступна, или если вы выполняете программу в рамках тестового сценария, то обратную цепочку вызовов в текстовом виде. В ней также демонстрируется содержимое регистра и цепочка вызовов, ведущая к аварийной ситуации:
error: Uncaught SIGSEGV (SEGV_MAPERR) on X550LD pid 256891 tid 256891
./hex16-backtrace.com
EUNKNOWN/0/No error information
Linux #1 SMP Debian 5.10.106-1 (2022-03-17) X550LD 5.10.0-13-amd64
RAX 0000000000000000 RBX 00007ffe5c5c9a70 RDI 000000000042dd48 ST(0) 0.0
RCX 0000000000000000 RDX 0000000000000000 RSI 0000000000000240 ST(1) 0.0
RBP 00007000007fff80 RSP 00007000007fff60 RIP 000000000040b698 ST(2) 0.0
R8 0000000000000000 R9 0000000000000001 R10 0000000000000004 ST(3) 0.0
R11 0000000000000293 R12 0000000000000000 R13 000000000042dd46 ST(4) 0.0
R14 00007ffe5c5c9a80 R15 00007ffe5c5c9b90 VF PF ZF IF
XMM0 00000000000000000000000000000000 XMM8 00000000000000000000000000000000
XMM1 7865682f656c706d6178652d6f6d736f XMM9 00000000000000000000000000000000
XMM2 632d67756265642f6f6d736f632f6666 XMM10 00000000000000000000000000000000
XMM3 7574732f6d6168747561672f656d6f68 XMM11 00000000000000000000000000000000
XMM4 6f632e65636172746b6361622d363178 XMM12 00000000000000000000000000000000
XMM5 65682f656c706d6178652d6f6d736f63 XMM13 00000000000000000000000000000000
XMM6 2d67756265642f6f6d736f632f666675 XMM14 00000000000000000000000000000000
XMM7 74732f6d6168747561672f656d6f682f XMM15 00000000000000000000000000000000
0x000000000040b697: fixpathname at /home/jart/cosmo/libc/stdio/fopen.c:26
(inlined by) fopen at /home/jart/cosmo/libc/stdio/fopen.c:62
0x00000000004098d0: hex16 at /home/gautham/stuff/cosmo/debug-cosmo-example/hex16-backtrace.c:5
0x000000000040291e: main at /home/gautham/stuff/cosmo/debug-cosmo-example/hex16-backtrace.c:22
0x00000000004029cb: cosmo at /home/jart/cosmo/libc/runtime/cosmo.S:77
0x0000000000402503: _start at /home/jart/cosmo/libc/crt/crt.S:103
10008004-10008004 rw-pa- 1x automap 64kB w/ 7872kB hole
10008080-100080ff rw-pa- 128x automap 8192kB w/ 96tB hole
6fe00004-6fe00004 rw-paF 1x g_fds 64kB
70000000-7000007f rw-Sa- 128x stack 8192kB
# суммарно 16 мБ отображаемой памяти
./hex16-backtrace.com
Из обратной цепочки вызовов становится понятно, что, если не указать файл, то случится отказ с участием fopen, поэтому нужно обновить программу, чтобы проверить, каков первый параметр fopen (т.е. argv[1]) — NULL или нет. Обратите внимание: для корректной генерации обратной цепочки вызовов требуется, чтобы файл hex16-backtrace.com.dbg находился в том же каталоге, что и hex16-backtrace.com, поскольку в нём содержится необходимая отладочная информация.
Если просто знать обратную цепочку тех вызовов, что привели к аварии, можно сэкономить время, необходимое на исправление ошибки. При портировании make на Cosmopolitan Libc мы добавили ShowCrashReports и убедились, что make выполняет несколько крупных вызовов alloca, которые и приводят к аварийному завершению. Чтобы это исправить, нужно было добавить вызов STATIC_STACK_SIZE в функцию main, после чего make могла собрать весь монорепозиторий Cosmopolitan Libc.
Отслеживание вызовов функций при помощи --ftrace
Иногда бывает недостаточно одной только обратной цепочки вызовов, которые привели к отказу. Cosmopolitan Libc позволяет логировать все вызовы функций за время выполнения программы. Просто передайте --ftrace в конце вашей программы следующим образом:
./hex16.com ./missing.txt --ftrace
# усечённый пример
FUN 257012 1'567'864 48 &main
FUN 257012 1'573'031 112 &hex16
FUN 257012 1'578'356 160 &fopen
FUN 257012 1'612'346 336 &printf
FUN 257012 1'720'829 144 &fgetc
FUN 257012 1'726'479 176 &fgetc_unlocked
Segmentation Fault- В первом столбце указано, что перед нами вызов функции
- Во втором столбце показаны ID процесса/ID потока, в которых вызывается функция
- В третьем столбце примерно отмечено время, истекшее с начала выполнения программы
- В последнем столбце приведено имя вызванной функции
Вывод ftrace по умолчанию транслируется в stderr; полезнее перенаправить его в файл, чтобы впоследствии проанализировать. Для ftrace не требуется ShowCrashReports () в начале функции main, однако всё-таки требуется hex16.com.dbg для hex16.com. О том, как работает ftrace, можно подробнее почитать здесь.
ftrace также помогает познакомиться с производительностью программы. Я написал обёртку на Python для ftrace, поэтому могу проверить, как идут дела в среде исполнения CPython3.6. Например, вот сколько вызовов требуется, чтобы сложить два значения в Python3.6, собранном при помощи Cosmopolitan Libc:
import cosmo
a = 1
b = 2
with cosmo.ftrace():
c = a + b
&meth_dealloc
&PyFrame_BlockSetup 76
&object_dealloc 265
&PyObject_Free 82
&_PyObject_Free.isra.0 52
&PyDict_GetItem 333
&lookdict_unicode_nodummy 157
&PyDict_GetItem 166
&lookdict_unicode_nodummy 34
&PyNumber_Add 273
&binary_op1 69
&long_add 178
&PyLong_FromLong 135
&PyDict_SetItem 273
&insertdict 164
&lookdict_unicode_nodummy 53
&PyFrame_BlockPop 320
&PyObject_CallFunctionObjArgs 249
&object_vacall 40
&_PyObject_FastCallDict 95
&_PyCFunction_FastCallDict 53
&_PyMethodDef_RawFastCallDict 86
&_PyStack_AsTuple 61
&PyTuple_New 121
&FtracerObject_exit 199
Числа справа указывают, сколько примерно времени требуется на выполнение каждой функции, и эта информация достаточно полезна для такого «медленного» языка как Python3.61. При помощи ftrace удобно написать собственный импортёр sys.meta_path для Python3.6 под Cosmopolitan Libc. Я просто переносил код из Python в C до тех пор, пока логи ftrace logs не перестали уменьшаться.
Трассировка системных вызовов при помощи --strace
Иногда при трассировке вызовов функций предоставляется слишком много информации, а вы всего лишь хотите уточнить, в какой области произошла ошибка — опираясь при этом на информацию из логов. Если у вас в программе используется целый ворох системных вызовов, то их можно логировать как функции, сообщая --strace в конце вызова вашей программы, вот так:
./hex16.com ./missing.txt --strace
SYS 257304 43'627 bell system five system call support 171 magnums loaded on gnu/systemd
SYS 257304 99'854 mmap(0x700000000000, 8'388'608, PROT_READ|PROT_WRITE, MAP_STACK|MAP_ANONYMOUS, -1, 0) → 0x700000000000 (8'388'608 bytes total)
SYS 257304 892'097 getenv("TERM") → "xterm-256color"
SYS 257304 908'170 openat(AT_FDCWD, "./missing.txt", 0, 0) → -1 errno= 2
SYS 257304 932'876 write(1, u"hex16.c -- reading file ./missing.txt◙", 38) → 38 errno= 2- В первом столбце указано, что перед нами системный вызов
- Во втором столбце показаны ID процесса/ID потока, в которых совершается вызов
- В третьем столбце примерно отмечено время, истекшее с начала выполнения программы
- В четвёртом столбце показан вывод системного вызова вместе со значениями ошибок errno
Флаг --strace, в отличие от ShowCrashReports и ftrace, не требует наличия файла hex16.com.dbg. Как теперь видно, openat приводит к -1 errno 2, если файл не существует. Поэтому давайте обновим код и проверим указатель FILE *, прежде, чем вызывать fgetc. Ниже показана исправленная программа hex16-fixed.c:
#include
#define NUM_CHARS 16
void hex16(const char *filename) {
FILE *fp = fopen(filename, "r");
char res[NUM_CHARS];
int i, c;
if (!fp) {
printf("unable to read %s!\n", filename);
return;
}
printf("hex16.c -- reading file %s\n", filename);
for (i = 0; i < NUM_CHARS; i++) {
c = fgetc(fp);
if (feof(fp) || c == -1) break;
printf("0x%02x ", c);
res[i] = (char)c;
}
res[i] = '\0';
fclose(fp);
printf("\n%s\n", res);
}
int main(int argc, char **argv) {
if (argc != 2) {
printf("USAGE:\n\t%s FILENAME\n", argv[0]);
return 1;
}
hex16(argv[1]);
return 0;
} ASAN/UBSAN
В hex16.com были исправлены ошибки, так что давайте выполним ещё один тестовый сценарий, чтобы посмотреть, нет ли там ещё ошибок. Что произойдёт, если в подаваемом на вход файле будет 16 или более символов?
cat ./sample2.txt
# cosmopolitan libc
./hex16.com ./sample2.txt
# hex16.c -- reading file ./sample2.txt
# 0x63 0x6f 0x73 0x6d 0x6f 0x70 0x6f 0x6c 0x69 0x74 0x61 0x6e 0x20 0x6c 0x69 0x62
# cosmopolitan lib2
./hex16.com ./sample2.txt
# hex16.c -- reading file ./sample2.txt
# 0x63 0x6f 0x73 0x6d 0x6f 0x70 0x6f 0x6c 0x69 0x74 0x61 0x6e 0x20 0x6c 0x69 0x62
# cosmopolitan lib3
Поведение hex16.com не согласуется в sample2.txt — иногда в консоль выводятся лишние мусорные символы. Но также здесь есть res[i] = '\0' после цикла, этот код нужен для завершения строки — так что же здесь происходит? Давайте применим для сборки среду выполнения ASAN/UBSAN, применяемую с Cosmopolitan Libc — и найдём ответ:
make clean
make MODE=dbg hex16-backtrace.com
./hex16-backtrace.com ./sample2.txt
hex16-backtrace.c:16: ubsan error: 'int' index 16 into 'char [16]' out of bounds (tid 257624)
0x0000000000480c00: __ubsan_handle_out_of_bounds at /home/jart/cosmo/libc/intrin/ubsan.c:289
0x0000000000421658: hex16 at /home/gautham/stuff/cosmo/debug-cosmo-example/hex16-backtrace.c:16
0x0000000000402bf1: main at /home/gautham/stuff/cosmo/debug-cosmo-example/hex16-backtrace.c:22
0x0000000000402cfd: cosmo at /home/jart/cosmo/libc/runtime/cosmo.S:77
0x0000000000402543: _start at /home/jart/cosmo/libc/crt/crt.S:103
Ах, оказывается, когда в файле более 16 символов, завершающий нуль записывается уже за пределами буфера. В результате при записи этой строки происходит переполнение буфера. Теперь можно изменить буфер так, чтобы в нём помещался ещё один дополнительный символ — именно на такой случай. Это приводит нас к новому и, опять же, фиксированному hex16-ubsan.c.
Среда выполнения ASAN/UBSAN для Cosmopolitan добавляет ещё одно волшебное усовершенствование к вашему потоку разработки, применяемому в C2, почти даром. Время сборки едва увеличивается, компилятору не приходится сообщать никаких новых аргументов, тесты можно писать как обычно, а производительность при работе с двоичными файлами почти не снижается. Естественно, теперь во время выполнения ваших двоичных файлов будет сохраняться безопасность памяти.
На всякий пожарный случай (или просто для нетерпеливых)
Иногда попадается досадный баг, возникающий лишь вследствие конкретной последовательности событий, а вам этот баг никак не отловить. Он не связан с ASAN/UBSAN — среда времени выполнения сообщает вам, что некоторые обращения к памяти получаются недействительными, но вы не знаете, с чего всё это началось. Системные вызовы не проливают света на проблему, поскольку проблема не в том, как ваша программа взаимодействует с ОС. У вас слишком много последовательностей вызовов функций, а ещё они перемешаны из-за многопоточности, поэтому сложно понять, что же тут происходит. Перед выполнением программы вы запускаете gdb и расставляете с дюжину контрольных точек, но она всё равно падает на взлёте, а вам не хватает терпения, чтобы подловить её в нужных местах. В отчаянии вы прибегаете к старым испытанным инструкциям printf, но и они не работают! У вас нет подходящих инструментов, по крайней мере правильно настроенных — как в случае с тем багом, когда Python не установил stdin, так как модуль encodings, оказывается, не был загружен3. Другой пример — когда в Rust хранилище, действующее в пределах потока, выполняет от libc, казалось бы, дурацкие запросы к памяти при запуске программы4.
Вы загнаны в угол. Как отладить такой с виду неуязвимый гейзенбаг?
1. Вы представляете себя на месте чипа x86_64 (с батареей, оперативной памятью и периферией RAM) и принимаетесь методом утёнка разбирать каждую ассемблерную инструкцию, беспомощно провожая их взглядом до тех пор, пока баг не будет найден (если будет).
2. А можно просто воспользоваться kprintf из Cosmopolitan Libc.
kprintf — это палочка-выручалочка из отладочного арсенала Cosmopolitan Libc. Взгляните на исходный код kprintf. Это бережливая реализация printf, предназначенная для работы где угодно. Именно этим принято пользоваться в Cosmopolitan Libc, когда другие функции пытаются писать логии, даже после аварийного останова программы. Вот что происходит, если вы попытаетесь вывести в консоль при помощи kprintf какой-нибудь странный адрес памяти:
kprintf("%s\n", 31415);
//!!7ab7
Можете даже клонировать монорепозиторий Cosmopolitan Libc и добавить вызовы kprintf во внутренние функции Cosmopolitan Libc.
Далее можете тестировать ваш код при помощи вашей же libc, кастомизированной для нужной вам отладки! Когда больше ничего не помогает, kprintf может справиться с задачей, при условии, что вы разyмно им пользуетесь, выводя значение каждой переменной после каждой инструкции в каждой функции, которую должна вызвать ваша программа.
Заключительные замечания
Никто с первого раза не напишет идеальный код. Но чем больше глаз — тем меньше багов. С Cosmopolitan Libc отладка превращается в искусство плаща и кинжала, а не в блуждание в потёмках. Вместо того, чтобы просто набивать шишки, можно рассмотреть проблему в пяти различных ракурсах, разобравшись таким образом, что именно делает ваша программа, и где она начинает терять трек:
- Можно вывести простую обратную цепочку вызовов с содержимым регистра
- Можно логировать все вызовы функций (или их часть), чтобы посмотреть, какая последовательность может приводить к замедлению или аварийному завершению программы
- Можно логировать все системные вызовы и проверить, как ваша программа взаимодействует с операционной системой
- Можно освоить работу с gdb и препарировать вашу программу, расставляя в ней всё больше контрольных точек или прибегая к другим подобным фокусам
- Если уже ум за разум заходит — всегда можно вернуться к привычным методам, только теперь пользоваться kprintf вместо printf — и приобрести суперсилу
Под всеми библиотеками, синтаксисом, абстракциями и оптимизациями всё равно должна лежать идея, объясняющая, что происходит. Писать программы гораздо интереснее, если понимаешь, чем именно сейчас занят компьютер. Подробная обратная связь помогает лучше разбираться в программах, а если эта связь ещё и оперативная — быстрее их разрабатывать. В Cosmopolitan Libc предлагается отладочный инструментарий, помогающий нам полнее представлять создаваемые нами программы.
________________________________________
1. В последние годы в Python серьёзно дорабатывается производительность. 5 августа 2022 года вышел CPython 3.11.0rc1, и я портировал его в Cosmopolitan Libc — вот здесь. В версии 3.11 пока нет ftrace и некоторых других ништяков, но будет интересно проверить, как ftrace позволит познакомиться с новыми «JIT-подобными» оптимизационными трюками CPython. ↩︎
2. Настоящая красота начинается, если при разработке включить MODE=dbg: вы по-прежнему работаете так же быстро, как и ранее, но теперь приобретаете шестое чувство, интуицию или дисциплину программирования на C. Поскольку по соображениям безопасности в UBSAN налагаются только гибкие ограничения, можно приступать к написанию UBSAN-пригодного кода, в то же время уверенно пробуя разные трюки с производительностью и оставаясь в уверенности, что UBSAN вас спасёт, если дела выйдут из-под контроля. Ранее я никогда не писал парсера для JSON, но писал парсер на C, в котором были предусмотрены NaN-ограничения и манипуляции с указателями, на это у меня ушло несколько вечеров. При включенном MODE=dbg он также проходит около 90% тестов из самого исчерпывающего набора для JSON. ↩︎
3. Это был гнусный баг, случавшийся в Python 3 при импорте стандартной библиотеки, если вы забывали правильно указать расположение каталога. Вот как примерно я это припоминаю: по умолчанию в Python 3 используется кодировка Unicode. Но когда она запускается, оказывается, что это не вполне Unicode, кодировка во многом походит на ASCII. Python в какой-то степени проверяет локаль, прежде, чем пытается импортировать encodings.py, а потом настраивает почти всё остальное. Поэтому, если файл encodings.py не найден, то Python застревает в этом чистилище и аварийно завершается. Мне не удавалось подключить сообщения об ошибках к encodings.py, так что я просто проверял каждый вызов в импортированной последовательности при помощи kprintf, пока не выяснялось, как исправить ситуацию. ↩︎
4. Без паники! Я же сказал, кажется. Не было ничего странного в том, как в Rust инициализируется хранилище в пределах потока, поскольку написанные мной примеры на Rust нормально работали с glibc. В конце концов, удалось найти баг — он был связан с инициализацией указателя в pthread_create в Cosmopolitan Libc, а исправление уложилось в одну строку. Сейчас в Cosmopolitan Libc уже поддерживаются pthreads, и допускается многопоточное исполнение скриптов Python 3.11 и исполняемых файлов Rust. ↩︎
