Наши партнеры

Система горячего водоснабжения монтаж
водоснабжения до последующего обслуживания. Полный комплекс
specservisgaz.ru

Библиотека сайта rus-linux.net

Руководство для начинающих пользователей SystemTap. Полезные сценарии SystemTap

Оригинал: SystemTap Beginners Guide
Авторы: Don Domingo, William Cohen
Дата публикации: 20 июля 2009 г.
Перевод: А.Панин
Дата перевода: 3 октября 2014 г.

Глава 5. Полезные сценарии SystemTap

5.3. Профилирование

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

5.3.1. Подсчет количества осуществленных вызовов функций

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

functioncallcount.stp

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

Вывод сценария functioncallcount.stp представляет собой список из имен вызванных функций вместе с числом их вызовов в течение периода исследования (отсортированный в алфавитном порядке). Пример 5.13, "Вариант вывода сценария functioncallcount,stp" содержит фрагмент вывода упомянутого сценария, запущенного с помощью команды stap functionclaccount.stp "*@mm/*.c":

Пример 5.13. Вариант вывода сценария functioncallcount.stp

5.3.2. Трассировка графа вызовов

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

para-cellgraph.stp

Сценарий para-cellgraph.stp принимает два аргумента командной строки:

Описание функций, вызовы которых/выходы из которых вы хотите отслеживать ($1).
Дополнительное, необязательное описание функции-триггера (trigger function) ($2), которая позволяет активировать или деактивировать механизм трассировки на уровне программных потоков. Трассировка на уровне каждого из программных потоков может продолжаться настолько долго, насколько долго не будет осуществляется выход из функции-триггера.

Сценарий para-callgraph.stp использует функцию thread_indent(); ввиду этого строки вывода сценария содержат метку времени, имя процесса и идентификатор программного потока, в рамках которого осуществлялся вызов функций, описанных с помощью параметра $1 (а именно, исследуемых функций, вызовы которых вы отслеживаете). Для получения дополнительной информации о функции thread_indent() обратитесь к ее описанию в разделе "Функции SystemTap".

Следующий пример содержит фрагмент вывода сценария, запущенного с помощью команды stap para-callgraph.stp 'kernel.function("*@fs/*.c")' 'kernel.function("sys_read")':

Пример 5.14. Вариант вывода сценария para-callgraph.stp

5.3.3. Подсчет процессорного времени, затраченного в пространствах ядра ОС и пользователя

В данном разделе проиллюстрирован способ определения количества процессорного времени, которое заданный программный поток проводит в пространстве ядра ОС и в пространстве пользователя.

thread-times.stp

Сценарий thread-times.stp выводит информацию о 20 процессах, использовавших большую часть времени центрального процессора в течение 5-секундного периода вместе с общим количеством тиков центрального процессора в течение этого периода. В выводе данного сценария также приведен процентный показатель использования центрального процессора каждым из процессов вместе с информацией о том, было ли это время затрачено в пространстве ядра или в пространстве пользователя.

Пример 5.15, "Вариант вывода сценария thread-times.stp" содержит фрагмент вывода сценария thread-times.stp после 5 секунд работы:

Пример 5.15. Вариант вывода сценария thread-times.stp

5.3.4. Мониторинг работы приложений, осуществляющих ожидание событий

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

timeout.stp

#! /usr/bin/env stap
# Авторские права (C) 2009 Red Hat, Inc.
# Разработка Ulrich Drepper "drepper@redhat.com"
# Модификации William Cohen "wcohen@redhat.com"

global process, timeout_count, to
global poll_timeout, epoll_timeout, select_timeout, itimer_timeout
global nanosleep_timeout, futex_timeout, signal_timeout

probe syscall.poll, syscall.epoll_wait {
  if (timeout) to[pid()]=timeout
}

probe syscall.poll.return {
  p = pid()
  if ($return == 0 && to[p] > 0 ) {
    poll_timeout[p]++
    timeout_count[p]++
    process[p] = execname()
    delete to[p]
  }
}

probe syscall.epoll_wait.return {
  p = pid()
  if ($return == 0 && to[p] > 0 ) {
    epoll_timeout[p]++
    timeout_count[p]++
    process[p] = execname()
    delete to[p]
  }
}

probe syscall.select.return {
  if ($return == 0) {
    p = pid()
    select_timeout[p]++
    timeout_count[p]++
    process[p] = execname()
  }
}

probe syscall.futex.return {
  if (errno_str($return) == "ETIMEDOUT") {
    p = pid()
    futex_timeout[p]++
    timeout_count[p]++
    process[p] = execname()
  }
}

probe syscall.nanosleep.return {
  if ($return == 0) {
    p = pid()
    nanosleep_timeout[p]++
    timeout_count[p]++
    process[p] = execname()
  }
}

probe kernel.function("it_real_fn") {
  p = pid()
  itimer_timeout[p]++
  timeout_count[p]++
  process[p] = execname()
}

