Когда приложение или драйвер ведёт себя странно, а strace показывает только оболочку, приходит время заглянуть глубже - прямо в код ядра. Здесь на помощь приходит ftrace: механизм трассировки в системе, который включает приборы прямо на уровнях подпрограмм и события. Для исследования медленных операций он просто незаменим. В статье разбираем практические шаги: включение ftrace, фильтрация нужных функций, запись событий и анализ результатов без сложностей и лишнего кода.
Ориентация в /sys/kernel/debug/tracing
File-system debugfs примонтирован по умолчанию в современных дистрибутивах в /sys/kernel/debug, и вся кухня ftrace развёрнута в подкаталоге tracing. Первый позыв к нему - это просто осмотр: ls tracing показывает список файлов, управляющих параметрами; current_tracer указывает текущий режим tracing, а trace - накопленные замеры. Система собрана так, чтобы любая команда чтения или записи к этим файлам была элементарной, она не требует компиляции или перезагрузки.
Чтобы начать что-то следить, выполните echo function > current_tracer, а затем echo 1 > tracing_on, и поток событий начнёт стекаться в текстовом журнале. Остановка происходит зеркальной командой echo 0 > tracing_on, а задач наличия контролируются через set_ftrace_filter. Всё это хранится очевидно и не требует особых приготовлений, кроме привычки к текстовым экспериментам.
Фильтрация и прицел на медленные пути
Если вас интересуют не все функции, а конкретные straggler, используйте set_ftrace_filter: туда пишется список имён, и выборка сразу ограничится только интересными функциями. Например echo __do_page_fault > set_ftrace_filter - и tracing будет отслеживать именно эту операцию. Режим события function_graph даёт графики вызовов с длительностью, которые особенно хорошо читаются, когда вам нужно ответить на вопрос "что именно занимает время внутри этого вызова".
Для более опытных пользователей в коллекцию включены tracepoints: они доступны через tracing/events и предлагают готовые события, такие как sched_switch, sys_enter_connect, block_io и другие. Активация точки делается простой записью 1 в enable соответствующего каталога, и вы получаете подробный и структурированный поток ситуаций, которые можно уже анализировать.
Анализ замеров и практические выводы
После того как вы накопили достаточно записей, трассировочный лог станет кладом ответов. Строки журнала показывают время, имя процесса, функцию и опционально полезную нагрузку; привычка отличает шум от мяса быстро - опытные люди узнают за пару заглядываний, что процесс занимается ожиданием диска, конкурирует за полки или исполняет длинные пользовательские циклы. Фильтрация с минимальным шумом это весь фокус, и он даётся быстро, если не запускать всё подряд без фильтра.
Ключевое умение здесь - корреляция: связывайте записи ftrace с времянкой вашей задачи и дисковыми операциями потока. Так вы узнаете, какая именно операция тормозит общий темп, а это знание - настоящая скала, на которую вы можете опереться.
## function_graph, длительность каждого вызова
Режим function_graph отличается от обычной трассировки функций тем, что показывает не только порядок вызовов, но и время каждого из них: в журнале появляются вертикальные линии, а под каждой функцией - микросекунды, потраченные внутри. Включение: echo function_graph > current_tracer, затем после сбора данных echo 0 > tracing_on. Чтение журнала наглядно: длинная полоса duration над кадром сразу указывает, какая именно вложенная функция съела время, и глазу не нужно сравнивать метки - система сама отрисовала профиль.
Для больших потоков полезно ограничить глубину через echo 5 > max_graph_depth, иначе журнал превращается в бесконечную лестницу из служебных вызовов. Сочетание фильтра по функциям и ограничения глубины делает вывод читаемым: в нём остаётся только интересующая ветка вызовов с точными цифрами, и это идеальный формат для ответа на вопрос "куда делись мои 40 миллисекунд".
Точки-события и практические сценарии
Помимо трассировки функций, ftrace владеет библиотекой статических точек-событий: каталог events делён на группы sched (планировщик), block (блочный ввод-вывод), net, kvm, syscalls и другие. Активация одной строки echo 1 > events/sched/sched_wakeup/enable включает поток событий о пробуждении задач, и по нему видно, кто будит кого и с какой задержкой. Для диагностики лагов это чистое золото: связка sched_wakeup и sched_switch в одном журнале объясняет, почему задача ожидала запуска дольше, чем работала.
Практический сценарий первый - медленная запись в файл: включаются block_rq_issue и block_rq_complete, и по парам событий считается латентность каждого запроса к диску. Сценарий второй - странная пауза в работе приложения: включается sched_switch для этого процесса, и видно, сколько раз его вытесняли и насколько. Сценарий третий - сетевые ретрансмиссии: точки в группе net показывают моменты сброса соединений. Во всех случаях одна и та же механика - выбрать точку, включить, воспроизвести проблему, выключить, прочитать.
Фильтры, трассировка только нужного процесса
Без фильтра журнал быстро становится нечитаемым, поэтому фильтрация - не украшение, а обязательная часть метода. По процессам: echo <PID> > set_event_pid ограничивает события только выбранным процессом, и весь шум остальной системы исчезает. По функциям для режима function: set_ftrace_filter перечисляет имена функций, по которым надо ходить, а set_ftrace_notrace, наоборот, исключает лишнее. Для событий работает знакомый по языкам запросов синтаксис: echo "comm == "nginx"" > events/sched/sched_switch/filter показывает переключения только для nginx.
Фильтры комбинируются: сначала сужаем по процессу, потом по типу события, и после этого даже минута записи на загруженном сервере остаётся обозримой. Привычка настраивать фильтры до включения tracing_on экономит и место, и время разбора.
Пример, поиск источника задержки записи
Соберём типовой разбор. Приложение периодически пишет отчёт на диск, и иногда операция вместо десятков миллисекунд занимает секунды. План: echo 1 > events/block/block_rq_issue/enable, echo 1 > events/block/block_rq_complete/enable, echo <PID> > set_event_pid, затем echo 1 > tracing_on и воспроизведение. Анализ журнала: grep по парам issue/complete с одинаковыми секторами, разница временных меток - латентность каждого запроса. Типичные находки: латентность растёт пачками ровно в моменты работы системы резервного копирования, либо медленные запросы имеют размер больше обычного и упираются в flush очереди.
Именно так выглядит смысл ftrace на практике: не абстрактное "что-то трассируется", а конкретные пары событий, из которых собирается ответ на конкретный производственный вопрос.
tracing_marker и корреляция с приложением
Иногда нужно связать события ядра с моментами внутри самого приложения: когда код проходит контрольную точку, write(fd, ...) в файл tracing_marker оставляет в журнале метку, которая синхронизируется с остальными событиями с точностью до микросекунд. Разработчики используют это, чтобы отметить границы транзакции, а затем в трассе найти, что происходило в ядре между двумя метками. Такая корреляция превращает журналы приложения и журналы ядра из разрозненных текстов в единую временную шкалу.
Накладные расходы и разумные пределы
Честность требует упомянуть цену: трассировка всех функций на всех процессах заметно замедляет систему, поэтому production-использование всегда идёт с фильтрами и на коротких интервалах. Точечные события дешевле, но и их поток на загруженном сервере создаёт миллионы строк. Практические правила: включать запись непосредственно перед воспроизведением проблемы и выключать сразу после; ограничивать размер буфера через buffer_size_kb; использовать snapshot-режим, когда журнал пишется циклически и фиксируется только в момент сбоя через echo 1 > snapshot.
При соблюдении этих правил ftrace безопасен даже на проде: за годы существования механизма он не раз переносил и тяжёлые нагрузки, и долгие сессии отладки без единого влияния на посторонние процессы.
Соседние обёртки, trace-cmd и perf-tools
Поверх ftrace существует слой удобных утилит: trace-cmd записывает и читает трассы в стиле tcpdump, с опцией -e для выбора событий и красивым выводом; KernelShark даёт графический просмотр записанных файлов. Набор perf-tools от Брендана Грегга - набор коротких скриптов (funclatency, bitesize) - закрывает типовые вопросы одной командой, скрывая работу с каталогами. Знание низкоуровневой механики остаётся ценным: когда готового скрипта нет, вы спускаетесь на уровень ниже и собираете ответ вручную за несколько минут.
Итоговая памятка
Короткий свод методики: mount debugfs, выбрать режим (function, function_graph или events), настроить фильтры по процессу и функции, включить tracing_on, воспроизвести проблему, выключить, прочитать trace, сформулировать вывод и приложить его к тикету. Каждый шаг проверен практикой, не требует установки и работает на любом современном ядре. Овладев этим циклом, вы получаете возможность спрашивать у ядра напрямую о том, что оно делало в любой момент, и получать точный, датированный ответ - а это и есть высшая форма диагностики.
kprobes, точки на любую функцию
Если нужного статического события не существует, ftrace через kprobes ставит точку прямо на вход любой функции ядра. Механика проста: echo "p:myprobe vfs_read file=$arg1 count=$arg2" > kprobe_events создаёт динамическое событие, а его поле появляются в журнале как обычные данные. На выходе - то же удобство фильтров и читаемые аргументы, что и у штатных точек, но с полем охвата: под трассировку попадает любой символ, видимый в /proc/kallsyms. Для ретросомопасных ядер старых версий это часто единственный способ заглянуть в интересную подсистему без переустановки всего.
Отладочные символы для базовых аргументов не обязательны: синтаксис $arg1 и $arg2 читает регистры по соглашениям архитектуры, а для полей структур доступна запись вида +OFFSET(<type>). Один раз составленный формат точки сохраняется в runbook и переиспользуется на всех однотипных машинах.
Место ftrace в общей культуре диагностики
В арсенале системного инженера ftrace занимает нишу точечного, surgical-а инструмента: perf отвечает на вопрос "где уходит процессор", strace - "какие вызовы делает процесс", а ftrace - "что происходило в ядре в конкретный момент". Умение быстро спускаться на этот уровень отличает специалиста, который ставит диагноз, от специалиста, который перезагружает сервер в надежде на везение. Порог входа здесь невысок - каталоги, echo и grep, - а отдача измеряется сэкономленными ночами. Именно по этим причинам ftrace держится в списке базовых навыков любого серьёзного Linux-инженера уже полтора десятилетия.
Сравнение с соседями по цеху
Для полноты картины стоит провести границы между инструментами одной семьи. strace показывает вызовы одного процесса на уровне интерфейса ядро-пользователь и слеп к остальной системе. perf снимает статистические профили и отвечает на вопрос о распределении процессорного времени. ftrace же повествует о событиях ядра в их хронологической последовательности, и именно последовательность делает его незаменимой: она отвечает на вопрос не "сколько", а "в каком порядке и с какой задержкой". В руках инженера, который знает эту разницу, каждая из утилит применяется по назначению, и ни одна не пытается заменить остальные.
Остаётся только повторить главное: ftrace всегда под рукой на любом современном ядре, и порог входа в него ниже, чем у любого соседнего инструмента его класса.
Пользуйтесь с удовольствием.
Готово.
Удачи в глубинах ядра Linux.