Вглубь ядра: знакомство с LTTng

в 8:01, , рубрики: LTTng, selectel, Блог компании Селектел, селектел, системное администрирование, трассировка ядра, ядро Linux

LTTng

В одной из предыдущих публикаций мы уже затронули проблематику трассировки и профилирования ядра Linux.

Сегодня мы хотели бы вновь вернуться к этой проблематике и подробно поговорить об одном интересном инструменте — трассировщике ядра LTTng, разработанном канадским программистом и исследователем Матьё Денуайе. С его помощью можно получать информацию о событиях как в пространстве ядра, так и в пользовательском пространстве.

LTTng может быть использован, например, для решения следующих задач (список далеко не полный):

  • анализ межпроцессного взаимодействия в системе;
  • анализ взаимодействия приложений в пользовательском пространстве с ядром;
  • измерение времени, затрачиваемого ядром на обслуживание запросов приложений;
  • анализ особенностей работы системы под высокими нагрузками.

LTTng уже давно включён в официальные репозитории современных дистрибутивов Linux. Его используют на практике такие компании, как Google, Siemens, Boeing и другие. На русском языке публикаций о нём практически нет.
В этой статье мы рассмотрим принципы работы LTTng и покажем, как осуществляется трассировка ядра с его помощью.

Немного истории

В прошлой статье мы подробно разобрали механизм точек трассировки (tracepoints) и даже привели примеры кода. Но мы ничего не сказали о том, что механизм tracepoints был создан в процессе работы над LTTng.

Ещё в 1999 году сотрудник компании IBM Карим Ягмур (Karim Yaghmour) начал работу над проектом LTT (Linux Trace Toolkit). В основе LTT лежала следующая идея: чтобы статически инструментировать наиболее важные фрагменты в коде ядра и благодаря этому получать информацию о работе системы. Несколько лет спустя эта идея была подхвачена и развита Матьё Денуайе в рамках проекта LTTng (Linux Tracing Tool New Generation). Первый релиз LTTng состоялся в 2005 году.

Слова New Generation используются в названии инструмента не просто так: Денуайе внёс огромный вклад в развитие механизмов трассировки и профилирования Linux. Он добавил статическое инструментирование для важнейших ядерных функций: так получился механизм kernel markers, в результате усовершенствования которого появился хорошо знакомый нам tracepoints. Tracepoints активно используется в LTTng. Именно благодаря этому механизму стало возможным осуществлять трассировку, не создавая дополнительной нагрузки на работу системы.
На материале проделанной работы Денуайе подготовил диссертацию, которая была защищена в 2009 году.

Матьё Денуайе ведёт постоянную работу по усовершенствованию LTTng. Последняя на сегодняшний день стабильная версия 2.7 вышла в свет в октябре 2015 года. Вот-вот должна выйти версия 2.8, которая на текущий момент находится в статусе релиз-кандидата и доступна для скачивания здесь.

Установка

LTTng включен в репозитории большинства современных дистрибутивов Linux, и установить её можно стандартным способом. В новых версиях популярных дистрибутивов (например, в недавно вышедшей Ubuntu 16.04) для установки по умолчанию доступна свежая версия  — 2.7:

$ sudo apt-get install lttng-tools lttng-modules-dkms

Если вы используете более старую версию Linux, для установки LTTng 2.7 понадобится добавить PPA-репозиторий:

$ sudo apt-add-repository ppa:lttng/ppa
$ sudo apt-get update
$ sudo apt-get install lttng-tools lttng-modules-dkms 

Пакет lttng-tools содержит следующие утилиты:

  • babeltrace — утилита для просмотра выводов трассировки в формате CTF (Common Trace Format);
  • lttng-sessiond — демон для управления трассировкой;
  • lttng-consumerd — демон, собирающий данные и записывающий их в кольцевой буфер;
  • lttng-relayd — демон, передающий данные по сети.

В пакет lttng-modules-dkms входят многочисленные модули ядра, с помощью которых осуществляется взаимодействие со встроенными механизмами трассировки и профилирования… Просмотреть их полный список можно с помощью команды