probe syscall.rt_sigtimedwait.return {
  if (errno_str($return) == "EAGAIN") {
    p = pid()
    signal_timeout[p]++
    timeout_count[p]++
    process[p] = execname()
  }
}

probe syscall.exit {
  p = pid()
  if (p in process) {
    delete process[p]
    delete timeout_count[p]
    delete poll_timeout[p]
    delete epoll_timeout[p]
    delete select_timeout[p]
    delete itimer_timeout[p]
    delete futex_timeout[p]
    delete nanosleep_timeout[p]
    delete signal_timeout[p]
  }
}

probe timer.s(1) {
  ansi_clear_screen()
  printf ("  pid |   poll  select   epoll  itimer   futex nanosle  signal| процесс\n")
  foreach (p in timeout_count- limit 20) {
     printf ("%5d |%7d %7d %7d %7d %7d %7d %7d| %-.38s\n", p,
              poll_timeout[p], select_timeout[p],
              epoll_timeout[p], itimer_timeout[p],
              futex_timeout[p], nanosleep_timeout[p],
              signal_timeout[p], process[p])
  }
}

Сценарий timeout.stp отслеживает количество выходов из следующих системных вызовов из-за истечения установленного времени ожидания, а не из-за наступления установленного события:

poll
select
epoll
itimer
futex
nonosleep
signal

Пример 5.16. Вариант вывода сценария timeout.stp

uid |   poll  select   epoll  itimer   futex nanosle  signal| процесс
28937 | 148793       0       0    4727   37288       0       0| firefox
22945 |      0   56949       0       1       0       0       0| scim-bridge
    0 |      0       0       0   36414       0       0       0| swapper
 4275 |  23140       0       0       1       0       0       0| mixer_applet2
 4191 |      0   14405       0       0       0       0       0| scim-launcher
22941 |   7908       1       0      62       0       0       0| gnome-terminal
 4261 |      0       0       0       2       0    7622       0| escd
 3695 |      0       0       0       0       0    7622       0| gdm-binary
 3483 |      0    7206       0       0       0       0       0| dhcdbd
 4189 |   6916       0       0       2       0       0       0| scim-panel-gtk
 1863 |   5767       0       0       0       0       0       0| iscsid
 2562 |      0    2881       0       1       0    1438       0| pcscd
 4257 |   4255       0       0       1       0       0       0| gnome-power-man
 4278 |   3876       0       0      60       0       0       0| multiload-apple
 4083 |      0    1331       0    1728       0       0       0| Xorg
 3921 |   1603       0       0       0       0       0       0| gam_server
 4248 |   1591       0       0       0       0       0       0| nm-applet
 3165 |      0    1441       0       0       0       0       0| xterm
29548 |      0    1440       0       0       0       0       0| httpd
 1862 |      0       0       0       0       0    1438       0| iscsid

Вы можете увеличить продолжительность периода исследования, отредактировав объявление второго зонда (timer.s(1)). Вывод сценария timeout.stp содержит имена и идентификаторы 20 наиболее интенсивно ожидающих наступления событий приложений вместе с информацией о количестве использованных для ожидания этих событий системных вызовов (время работы которых истекло). Пример 5.16, "Вариант вывода сценария timeout.stp" содержит фрагмент вывода упомянутого сценария. В данном примере приложение firefox выполняет чрезмерное количество системных вызовов для ожидания событий в рамках модуля своего плагина.

5.3.5. Отслеживание наиболее часто используемых системных вызовов

Сценарий timeout.stp из Раздела 5.3.4, "Мониторинг приложений, осуществляющих ожидание событий" может помочь с идентификацией приложений, которые интенсивно используют системные вызовы для ожидания событий путем исследования небольшого подмножества системных вызовов (poll, select, epoll, itimer, futex, nanosleep и signal). Однако, в некоторых системах чрезвычайно большое количество задействованных системных вызовов, не относящихся к данному подмножеству, может быть причиной затрат процессорного времени в пространстве ядра. Если вы подозреваете, что ваше приложение осуществляет чрезмерное количество системных вызовов, вам придется идентифицировать наиболее часто используемые системные вызовы в рамках вашей системы. Для этого вы можете использовать сценарий topsys.stp.

topsys.stp

Сценарий topsys.stp выводит информацию о 20 наиболее часто используемых в рамках системы системных вызовах с 5-секундными интервалами. Он также выводит информацию о количестве вызовов каждого из этих системных вызовов в течение заданного промежутка времени. Обратитесь к Примеру 5.17, "Вариант вывода сценария topsys.stp" для ознакомления со структурой вывода данного сценария.

Пример 5.17, Вариант вывода сценария topsys.stp

5.3.6. Отслеживание интенсивности осуществления системных вызовов каждым из процессов

