Modern strace (Дмитрий Левин, OSSDEVCONF-2018) — различия между версиями

Версия 08:41, 10 октября 2018

Докладчик: Дмитрий Левин

strace — инструмент для отслеживания и влияния на взаимодействия пользовательских процессов и ядра Linux: системных вызовов, сигналов и изменений состояния процесса. Будучи традиционным инструментом, популярным среди разработчиков для диагностики, отладки и изучения поведения ПО, проект продолжает активно развиваться, и за минувшие несколько лет в strace реализованы новые полезные возможности.

Видео

Презентация

Thesis

Введение

strace как инструмент мониторинга взаимодействия пользовательских процессов с ядром существует уже почти 27 лет и широко применяется для диагностики, отладки и изучения поведения ПО. Многочисленные параметры управления фильтрацией дают возможность пользователю strace легко и гибко настраивать отображение системных вызовов и сигналов. С каждым выпуском strace таких возможностей становится больше, а точность отображения — выше.

Начиная с версии 4.13, выпущенной в июле 2016 года, расписание выпусков новых версий strace синхронизировано с расписанием выпусков новых версий ядра linux. Таким образом новые интерфейсы, добавляемые в релизы ядра linux, сопровождаются соответствующими парсерами, добавляемыми в релизы strace.

strace относится к традиционным инструментам, и пользователи со стажем зачастую не подозревают о новых возможностях, появившихся в strace за последние несколько лет, таких как

отслеживание файловых путей: параметр -y;
отслеживание сетевых протоколов: параметр -yy;
отслеживание стека вызовов: параметр -k;
сбор статистики по времени, проведённому отслеживаемыми процессами в системных вызовах: параметр -w;
фильтрация системных вызовов по файловым путям: параметр -P;
фильтрация системных вызовов по именам: с помощью регулярных выражений и новых классов системных вызовов;
модификация системных вызовов: инъекции ошибок, кодов возврата, сигналов, и задержек.

Отслеживание файловых путей и фильтрация по файловым путям

Начиная с версии 4.7, выпущенной в мае 2012 года, реализована возможность отслеживания файловых путей, соответствующих дескрипторам, с помощью параметра -y. Например,

$ strace -y -e %fstat cat /dev/null > /dev/full 
fstat(3</etc/ld.so.cache>, {st_mode=S_IFREG|0644, st_size=14318, ...}) = 0
fstat(3</lib64/libc-2.27.so>, {st_mode=S_IFREG|0755, st_size=1800216, ...}) = 0
fstat(1</dev/full>, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 7), ...}) = 0
fstat(3</dev/null>, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), ...}) = 0
+++ exited with 0 +++

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