$ lsmod | grep lttng

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

  • модули для работы с точками трассировки (tracepoints);
  • модули для работы с кольцевым буфером;
  • модули-пробы, предназначенные для динамической трассировки ядра.

Из официальных репозиториев для установки доступен также пакет LTTng-UST, с помощью которого осуществляется трассировка событий в пользовательском пространстве. В рамках этой статьи мы его рассматривать не будем. Заинтересованных читателей отсылаем к&nbsp статье, которая может служить вполне неплохим введением в тему.
Все команды LTTng должны выполняться либо от имени root-пользователя, либо от имени пользователя, включённого в специальную группу tracing (она создаётся автоматически при установке).

Основные понятия: сессии, события и каналы

Процесс взаимодействия всех компонентов LTTng можно представить в виде следующей схемы:

LTTng

Чтобы лучше понять, как всё это работает, сделаем небольшой теоретический экскурс и разберём содержание основных понятий.

Как уже было сказано выше, трассировка в LTTng осуществляется на основе как статического, так и динамического инструментирования кода.

Во время выполнения инструментированного кода вызывается специальная функция-проба (англ. probе, что можно также перевести как «датчик» или «зонд»), которая считывает статус сессии и записывает информацию о событиях в каналы.

Проясним содержание понятий «сессия» и «канал». Сессией называется процедура трассировки с заданными пользователем параметрами. На рисунке выше показана всего одна сессия, но в LTTng можно запускать и несколько сессий одновременно.Сессию можно в любой момент остановить, изменять её настройки и затем запускать снова.

Для передачи отладочной информации каждая сессия использует каналы. Канал — это набор событий с определёнными характеристиками и дополнительной контекстной информацией. К числе характеристик (более подробно мы расскажем о них ниже) канала относятся: размер буфера, режим трассировки, период очистки буфера.

Зачем нужны каналы? Прежде всего для того, чтобы поддерживать общий кольцевой буфер, в который при трассировки записываются события и откуда их затем забирает демон-приёмник (consumer daemon). Кольцевой буфер в свою очередь подразделяется на многочисленные секции (sub-buffers) одинакового размера. Данные о событиях записываются в секцию, пока она не будет заполнена. После этого запись данных будет продолжена, но уже в другую секцию. Данные из переполненных секций запирает демон-приёмник и сохраняет их на диске (или передаёт по сети).

В идеале ситуаций, когда в секции заполнены и данные записывать некуда, возникать не должно. В реальной практике, однако, такие случаи иногда бывают. В официальной документации прямо сказано, что в LTTng производительность поставлена во главу угла: лучше потерять некоторую часть событий, чем замедлить работу системы. При создании канала можно выбирать один из двух режимов работы при переполнении буфера:

  • режим сброса (discard mode) — все новые события не будут записываться до тех пор, пока не освободится одна из секций;
  • режим перезаписи (overwrite mode) — самые старые события будут удалены, а на их место будут записываться новые.

Более подробно о настройке каналов можно прочитать здесь.

Трассировка событий

Приступим к изучению LTTng на практике и запустим первую трассировочную сессию.
Просмотреть список доступных для трассировки событий можно так (приводим лишь небольшой фрагмент, на самом деле этот список гораздо больше):

$ lttng list --kernel