В данном разделе проиллюстрирован способ определения процессов, наиболее интенсивно осуществляющих системные вызовы. В предыдущих разделах мы обсуждали способ выявления наиболее часто используемых в рамках системы системных вызовов с течением времени (Раздел 5.3.5, "Отслеживание наиболее часто используемых системных вызовов"). Также мы обсудили способ идентификации приложений, которые наиболее интенсивно используют определенный набор "ожидающих событий" системных вызовов (Раздел 5.3.4, "Мониторинг работы приложений, осуществляющих ожидание событий"). Мониторинг интенсивности осуществления системных вызовов каждым из процессов, позволяет получить больше данных для исследования вашей системы с целью поиска процессов, ожидающих наступления событий, а также выявления других неоправданных затрат ресурсов.

syscalls_by_proc.stp

Сценарий syscalls_by_proc.stp выводит имена 20 процессов, осуществляющих наибольшее количество системных вызовов. Также он выводит информацию о количестве системных вызовов, осуществленных каждым из этих процессов в течение периода заданной продолжительности. Обратитесь к Примеру 5.18, "Вариант вывода сценария syscalls_by_proc.stp" для ознакомления со структурой вывода данного сценария.

Пример 5.18. Вариант вывода сценария syscalls_by_proc.stp

Для вывода идентификаторов процессов вместо имен процессов следует использовать следующий сценарий.

syscalls_by_pid.stp

Как ясно из вывода, вам необходимо вручную завершить исполнение сценария для того, чтобы он вывел результаты. Вы можете реализовать таймер в рамках любого из приведенных сценариев, просто добавив зонд для события timer.s(); например, для сообщения сценарию о необходимости завершения работы по истечении 5 секунд, следует добавить следующий зонд в сценарий:

probe timer.s(5)
{
	exit()
}

5.4. Идентификация конфликтующих блокировок в пространстве пользователя

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

Для простоты можно считать, что конфликты быстрых взаимных исключений пространства пользователя (futex) возникают тогда, когда множество процессов пытается получить доступ к одной и той же переменной блокировки в один и тот же момент времени. Результат этого конфликта может заключаться в низкой производительности приложения, так как блокировка приводит к последовательному исполнению инструкций; один процесс получает контроль над блокировкой в то время, когда все остальные процессы должны ожидать повторного освобождения переменной данной блокировки.

Сценарий futexes.stp исследует системный вызов futex с целью сбора информации о конфликтах блокировок.

futexes.stp

#! /usr/bin/env stap

# Данный сценарий пытается идентифицировать конфликтующие блокировки пространства 
# пользователя путем отслеживания использования системного вызова futex.

global FUTEX_WAIT = 0 /*, FUTEX_WAKE = 1 */
global FUTEX_PRIVATE_FLAG = 128 /* linux 2.6.22+ */
global FUTEX_CLOCK_REALTIME = 256 /* linux 2.6.29+ */

global lock_waits # информация (tid,lock) о времени блокировок длительного хранения
global process_names # таблица соответствий pid - исполняемый файл длительного хранения.

probe syscall.futex.return {  
  if (($op & ~(FUTEX_PRIVATE_FLAG|FUTEX_CLOCK_REALTIME)) != FUTEX_WAIT) next
  process_names[pid()] = execname()
  elapsed = gettimeofday_us() - @entry(gettimeofday_us())
  lock_waits[pid(), $uaddr] <<< elapsed
}

probe end {
  foreach ([pid+, lock] in lock_waits) 
    printf ("%s[%d] блокировка %p была причиной конфликта %d раз(а), в среднем в течение %d мс\n",
            process_names[pid], pid, lock, @count(lock_waits[pid,lock]),
            @avg(lock_waits[pid,lock]))
}

Исполнение сценария futexes.stp должно быть остановлено вручную; по завершении работы он выводит следующую информацию:

Имя и идентификатор процесса, в рамках которого произошел конфликт блокировок
Адрес переменной блокировки, из-за которой произошел конфликт
Количество конфликтов из-за переменной блокировки
Среднее время конфликтов, рассчитанное в течение периода исследования

Пример 5.19, "Вариант вывода сценария futexes.stp" содержит фрагмент вывода сценария futexes.stp, полученного после завершения работы сценария (после исполнения сценария в течение примерно 20 секунд).

Пример 5.19. Вариант вывода сценария futexes.stp

[...]
automount[2825] блокировка 0x00bc7784 была причиной конфликта 18 раз(а), в среднем в течение 999931 мс
synergyc[3686] блокировка 0x0861e96c была причиной конфликта 192 раз(а), в среднем в течение 101991 мс
synergyc[3758] блокировка 0x08d98744 была причиной конфликта 192 раз(а), в среднем в течение 101990 мс
synergyc[3938] блокировка 0x0982a8b4 была причиной конфликта 192 раз(а), в среднем в течение 101997 мс
[...]

Следующий раздел : Глава 6. Обзор сообщений об ошибках SystemTap.