Отладка наблюдением

Иногда мелкие проблемы могут быть найдены путём наблюдения за поведением приложения в пространстве пользователя. Наблюдение за программами также может помочь в создании атмосферы доверия, что драйвер работает правильно. Например, мы могли чувствовать уверенность в scull после наблюдения за тем, как его реализация read реагировала на запросы чтения различных объёмов данных.

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

Команда strace представляет собой мощный инструмент, который показывает все системные вызовы, сделанные программой пространства пользователя. Она не только показывает вызовы, но может также показать аргументы вызовов и возвращаемые значения в символической форме. Когда системный вызов заканчивается неудачно, отображается символическое значение ошибки (например, ENOMEM) и соответствующая строка (Out of memory, не хватает памяти). strace имеет много параметров командной строки; наиболее полезной из которых являются -t для отображения времени, когда был выполнен каждый вызов, -T для отображения времени, проведённого в вызове, -е для  ограничения типов трассируемых вызовов, и -o, чтобы перенаправить вывод в файл. По умолчанию strace печатает информацию трассировки в stderr.

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

Информация трассировки часто используется для подтверждения сообщений об ошибках, посылаемых разработчикам приложений, но это также бесценна для программистов ядра. Мы видели, как выполняется код драйвера, реагируя на системные вызовы; strace позволяет проверить соответствие входных и выходных данных каждого вызова.

Например, следующий снимок экрана показывает последние строки (большинство из них) работы команды strace ls /dev > /dev/scull0:

open("/dev", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3

fstat64(3, {st_mode=S_IFDIR|0755, st_size=24576, ...}) = 0

fcntl64(3, F_SETFD, FD_CLOEXEC) = 0

getdents64(3, /* 141 запись */, 4096) = 4088

[...]

getdents64(3, /* 0 записей */, 4096) = 0

close(3) = 0

[...]

fstat64(1, {st_mode=S_IFCHR|0664, st_rdev=makedev(254, 0), ...}) = 0

write(1, "MAKEDEV\nadmmidi0\nadmmidi1\nadmmid"..., 4096) = 4000

write(1, "b\nptywc\nptywd\nptywe\nptywf\nptyx0\n"..., 96) = 96

write(1, "b\nptyxc\nptyxd\nptyxe\nptyxf\nptyy0\n"..., 4096) = 3904

write(1, "s17\nvcs18\nvcs19\nvcs2\nvcs20\nvcs21"..., 192) = 192

write(1, "\nvcs47\nvcs48\nvcs49\nvcs5\nvcs50\nvc"..., 673) = 673

close(1) = 0

exit_group(0) = ?

Как явствует из первого вызова write, после того, как ls закончила просмотр целевого каталога, она попыталась записать 4 Кб. Странно (для ls), только 4000 байт были записаны, и операция была повторена. Однако, мы знаем, что реализация write в scull пишет один квант за раз, так что мы могли бы ожидать частичную запись. Через несколько шагов все данные проталкиваются и программа успешно завершается. В качестве другого примера давайте почитаем устройство scull (с помощью команды wc):

[...]

open("/dev/scull0", O_RDONLY|O_LARGEFILE) = 3

fstat64(3, {st_mode=S_IFCHR|0664, st_rdev=makedev(254, 0), ...}) = 0

read(3, "MAKEDEV\nadmmidi0\nadmmidi1\nadmmid"..., 16384) = 4000

read(3, "b\nptywc\nptywd\nptywe\nptywf\nptyx0\n"..., 16384) = 4000

read(3, "s17\nvcs18\nvcs19\nvcs2\nvcs20\nvcs21"..., 16384) = 865

read(3, "", 16384) = 0

fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), ...}) = 0

write(1, "8865 /dev/scull0\n", 17) = 17

close(3) = 0

exit_group(0) = ?

Как и ожидалось, read может получить только 4000 байт за раз, но общий объём данных тот же, что был записан в предыдущем примере. Интересно отметить, как, в отличие от предыдущей трассировки, организованы повторы в данном примере. wc оптимизирован для быстрого чтения и, таким образом, обходит стандартные библиотеки, пытаясь прочитать больше данных одним системным вызовом. Вы можете видеть из строк чтения в трассировке, как wc пытался прочитать 16 Кб за раз.

Специалисты по Linux могут найти много полезной информации в выводе strace. Если вы убрали все символы, вы можете ограничить себя просмотром, как работают файловые методы (open, read и другие) с помощью флага efile.

Лично мы находим strace наиболее полезной для выявления ошибок в системных вызовах. Часто вызов perror в приложении или демо-программе не достаточно подробен, чтобы быть полезным для отладки, и возможность точно сказать, какие аргументы в каком системном вызове вызвали ошибку может быть большой помощью.