Kernel events:
-------------
      writeback_nothread (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      writeback_queue (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      writeback_exec (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      writeback_start (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      writeback_written (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      writeback_wait (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      writeback_pages_written (loglevel: TRACE_EMERG (0)) (type: tracepoint)
            …….
      snd_soc_jack_irq (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      snd_soc_jack_report (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      snd_soc_jack_notify (loglevel: TRACE_EMERG (0)) (type: tracepoint)
      snd_soc_cache_sync (loglevel: TRACE_EMERG (0)) (type: tracepoint)

Попробуем отследить какое-нибудь событие — например, sched_switch. Сначала создадим сессию:

$ lttng create test_session
Session test_session created.
Traces will be written in /user/lttng-traces/test_session-20151119-134747

Итак, сессия создана. Все собранные в ходе этой сессии данные будут записываться в файл /user/lttng-traces/test_session-20151119-134747. Затем активируем интересующее нас событие:

$ lttng enable-event -k sched_switch
Kernel event sched_switch created in channel channel0

Далее выполним:

$ lttng start
Tracing started for session test_session

$ sleep 1
$ lttng stop

Информация обо всех событиях sched_switch будет сохранятся в отдельном файле. Просмотреть данные его содержимое можно так:

$ lttng view

Список событий будет слишком большим. Более того, он будет включать слишком много информации. Попробуем конкретизировать запрос и получить информацию только о событиях, которые имели место при выполнении команды sleep:

$ babeltrace /user/lttng-traces/test_session-20151119-134747 | grep sleep

[13:53:23.278672041] (+0.001249216) luna sched_switch: { cpu_id = 0 }, { prev_comm = "sleep", prev_tid = 10935, prev_prio = 20, prev_state = 1, next_comm = "swapper/0", next_tid = 0, next_prio = 20 }
[13:53:24.278777924] (+0.005448925) luna sched_switch: { cpu_id = 0 }, { prev_comm = "swapper/0", prev_tid = 0, prev_prio = 20, prev_state = 0, next_comm = "sleep", next_tid = 10935, next_prio = 20 }
[13:53:24.278912164] (+0.000134240) luna sched_switch: { cpu_id = 0 }, { prev_comm = "sleep", prev_tid = 10935, prev_prio = 20, prev_state = 0, next_comm = "rcuos/0", next_tid = 8, next_prio = 20 }

Вывод содержит информацию обо всех событиях sched_switch, зарегистрированных в системном ядре за время сессии. Он состоит из нескольких полей. Первое поле — это метка времени, второе — так называемая дельта (количество времени между предыдущим и текущим событием). В поле cpu_id указывается номер CPU, для которого было зарегистрировано событие. Далее следует дополнительная контекстуальная информация.

По завершении трассировки сессию нужно удалить:

$ lttng destroy

Трассировка системных вызовов

Для отслеживания системных вызовов у команды lttng enable-event имеется специальная опция — syscall. В статье, посвящённой ftrace, мы разбирали пример с отслеживанием системного вызова chroot. Попробуем проделать то же самое с помощью LTTng:

$ lttng create 
$ lttng enable-event -k --syscall chroot
$ lttng start

Создадим изолированное окружение с помощью команды chroot, а затем выполним:

$ lttng stop
$ lttng view

[12:05:51.993970181] (+?.?????????) andrei syscall_entry_chroot: { cpu_id = 0 }, { filename = "test" }
[12:05:51.993974601] (+0.000004420) andrei syscall_exit_chroot: { cpu_id = 0 }, { ret = 0 }
[12:06:53.373062654] (+61.379088053) andrei syscall_entry_chroot: { cpu_id = 0 }, { filename = "test" }
[12:06:53.373066648] (+0.000003994) andrei syscall_exit_chroot: { cpu_id = 0 }, { ret = 0 }
[12:07:36.701313906] (+43.328247258) andrei syscall_entry_chroot: { cpu_id = 1 }, { filename = "test" }
[12:07:36.701325202] (+0.000011296) andrei syscall_exit_chroot: { cpu_id = 1 }, { ret = 0 }

Как видим, вывод содержит информация обо всех входах в системный вызов syscall и выходах из него. По сравнению с выводом ftrace он выглядит несколько более структурированным и человекопонятным.

Динамическая трассировка

Выше мы рассмотрели примеры статической трассировки с использованием механизма tracepoints.

Для отслеживания событий в Linux также можно использовать механизм динамической трассировки kprobes (сокращение от kernel probes, как не трудно догадаться). Он позволяет добавлять новые точки трассировки (пробы) в ядро «на лету». Именно на kprobes основывается известный инструмент SystemTap. Работает он так: чтобы добавить в ядро пробу, нужно написать скрипт на специальном C-подобном языке; затем этот скрипт транслируется в код на C, который компилируется в отдельный модуль ядра. Использовать такой инструмент на практике очень сложно.

Начиная с версии ядра 3.10 поддержка kprobes была добавлена в ftrace. Благодаря этому стала возможной динамическая трассировка без написания скриптов и добавления новых модулей.

Реализована поддержка kprobes и в LTTng. Поддерживается два вида проб: собственно kprobes («базовые» пробы, которые могут быть вставлены в любое место в ядре) и kretprobes (ставятся перед выходом из функции и дают доступ к её результату). Рассмотрим несколько практических примеров,

В LTTng для установки «базовых» проб используется опция, которая так и называется — probe:

$ lttng create
$ lttng enable-event --kernel sys_open --probe sys_open+0x0
$ lttng enable-event --kernel sys_close --probe sys_close+0x0
$ lttng start
$ sleep 1     
$ lttng stop

Полученный в результате трассировки вывод будет выглядеть так (приводим небольшой фрагмент):

…..
[12:45:26.842026294] (+0.000028311) andrei sys_close: { cpu_id = 1 }, { ip = 0xFFFFFFFF81209830 }
[12:45:26.842036177] (+0.000009883) andrei sys_open: { cpu_id = 1 }, { ip = 0xFFFFFFFF8120B940 }
[12:45:26.842064681] (+0.000028504) andrei sys_close: { cpu_id = 1 }, { ip = 0xFFFFFFFF81209830 }
[12:45:26.842097484] (+0.000032803) andrei sys_open: { cpu_id = 1 }, { ip = 0xFFFFFFFF8120B940 }
[12:45:26.842126464] (+0.000028980) andrei sys_close: { cpu_id = 1 }, { ip = 0xFFFFFFFF81209830 }
[12:45:26.842141670] (+0.000015206) andrei sys_open: { cpu_id = 1 }, { ip = 0xFFFFFFFF8120B940 }
[12:45:26.842179482] (+0.000037812) andrei sys_close: { cpu_id = 1 }, { ip = 0xFFFFFFFF81209830 }

В приведённом выводе содержится поле ip — адрес отслеживаемоей функции в ядре.

С помощью опции −−function можно выставлять динамические пробы на вход в функцию и выход из неё, например:

$ lttng enable-event call_rcu_sched -k --function call_rcu_sched

.....

[15:31:39.092335027] (+0.000000742) cs31401 call_rcu_sched_return: { cpu_id = 0 }, { }, { ip = 0xFFFFFFFF810E7B10, parent_ip = 0xFFFFFFFF810A206D }
[15:31:39.092398089] (+0.000063062) cs31401 call_rcu_sched_entry: { cpu_id = 0 }, { }, { ip = 0xFFFFFFFF810E7B10, parent_ip = 0xFFFFFFFF810A206D }
[15:31:39.092398883] (+0.000000794) cs31401 call_rcu_sched_return: { cpu_id = 0 }, { }, { ip = 0xFFFFFFFF810E7B10, parent_ip = 0xFFFFFFFF810A206D }

В приведённом выводе присутствует ещё одно поле: parent_ip — адрес функции, которая вызвала отслеживаемую функцию.

В этом разделе мы привели лишь самые простые примеры. Однако возможности LTTng гораздо шире: сочетая различные способы инструментации, с его помощью можно получать такую информацию о работе системы, которую с помощью других инструментов получить сложно или вовсе невозможно. Прочитать об этом подробнее и ознакомиться с интересными примерами можно, например, в этой статье на LWN.net.

Заключение

LTTng — инструмент интересный и перспективный.Чтобы рассказать обо всех его возможностях, одной статьи явно не хватит. Поэтому будем признательны за любые замечания и дополнения.
А если вы используете LTTng на практике, приглашаем поделиться опытом в комментариях.

Для всех, кто хочется познакомиться с LTTng поближе, приводим подборку ссылок на интересные и полезные материалы:

Если вы по тем или иным причинам не можете оставлять комментарии здесь, добро пожаловать в наш корпоративный блог.

Автор: Селектел

Источник

Поделиться новостью

* - обязательные к заполнению поля