Thank you for reading this post, don't forget to subscribe!
strace
— утилита для Linux, которая позволяет отследить выполнение системных вызовов (system call
) и сигналов к ядру системы
КОМАНДА STRACE LINUX
Как я уже сказал, команда strace показывает все системные вызовы программы, которые та отправляет к системе во время выполнения, а также их параметры и результат выполнения. Но при необходимости можно подключиться и к уже запущенному процессу. Перед тем, как перейти к практике, разберём опции утилиты и её синтаксис:
$ strace опции команда аргументы
В самом простом варианте strace запускает переданную команду с её аргументами и выводит в стандартный поток ошибок все системные вызовы команды. Давайте разберём опции утилиты, с помощью которых можно управлять её поведением:
- -i - выводить указатель на инструкцию во время выполнения системного вызова;
- -k - выводить стек вызовов для отслеживаемого процесса после каждого системного вызова;
- -o - выводить всю информацию о системных вызовах не в стандартный поток ошибок, а в файл;
- -q - не выводить сообщения о подключении о отключении от процесса;
- -qq - не выводить сообщения о завершении работы процесса;
- -r - выводить временную метку для каждого системного вызова;
- -s - указать максимальный размер выводимой строки, по умолчанию 32;
- -t - выводить время суток для каждого вызова;
- -tt - добавить микросекунды;
- -ttt - добавить микросекунды и количество секунд после начала эпохи Unix;
- -T - выводить длительность выполнения системного вызова;
- -x - выводить все не ASCI-строки в шестнадцатеричном виде;
- -xx - выводить все строки в шестнадцатеричном виде;
- -y - выводить пути для файловых дескрипторов;
- -yy - выводить информацию о протоколе для файловых дескрипторов;
- -c - подсчитывать количество ошибок, вызовов и время выполнения для каждого системного вызова;
- -O - добавить определённое количество микросекунд к счетчику времени для каждого вызова;
- -S - сортировать информацию выводимую при опции -c. Доступны поля time, calls, name и nothing. По умолчанию используется time;
- -w - суммировать время между началом и завершением системного вызова;
- -e - позволяет отфильтровать только нужные системные вызовы или события;
- -P - отслеживать только системные вызовы, которые касаются указанного пути;
- -v - позволяет выводить дополнительную информацию, такую как версии окружения, статистику и так далее;
- -b - если указанный системный вызов обнаружен, трассировка прекращается;
- -f - отслеживать также дочерние процессы, если они будут созданы;
- -ff - если задана опция -o, то для каждого дочернего процесса будет создан отдельный файл с именем имя_файла.pid.
- -I - позволяет блокировать реакцию на нажатия Ctrl+C и Ctrl+Z;
- -E - добавляет переменную окружения для запускаемой программы;
- -p - указывает pid процесса, к которому следует подключиться;
- -u - запустить программу, от имени указанного пользователя.
Вы знаете основные опции strace, но чтобы полноценно ею пользоваться, нужно ещё разобраться с системными вызовами, которые используются чаще всего. Мы не будем рассматривать все, а только основные. Многие из них вы уже и так знаете, потому что они называются так же, как и команды в терминале:
- fork - создание нового дочернего процесса;
- read - попытка читать из файлового дескриптора;
- write - попытка записи в файловый дескриптор;
- open - открыть файл для чтения или записи;
- close - закрыть файл после чтения или записи;
- chdir - изменить текущую директорию;
- execve - выполнить исполняемый файл;
- stat - получить информацию о файле;
- mknod - создать специальный файл, например, файл устройства или сокет;
А теперь разберём примеры strace Linux.
ПРИМЕРЫ ИСПОЛЬЗОВАНИЯ STRACE
1. ЗАПУСК ПРОГРАММЫ
Самый простой способ запуска утилиты - просто передать ей в параметрах имя команды или исполняемый файл программы, которую мы хотим исследовать. Например, uname:
strace uname
Как и ожидалось, мы видим список системных вызовов, которые делает утилита, чтобы узнать версию ядра. Синтаксис вывода такой:
имя_системного_вызова (параметр1, параметр2) = результат сообщение
Имя системного вызова указывает, какой именно вызов использовала программа. Для большинства вызовов характерно то, что им нужно передавать параметры, имена файлов, данные и так далее. Эти параметры передаются в скобках. Далее идет знак равенства и результат выполнения. Если всё прошло успешно, то здесь будет ноль или положительное число. Если же возвращается отрицательное значение, делаем вывод, что произошла ошибка. В таком случае выводится сообщение.
Например, в нашем выводе есть сообщения об ошибке:
Здесь результат выполнения -1 и сообщение говорит, что файл не найден. Но на работу программы это не влияет. Это проблема подключения сторонних библиотек и к этой утилите она не имеет отношения. А основная работа программы выполняется строчкой:
И здесь ядро вернуло положительный результат.
2. ПОДКЛЮЧЕНИЕ К ЗАПУЩЕННОЙ ПРОГРАММЕ
Если программа, которую нам надо отследить, уже запущена, то не обязательно её перезапускать с нашей утилитой. Можно подключиться к ней по ее идентификатору PID. Для тестирования этой возможности запустим утилиту dd, которая будет записывать нули из /dev/zero в файл file1:
dd if=/dev/zero of=~/file1
Теперь узнаем PID нашего процесса, поскольку он такой один, можно воспользоваться pidof, вы же можете использовать ps:
pidof dd
И осталось подключиться к нашему процессу:
sudo strace -p 31796
В выводе утилиты мы видим, что она читает данные из одного места с помощью вызова read и записывает в другое через write. Чтобы отсоединится от процесса, достаточно нажать Ctrl+C. Дальше рассмотрим примеры strace Linux для фильтрации данных.
3. ФИЛЬТРАЦИЯ СИСТЕМНЫХ ВЫЗОВОВ
Утилита выводит слишком много данных, и, зачастую, большинство из них нас не интересуют. С помощью опции -e можно применять различные фильтры для более удобного поиска проблемы. Мы можем отобразить только вызовы stat, передав в опцию -e такой параметр trace=stat:
sudo strace -e trace=stat nautilus
Кроме непосредственно системных вызовов, в качестве параметра для trace можно передавать и такие значения:
- file - все системные вызовы, которые касаются файлов;
- process - управление процессами;
- network - сетевые системные вызовы;
- signal - системные вызовы, что касаются сигналов;
- ipc - системные вызовы IPC;
- desc - управление дескрипторами файлов;
- memory - работа с памятью программы.
4. ВОЗВРАЩЕНИЕ ОШИБКИ
Можно попросить strace вернуть программе ошибку по нужному системному вызову -e, но с параметром fault. Синтаксис конструкции такой:
fault=имя_вызова:error=тип_ошибки:when=количество
С именем вызова всё понятно, тип ошибки, номер ошибки, которую надо вернуть. А с количеством всё немного сложнее. Есть три варианта:
- цифра - вернуть ошибку только после указанного количества запросов;
- цифра+ - вернуть ошибку после указанного количества запросов и для всех последующих;
- цифра+шаг - вернуть ошибку для указанного количества и для последующих с указанным шагом.
Например, сообщим uname, что системного вызова uname не существует:
sudo strace -e fault=uname uname
В выводе видим, что система вернула программе нашу ошибку, а потом та с помощью вызова write говорит пользователю, что узнать версию и называние системы невозможно.
5. ФИЛЬТРАЦИЯ ПО ПУТИ
Если вас интересует не определённый вызов, а все операции с нужным файлом, то можно выполнить фильтрацию по нему с помощью опции -P. Например, меня интересует, действительно ли утилита lscpu обращается к файлу /proc/cpuinfo, чтобы узнать информацию о процессоре:
strace -P /proc/cpuinfo lscpu
И в результате мы видим, что действительно обращается. Она открывает его для чтения с помощью вызова openat.
6. СТАТИСТИКА СИСТЕМНЫХ ВЫЗОВОВ
С помощью опции -с вы можете собрать статистику для системных вызовов, которые использует программа. Например, сделаем это для nautilus:
sudo strace -c nautilus
Во время работы утилита ничего выводить не будет. Результат будет рассчитан и выведен, когда вы завершите отладку. В выводе будут такие колонки:
- time - процент времени от общего времени выполнения системных вызовов;
- seconds - общее количество секунд, затраченное на выполнение системных вызовов этого типа;
- calls - количество обращений к вызову;
- errors - количество ошибок;
- syscall - имя системного вызова.
Если вы хотите получать эту информацию в режиме реального времени, используйте опцию -C.
7. ОТСЛЕЖИВАНИЕ ВРЕМЕНИ ВЫПОЛНЕНИЯ
Чтобы отображать время выполнения каждого системного вызова, используйте опцию -t:
strace -t uname
Можно также отображать микросекунды:
strace -tt uname
Или отображать время в формате UNIX:
strace -ttt uname
Чтобы добавить время выполнения вызова, добавьте -T:
strace -ttt -T uname
==================================================
Для примера возьмем простую программу на С, которая выводит содержимое указанного файла:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 |
#include <stdio.h> #include <stdlib.h> int main() { char ch, file_name[25]; FILE *fp; printf("Enter the name of file you wish to see\n"); gets(file_name); fp = fopen(file_name,"r"); // read mode if( fp == NULL ) { perror("Error while opening the file.\n"); exit(EXIT_FAILURE); } printf("The contents of %s file are :\n", file_name); while( ( ch = fgetc(fp) ) != EOF ) printf("%c",ch); fclose(fp); return 0; } |
[/codesyntax]
Ее выполнение:
./openfile
Enter the name of file you wish to see
openfile.c
The contents of openfile.c file are :
include <stdio.h>
include <stdlib.h>
int main()
{
…
return 0;
}
Запускаем openfile
с starce
:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 |
strace ./openfile execve("./openfile", ["./openfile"], [/* 30 vars */]) = 0 brk(0) = 0x85b000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb7e074b000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=47052, ...}) = 0 mmap(NULL, 47052, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb7e073f000 close(3) = 0 open("/lib64/libc.so.6", O_RDONLY) = 3 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\356\1\0\0\0\0\0"..., 832) = 832 fstat(3, {st_mode=S_IFREG|0755, st_size=1920936, ...}) = 0 mmap(NULL, 3750152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb7e0199000 mprotect(0x7fb7e0323000, 2097152, PROT_NONE) = 0 mmap(0x7fb7e0523000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18a000) = 0x7fb7e0523000 mmap(0x7fb7e0528000, 18696, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb7e0528000 close(3) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb7e073e000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb7e073d000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb7e073c000 arch_prctl(ARCH_SET_FS, 0x7fb7e073d700) = 0 mprotect(0x7fb7e0523000, 16384, PROT_READ) = 0 mprotect(0x7fb7e074c000, 4096, PROT_READ) = 0 munmap(0x7fb7e073f000, 47052) = 0 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 7), ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb7e074a000 write(1, "Enter the name of file you wish "..., 39Enter the name of file you wish to see ) = 39 fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 7), ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb7e0749000 read(0, openfile.c "openfile.c\n", 1024) = 11 brk(0) = 0x85b000 brk(0x87c000) = 0x87c000 open("openfile.c", O_RDONLY) = 3 write(1, "The contents of openfile.c file "..., 38The contents of openfile.c file are : ) = 38 fstat(3, {st_mode=S_IFREG|0664, st_size=486, ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb7e0748000 read(3, "#include <stdio.h>\n#include <std"..., 4096) = 486 write(1, "#include <stdio.h>\n", 19#include <stdio.h> ) = 19 write(1, "#include <stdlib.h>\n", 20#include <stdlib.h> ... write(1, " fclose(fp);\n", 15 fclose(fp); ) = 15 write(1, " return 0;\n", 13 return 0; ) = 13 write(1, "}\n", 2} ) = 2 read(3, "", 4096) = 0 close(3) = 0 munmap(0x7fb7e0748000, 4096) = 0 exit_group(0) = ? +++ exited with 0 +++ |
[/codesyntax]
Например, тут виден вызов mmap()
, который выполняет запрос на выделение памяти:
…
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f115bfbb000
…
Проверяем
pmap 23342 | grep 7f115bfbb
00007f115bfbb000 12K rw--- [ anon ]
Или — файлы, к которым выполняется системный вызов open()
, после передачи имени файла функции gets()
:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 |
write(1, "Enter the name of file you wish "..., 39Enter the name of file you wish to see ) = 39 ... open("openfile.c", O_RDONLY) = 3 write(1, "The contents of openfile.c file "..., 38The contents of openfile.c file are : ) = 38 |
[/codesyntax]
Отображение определенных вызовов
Что бы вывести только список интересующих системных вызовов — используйте опцию -e
.
Например — отобразить только вызовы open()
:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
strace -e open ./openfile open("/etc/ld.so.cache", O_RDONLY) = 3 open("/lib64/libc.so.6", O_RDONLY) = 3 Enter the name of file you wish to see openfile.c open("openfile.c", O_RDONLY) = 3 The contents of openfile.c file are : include <stdio.h> include <stdlib.h> int main() { char ch, stpchar, file_name[25]; FILE *fp; ... |
[/codesyntax]
Что бы отобразить несколько определенных вызовов — добавьте -e trace=
, и через запятую — список вызовов:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
strace -e trace=open,mmap ./openfile mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd11b7a7000 open("/etc/ld.so.cache", O_RDONLY) = 3 mmap(NULL, 47052, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fd11b79b000 open("/lib64/libc.so.6", O_RDONLY) = 3 mmap(NULL, 3750152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fd11b1f5000 mmap(0x7fd11b57f000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18a000) = 0x7fd11b57f000 mmap(0x7fd11b584000, 18696, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fd11b584000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd11b79a000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd11b799000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd11b798000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd11b7a6000 Enter the name of file you wish to see mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd11b7a5000 ... |
[/codesyntax]
Сохранение вывода в файл
Так как текста может быть много — иногда вывод удобнее сохранить в файл.
Для этого используйте опцию -o
:
strace -o openfile_strace.log -e trace=open,mmap ./openfile
Enter the name of file you wish to see
sc
Error while opening the file.
Результат
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 |
cat openfile_strace.log mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fee12b6f000 open("/etc/ld.so.cache", O_RDONLY) = 3 ... mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fee12b6d000 open("sc", O_RDONLY) = -1 ENOENT (No such file or directory) mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fee12b6c000 +++ exited with 1 +++ |
[/codesyntax]
Трассировка вызовов запущенного процесса
Для подключения к уже работающему процессу — используйте опцию -p
.
Например — берем любой PID:
ps -au mid
PID TTY TIME CMD
1334 ? 00:04:17 uwsgi
1335 ? 00:04:17 uwsgi
1749 ? 00:13:26 uwsgi
…
Подключаемся к нему, записывая вывод в файл:
sudo strace -p 1334 -o uwsgi_strace.log -e mmap
[sudo] password for mid:
Process 1334 attached
^CProcess 1334 detached
Проверяем
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 |
cat uwsgi_strace.log lseek(2, 0, SEEK_CUR) = 525797 getsockopt(3, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0d\0\0\0"..., [104]) = 0 wait4(-1, 0x7ffc5a5853ac, WNOHANG, NULL) = 0 ... getsockopt(3, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0d\0\0\0"..., [104]) = 0 wait4(-1, 0x7ffc5a5853ac, WNOHANG, NULL) = 0 epoll_wait(9, <detached ...> |
[/codesyntax]
Отображение времени выполнения вызова
Добавим опцию -t
:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 |
strace -t -e trace=open,mmap ./openfile 14:04:51 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7a31229000 14:04:51 open("/etc/ld.so.cache", O_RDONLY) = 3 ... 14:04:51 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7a3121b000 14:04:51 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7a3121a000 ... |
[/codesyntax]
Статистика системных вызовов
С помощью опции -c
— можно получить наглядную статистику выполнения программы:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
strace -c ./openfile Enter the name of file you wish to see openfile.c The contents of openfile.c file are : include <stdio.h> include <stdlib.h> .. fclose(fp); return 0; } % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 0.00 0.000000 0 4 read 0.00 0.000000 0 31 write 0.00 0.000000 0 3 open 0.00 0.000000 0 3 close 0.00 0.000000 0 5 fstat 0.00 0.000000 0 11 mmap 0.00 0.000000 0 3 mprotect 0.00 0.000000 0 2 munmap 0.00 0.000000 0 3 brk 0.00 0.000000 0 1 1 access 0.00 0.000000 0 1 execve 0.00 0.000000 0 1 arch_prctl ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000000 68 1 total |
[/codesyntax]
Например, вызов:
[codesyntax lang="php" blockstate="collapsed"]
1 2 3 4 5 6 7 8 9 10 11 |
... open("openfile.c", O_RDONLY) = 3 ... [simterm] Описан тут>>>. А сам вызов open() можно найти тут>>>, после чего --- найти исходный код open.c, в котором и определяется open(): [simterm] ... SYSCALL_DEFINE3(open, const char __user *, filename, int, flags, umode_t, mode) ... |
[/codesyntax]