- strace
- Some of the features
- Attach to an already running process.
- Print paths and more info associated with file descriptors.
- Filter by type of syscall.
- Trace only system calls accessing given path.
- Perform a full hexadecimal and ASCII dump of all the data read from/written to file descriptors.
- Perform a syscall fault injection.
- Count time, calls, and errors for each system call.
- strace
- Some of the features
- Attach to an already running process.
- Print paths and more info associated with file descriptors.
- Filter by type of syscall.
- Trace only system calls accessing given path.
- Perform a full hexadecimal and ASCII dump of all the data read from/written to file descriptors.
- Perform a syscall fault injection.
- Count time, calls, and errors for each system call.
- Strace
- Разбираемся с системными вызовами в Linux с помощью strace
- Заключение
strace
linux syscall tracer
- Official repositories are at GitHub and GitLab.
- You can get latest binary packages from Fedora rawhide, OBS, Sisyphus.
- The latest officially signed release tarball can be found here.
- Development takes place on the mailing list (archive). Everyone is welcome to send bug reports, feature requests, comments and patches there.
- IRC channel: #strace@oftc.
- strace is released under the GNU Lesser General Public License license version 2.1 or later. strace mascot is CC BY-SA 4.0, by Vitaly Chaykovsky.
strace is a diagnostic, debugging and instructional userspace utility for Linux. It is used to monitor and tamper with interactions between processes and the Linux kernel, which include system calls, signal deliveries, and changes of process state.
System administrators, diagnosticians and trouble-shooters will find it invaluable for solving problems with programs for which the source is not readily available since they do not need to be recompiled in order to trace them.
The operation of strace is made possible by the kernel feature known as ptrace.
Some of the features
Attach to an already running process.
Print paths and more info associated with file descriptors.
Filter by type of syscall.
Trace only system calls accessing given path.
Perform a full hexadecimal and ASCII dump of all the data read from/written to file descriptors.
Perform a syscall fault injection.
Count time, calls, and errors for each system call.
Based on a Github Pages theme — minimal
Источник
strace
linux syscall tracer
- Official repositories are at GitHub and GitLab.
- You can get latest binary packages from Fedora rawhide, OBS, Sisyphus.
- The latest officially signed release tarball can be found here.
- Development takes place on the mailing list (archive). Everyone is welcome to send bug reports, feature requests, comments and patches there.
- IRC channel: #strace@oftc.
- strace is released under the GNU Lesser General Public License license version 2.1 or later. strace mascot is CC BY-SA 4.0, by Vitaly Chaykovsky.
strace is a diagnostic, debugging and instructional userspace utility for Linux. It is used to monitor and tamper with interactions between processes and the Linux kernel, which include system calls, signal deliveries, and changes of process state.
System administrators, diagnosticians and trouble-shooters will find it invaluable for solving problems with programs for which the source is not readily available since they do not need to be recompiled in order to trace them.
The operation of strace is made possible by the kernel feature known as ptrace.
Some of the features
Attach to an already running process.
Print paths and more info associated with file descriptors.
Filter by type of syscall.
Trace only system calls accessing given path.
Perform a full hexadecimal and ASCII dump of all the data read from/written to file descriptors.
Perform a syscall fault injection.
Count time, calls, and errors for each system call.
Based on a Github Pages theme — minimal
Источник
Strace
В течение минуты думал над заголовком, так ничего и не придумал…
Strace. Наверное нет того человека, который бы не слышал про strace. Если кто не слышал, то strace — это утилита, отслеживающая системные вызовы, которые представляют собой механизм трансляции, обеспечивающий интерфейс между процессом и операционной системой (ядром). Эти вызовы могут быть перехвачены и прочитаны. Это позволяет лучше понять, что процесс пытается сделать в заданное время. Перехватывая эти вызовы, мы можем добиться лучшего понимания поведения процессов, особенно если что-то идет не так. Функциональность операционной системы, позволяющая отслеживать системные вызовы, называется ptrace. Strace вызывает ptrace и читает данные о поведении процесса, возвращая отчет. Детали можно прочитать в вики или официальном man. Собственно вот, ну и речь конечно же о Linux. В других ОС свои аналоги.
Так вот, лично для меня strace это как последняя инстанция. Когда уже все логи просмотрены, все debug и verbose ключи включены, а причина проблем так и не обнаружена, я достаю из широких штанин запускаю strace. Есть одно но, strace это такой инструмент который вовсе не является серебряной пулей, которая тут же все покажет и расскажет. Для работы с strace требуется наличие определенных знаний и чем шире и глубже эти знания тем больше вероятность обнаружения проблемы.
В интернетах полно вводных статей, где описываются примеры запуска strace. Я же в этой статье покажу частные проблемы и их решение с помощью strace.
Первый случай. Не запускается виртуальная машина KVM с включенной настройкой vhost=on для сетевых интерфейсов. Если опустить этот параметр, виртуальная машина успешно запускается.
Итак для начала я отсек все лишние параметры и оставил только обязательные опции и параметры создания сетевого интерфейса. Это нужно чтобы не увеличивать и без того объемный вывод strace:
# qemu-system-x86_64 -m 4096 -netdev tap,ifname=tap90,id=tap90,vhost=on -device virtio-net-pci,netdev=tap90,mac=08:77:D1:00:90:90
qemu-system-x86_64: -netdev tap,ifname=tap90,id=tap90,vhost=on: vhost-net requested but could not be initialized
qemu-system-x86_64: -netdev tap,ifname=tap90,id=tap90,vhost=on: Device ‘tap’ could not be initialized
Итак запускаем виртуальную машину с strace и анализируем вывод. Я намерено опускаю большую часть вывода и показываю только ту часть по которой можно определить причину проблемы.
Как видно ошибка возникает в вызове open() при попытке открытия устройства /dev/vhost-net. После чего, печатаются сообщения об ошибках которые наблюдались при простом запуске виртуальной машины.
В качестве workaround пришлось сбросить page cache и buffers через выполнение echo 3 > /proc/sys/vm/drop_caches, после чего виртуальная машина успешно запустилась. Потом часть машин перенесли на другие хосты, но это уже другая история.
Второй случай. И снова виртуальная машина и забегая вперед скажу что здесь снова вопрос памяти. Опытным путем стало понятно что виртуальная машина не запускается с большим значением выделяемой памяти. В данном случае -m 10240. Если указывать меньшие значения, то машина запускается. При этом свободной памяти на сервере больше 10GB. И снова расчехляем strace. В примере ниже я опускаю весь список параметров запуска виртуальной машины и часть ненужного вывода strace.
И снова уже известный Cannot allocate memory, но уже в mprotect(). Ищем и находим что ограничивает нас sysctl ключ vm.overcommit_memory со значением 2. Меняем на 0 и машина успешно запускается.
Третий случай. Здесь есть некоторый процесс который работает какое-то время, затем неожиданно начинает расходовать ресурсы CPU. Load average поднимается с 0.5 до 1,5 (в системе, а это виртуальная машина всего 2 виртуальных процессора). Latency увеличивается, отзывчивость сервиса падает. При перезапуске процесса, через какое-то время ситуация повторяется. Время прошедшее с момента запуска и перед сбоем всегда разное. Итак, подключаем strace к процессу в момент когда процесс начинает вести себя неправильно. И тут же видим много сообщений типа:
Системный вызов accept() завершается с ошибкой «EMFILE (Too many open files)». Смотрим лимиты процесса в /proc/pid/limits и проверяем количество открытых файлов с помощью lsof.
Лимит открытых файлов 1024, и текущее количество открытых процессом файлов, чуть превышает значение лимита. Тут все ясно, сначала с помощью prlimit увеличиваем значение лимита у запущенного процесса, а затем закрепляем лимиты на совсем через правку /etc/security/limits.conf.
Четвертый случай. Здесь следует сделать небольшое отступление. Здесь мы рассматриваем связку pgBouncer — PostgreSQL. Приложение работает с базой данных через pgBouncer, т.е. подключается к нему, pgBouncer выдает коннект к базе из пула, приложение делает свои дела, отключается, а коннект возвращается в пул и находится до тех пор пока не будет выдано следующему клиенту.
Итак проблема, в логе приложения и в логе postgres’а начали появляться сообщения о том что транзакции в базе данных не могут выполнить обновление/удаление/вставку данных, т.к. транзакция находится в READ ONLY режиме.
В процессе поиска, была выдвинуто несколько гипотез, одна из них впоследствии оказалась правильной. Клиент, подключаясь к пулеру устанавливает сессию в READ ONLY режим. После отключения клиента, эта настройка прилипает к серверному коннекту и живет с ним пока pgBouncer принудительно не завершит этот коннект. Если указать server_reset_query = DISCARD ALL в настройках pgBouncer, то при отключении все session-based настройки будут сброшены. Таким образом кто-то выставлял READ ONLY сессию, она сохранялась и затем этот коннект доставался другим клиентам. Вобщем DISCARD ALL было временным решением, пока искали виновника. Поиски были продолжительными и подозрения легли на приложение, однако разработчики уверяли что проверили все места в коде и не выявили проблемных мест…
Достаем strace, подключаемся в pgBouncer и ждем.
Ловим по ключевому слову READ ONLY. А вывод сохраняем в отдельный лог. Так как после обнаружения придется еще покопаться в нем.
Итак прошло какое-то время и вот оно:
Ждем еще некоторое время (ловим другие запросы этого же клиента), выключаем strace и открываем наш лог.
Здесь самое важное номера дескрипторов, в частности дескриптор с номером 10 (обратите внимание на recvfrom(10). Нужно найти кто открыл эти дескрипторы которое предшествовали пойманному сообщению, немного grep и вот оно. Системный вызов accept() ( accept(. ) = 10) открывает тот самый дескриптор с номером 10.
В беседе с разработчиками выяснилось что адрес 192.168.10.1 принадлежит VPN-серверу, через который подключались разработчики. После проведения воспитательных бесед и принятия организационных мер проблема больше не проявлялась.
Источник
Разбираемся с системными вызовами в Linux с помощью strace
Перевод статьи подготовлен специально для студентов базового и продвинутого курсов Administrator Linux.
Системный вызов — это механизм взаимодействия пользовательских программ с ядром Linux, а strace — мощный инструмент, для их отслеживания. Для лучшего понимания работы операционной системы полезно разобраться с тем, как они работают.
В операционной системе можно выделить два режима работы:
- Режим ядра (kernel mode) — привилегированный режим, используемый ядром операционной системы.
- Пользовательский режим (user mode) — режим, в котором выполняется большинство пользовательских приложений.
Пользователи при повседневной работе обычно используют утилиты командной строки и графический интерфейс (GUI). При этом в фоне незаметно работают системные вызовы, обращаясь к ядру для выполнения работы.
Системные вызовы очень похожи на вызовы функций, в том смысле, что в них передаются аргументы и они возвращают значения. Единственное отличие состоит в том, что системные вызовы работают на уровне ядра, а функции нет. Переключение из пользовательского режима в режим ядра осуществляется с помощью специального механизма прерываний.
Большая часть этих деталей скрыта от пользователя в системных библиотеках (glibc в Linux-системах). Системные вызовы по своей природе являются универсальными, но несмотря на это, механика их выполнения во многом аппаратно-зависима.
В этой статье рассматривается несколько практических примеров анализа системных вызовов с помощью strace . В примерах используется Red Hat Enterprise Linux, но все команды должны работать и в других дистрибутивах Linux:
Для начала убедитесь, что в вашей системе установлены необходимые инструменты. Проверить установлен ли strace можно с помощью приведенной ниже команды. Для просмотра версии strace запустите ее с параметром -V:
Если strace не установлен, то установите запустив:
Для примера создайте тестовый каталог в /tmp и два файла с помощью команды touch :
(Я использую каталог /tmp только потому, что доступ к нему есть у всех, но вы можете использовать любой другой.)
С помощью команды ls проверьте, что в каталоге testdir создались файлы:
Вероятно, вы используете команду ls каждый день, не осознавая того, что под капотом работают системные вызовы. Здесь в игру вступает абстракция. Вот как работает эта команда:
Команда ls вызывает функции из системных библиотек Linux (glibc). Эти библиотеки, в свою очередь, вызывают системные вызовы, которые выполняют большую часть работы.
Если вы хотите узнать, какие функции вызывались из библиотеки glibc, то используйте команду ltrace со следующей за ней командой ls testdir/ :
Если ltrace не установлен, то установите:
На экране будет много информации, но не беспокойтесь — мы это рассмотрим далее. Вот некоторые из важных библиотечных функций из вывода ltrace :
Изучив этот вывод, вы, вероятно, поймете, что происходит. Каталог с именем testdir открывается с помощью библиотечной функции opendir , после чего следуют вызовы функций readdir , читающих содержимое каталога. В конце происходит вызов функции closedir , которая закрывает каталог, открытый ранее. Пока проигнорируйте остальные функции, такие как strlen и memcpy .
Как вы видите, можно легко посмотреть вызываемые библиотечные функции, но в этой статье мы сфокусируемся на системных вызовах, которые вызываются функциями системных библиотек.
Для просмотра системных вызовов используйте strace с командой ls testdir , как показано ниже. И вы снова получите кучу бессвязной информации:
В результате выполнения strace вы получите список системных вызовов, выполненных при работе команды ls . Все системные вызовы можно разделить на следующие категории:
- Управление процессами
- Управление файлами
- Управление каталогами и файловой системой
- Прочие
Есть удобный способ анализа полученной информации — записать вывод в файл с помощью опции -o .
На этот раз на экране не будет никаких данных — команда ls отработает, как и ожидается, показав список файлов и записав весь вывод strace в файл trace.log . Для простой команды ls файл содержит почти 100 строк:
Взгляните на первую строку в файле trace.log :
- В начале строки находится имя выполняемого системного вызова — это execve.
- Текст в круглых скобках — это аргументы, передаваемые системному вызову.
- Число после знака = (в данном случае 0) — это значение, возвращаемое системным вызовом.
Теперь результат не кажется слишком пугающим, не так ли? И вы можете применить ту же логику и для других строк.
Обратите внимание на ту единственную команду, которую вы вызвали — ls testdir . Вам известно имя каталога, используемое командой ls , так почему бы не воспользоваться grep для testdir в файле trace.log и не посмотреть, что найдется? Посмотрите внимательно на результат:
Возвращаясь к приведенному выше анализу execve , можете ли вы сказать, что делает следующий системный вызов?
Не нужно запоминать все системные вызовы и то, что они делают: все есть в документации. Man-страницы спешат на помощь! Перед запуском команды man убедитесь, что установлен пакет man-pages :
Помните, что вам нужно добавить «2» между командой man и именем системного вызова. Если вы прочитаете в man про man ( man man ), то увидите, что раздел 2 зарезервирован для системных вызовов. Аналогично если вам нужна информация о библиотечных функциях, то нужно добавить 3 между man и именем библиотечной функции.
Ниже приведены номера разделов man :
Для просмотра документации по системному вызову запустите man с именем этого системного вызова.
В соответствии с документацией системный вызов execve выполняет программу, которая передается ему в параметрах (в данном случае это ls ). В него также передаются дополнительные параметры для ls. В этом примере это testdir . Следовательно, этот системный вызов просто запускает ls с testdir в качестве параметра:
В следующий системный вызов stat передается параметр testdir :
Для просмотра документации используйте man 2 stat . Системный вызов stat возвращает информацию об указанном файле. Помните, что все в Linux — файл, включая каталоги.
Далее системный вызов openat открывает testdir . Обратите внимание, что возвращается значение 3. Это дескриптор файла, который будет использоваться в последующих системных вызовах:
Теперь откройте файл и обратите внимание на строку, следующую после системного вызова openat . Вы увидите системный вызов getdents , который делает большую часть необходимой работы для выполнения команды ls testdir . Теперь выполним grep getdents для файла trace.log :
В документации ( man getdents ) говорится, что getdents читает записи каталога, это, собственно, нам и нужно. Обратите внимание, что аргумент для getdent равен 3 — это дескриптор файла, полученный ранее от системного вызова openat .
Теперь, когда получено содержимое каталога, нужен способ отобразить информацию в терминале. Итак, делаем grep для другого системного вызова write , который используется для вывода на терминал:
В аргументах вы можете видеть имена файлов, которые будут выводится: file1 и file2 . Что касается первого аргумента (1), вспомните, что в Linux для любого процесса по умолчанию открываются три файловых дескриптора:
- 0 — стандартный поток ввода
- 1 — стандартный поток вывода
- 2 — стандартный поток ошибок
Таким образом, системный вызов write выводит file1 и file2 на стандартный вывод, которым является терминал, обозначаемый числом 1.
Теперь вы знаете, какие системные вызовы сделали большую часть работы для команды ls testdir/ . Но что насчет других 100+ системных вызовов в файле trace.log ?
Операционная система выполняет много вспомогательных действий для запуска процесса, поэтому многое из того, что вы видите в файле trace.log — это инициализация и очистка процесса. Посмотрите файл trace.log полностью и попытайтесь понять, что происходит во время запуска команды ls .
Теперь вы можете анализировать системные вызовы для любых программ. Утилита strace так же предоставляет множество полезных параметров командной строки, некоторые из которых описаны ниже.
По умолчанию strace отображает не всю информацию о системных вызовах. Однако у нее есть опция -v verbose , которая покажет дополнительную информацию о каждом системном вызове:
Хорошая практика использовать параметр -f для отслеживания дочерних процессов, созданных запущенным процессом:
А если вам нужны только имена системных вызовов, количество их запусков и процент времени, затраченного на выполнение? Вы можете использовать опцию -c , чтобы получить эту статистику:
Если вы хотите отследить определенный системный вызов, например, open , и проигнорировать другие, то можно использовать опцию -e с именем системного вызова:
А что, если нужно отфильтровать по нескольким системным вызовам? Не волнуйтесь, можно использовать ту же опцию -e и разделить необходимые системные вызовы запятой. Например, для write и getdent :
До сих пор мы отслеживали только явный запуск команд. Но как насчет команд, которые были запущены ранее? Что, если вы хотите отслеживать демонов? Для этого у strace есть специальная опция -p , которой вы можете передать идентификатор процесса.
Мы не будем запускать демона, а используем команду cat , которая отображает содержимое файла, переданного ему в качестве аргумента. Но если аргумент не указать, то команда cat будет просто ждать ввод от пользователя. После ввода текста она выведет введенный текст на экран. И так до тех пор, пока пользователь не нажмет Ctrl+C для выхода.
Запустите команду cat на одном терминале.
На другом терминале найдите идентификатор процесса (PID) с помощью команды ps :
Теперь запустите strace с опцией -p и PID’ом, который вы нашли с помощью ps . После запуска strace выведет информацию о процессе, к которому он подключился, а также его PID. Теперь strace отслеживает системные вызовы, выполняемые командой cat . Первый системный вызов, который вы увидите — это read, ожидающий ввода от потока с номером 0, то есть от стандартного ввода, который сейчас является терминалом, на котором запущена команда cat :
Теперь вернитесь к терминалу, где вы оставили запущенную команду cat , и введите какой-нибудь текст. Для демонстрации я ввел x0x0 . Обратите внимание, что cat просто повторил то, что я ввел и x0x0 на экране будет дважды.
Вернитесь к терминалу, где strace был подключен к процессу cat . Теперь вы видите два новых системных вызова: предыдущий read , который теперь прочитал x0x0 , и еще один для записи write , который записывает x0x0 обратно в терминал, и снова новый read , который ожидает чтения с терминала. Обратите внимание, что стандартный ввод (0) и стандартный вывод (1) находятся на одном и том же терминале:
Представляете, какую пользу может принести вам запуск strace для демонов: вы можете увидеть все, что делается в фоне. Завершите команду , нажав . Это также прекратит сеанс , так как отслеживаемый процесс был прекращен.
Для просмотра отметок времени системных вызовов используйте опцию -t :
А если вы хотите узнать время, проведенное между системными вызовами? Есть удобная опция -r , которая показывает время, затраченное на выполнение каждого системного вызова. Довольно полезно, не так ли?
Заключение
Утилита strace очень удобна для изучения системных вызовов в Linux. Чтобы узнать о других параметрах командной строки, обратитесь к man и онлайн-документации.
Источник