$ strace -P /etc/ld.so.cache ls /var/empty
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=14318, ...}) = 0
mmap(NULL, 14318, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f21cc43c000
close(3) = 0
+++ exited with 0 +++

Отслеживание сетевых протоколов и устройств

Начиная с версии 4.10, выпущенной в марте 2015 года, реализована возможность отслеживания характеристик сетевых протоколов, соответствующих дескрипторам сокетов, с помощью параметра -yy. Начиная с версии 4.22, выпущенной в апреле этого года, с помощью этого же параметра можно отслеживать и характеристики устройств. Например,

$ netcat -l 127.0.0.1 12345 & strace -yy -e %network,%desc netcat 127.0.0.1 12345 < /dev/null
...
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3<TCP:[4100654321]>
connect(3<TCP:[4100654321]>, {sa_family=AF_INET, sin_port=htons(12345),
  sin_addr=inet_addr("127.0.0.1")}, 16) = 0
poll([{fd=3<TCP:[127.0.0.1:34567->127.0.0.1:12345]>, events=POLLIN},
  {fd=0</dev/null<char 1:3>>, events=POLLIN}], 2, -1) = 1 ([{fd=0, revents=POLLIN}])
read(0</dev/null<char 1:3>>, "", 2048) = 0
shutdown(3<TCP:[127.0.0.1:34567->127.0.0.1:12345]>, SHUT_WR) = 0
poll([{fd=3<TCP:[127.0.0.1:34567->127.0.0.1:12345]>, events=POLLIN},
  {fd=-1}], 2, -1) = 1 ([{fd=3, revents=POLLIN|POLLHUP}])
read(3<TCP:[127.0.0.1:34567->127.0.0.1:12345]>, "", 2048) = 0
shutdown(3<TCP:[127.0.0.1:34567->127.0.0.1:12345]>, SHUT_RD)
  = -1 ENOTCONN (Transport endpoint is not connected)
close(3<TCP:[127.0.0.1:34567->127.0.0.1:12345]>) = 0
+++ exited with 0 +++

Отслеживание стека вызовов

Начиная с версии 4.9, выпущенной в августе 2014 года, реализована экспериментальная возможность отслеживания стека вызовов функций с помощью параметра -k. Начиная с версии 4.23, выпущенной в июне этого года, усовершенствованная реализация этой возможности с использованием библиотеки libdw уже не носит экспериментальный статус. Например,

$ strace -k -e rmdir rmdir /
rmdir("/") = -1 EBUSY (Device or resource busy)
 > /lib64/libc-2.27.so(rmdir+0x7) [0xe9fa7]
 > /bin/rmdir(main+0x138) [0x401748]
 > /lib64/libc-2.27.so(__libc_start_main+0xe6) [0x21bd6]
 > /bin/rmdir(_start+0x29) [0x401939]
rmdir: failed to remove '/': Device or resource busy
+++ exited with 1 +++

Cбор статистики

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

$ strace -cw -e execve,nanosleep sleep 1
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 99.99    1.000041     1000040         1           nanosleep
  0.01    0.000124         123         1           execve
------ ----------- ----------- --------- --------- ----------------
100.00    1.000164                     2           total

Фильтрация системных вызовов по именам

Начиная с версии 4.17, выпущенной в мае 2017 года, синтаксис описания множества системных вызовов существенно расширился.

В описании имён системных вызовов теперь поддерживаются регулярные выражения:

strace -e trace=/regexp.

В описании множества системных вызовов поддерживаются описания, которым не соответствует ни одного системного вызова:

strace -e trace=?set.

Имена классов системных вызовов теперь начинаются с префикса %:

strace -e trace=%class.

Прежний способ именования классов без префикса % поддерживается, но уже считается устаревшим и не рекомендуется для применения.

Добавлены новые классы системных вызовов:

%stat – stat, stat64, oldstat и их вариации;
%lstat – lstat, lstat64, oldlstat и их вариации;
%fstat – fstat, fstat64, fstatat64, newfstatat, oldfstat и их вариации;
%%stat – stat, lstat, fstat, fstatat, statx и их вариации;
%statfs – эквивалент /^(.*_)?statv?fs;
%fstatfs – эквивалент /fstatv?fs;
%%statfs – эквивалент /statv?fs|fsstat|ustat.

Модификация системных вызовов

Начиная с версии 4.15, выпущенной в декабре 2016 года, реализован механизм инъекций ошибок в системные вызовы. Синтаксис syscall fault injection выглядит следующим образом:

strace -e fault=set[:error=errno][:when=expr]

Начиная с версии 4.16, выпущенной в феврале 2017 года, реализован более общий механизм вмешательства в системные вызовы, который, помимо инъекций ошибок, позволяет осуществлять инъекции кодов возврата и сигналов, а начиная с версии 4.22, выпущенной в апреле 2018 года, ещё и инъекции задержек. Интерфейс этого нового механизма выглядит следующим образом:

strace -e inject=set[parameters]

где parameters могут принимать следующие значения:

:error=errno либо :retval=value – инъекция ошибки либо кода возврата;
:syscall=syscall – подменяемый системный вызов для инъекции ошибок либо кода возврата;
:signal=sig – инъекция сигнала;
:delay_enter=usecs – инъекция задержки перед системным вызовом;
:delay_exit=usecs – инъекция задержки после системного вызова;
:when=expr – правило применения инъекции.

Пример инъекции ошибки:

$ strace -e trace=/open -e inject=/open:when=3:error=EACCES cat /dev/null
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/dev/null", O_RDONLY) = -1 EACCES (Permission denied) (INJECTED)
cat: /dev/null: Permission denied
+++ exited with 1 +++

Пример инъекции задержки:

$ dd if=/dev/zero of=/dev/null bs=1M count=10
10+0 records in
10+0 records out
10485760 bytes (10 MB, 10 MiB) copied, 0.00211354 s,
5.0 GB/s

$ strace -e inject=write:delay_exit=100000 -e write -o /dev/null \
  dd if=/dev/zero of=/dev/null bs=1M count=10
10+0 records in
10+0 records out
10485760 bytes (10 MB, 10 MiB) copied, 1.10658 s,
9.5 MB/s

Примечания и ссылки