Текущая версия на 10:05, 19 марта 2024

Linux `perf`

Поиск проблем в ядре, пример.

Авторы

Основное исследование провел <>, я сделал только некоторые незначительные дополнения и оформил эту доку.

Зачем это нужно ?

Иногда хочется понять, что вообще происходит с системой, в частности мы наблюдали примерно 30-процентное проседание скорости работы хранилища (в IOPS)
после обновления Compute Node (OpenStack) с ядра 5.4 до 5.15

TL;DR

Дело было в том что процессор переходил в режим сохранения энергии слишком активно
intel_idle.max_cstate=0
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=a472ad2bcea479ba068880125d7273fc95c14b70

Введение в `perf`

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

Сбор данных

perf record -a -F 99 -g

-a, --all-cpus - собрать данные со всех процессоров
-F, --freq= - частота, лучше выбирать нечетную что бы избежать ситуации когда регулярные события с происходящие частотой равной или кратной частоте семплирования, не будут записаны.
-g нужна для захвата стек трейсов
Результат будет записан в файл perf.data (не указано, это значение по-умолчанию)

Другие опции сбора можно подсмотреть например здесь: Хабр

Просмотр результатов

Посмотреть полученный результат можно командой:

perf report -g fractal

Опция -g fractal нужна для того, чтобы проценты, отражающие количество сэмплов с этой функцией и показываемые perf, были относительны вызывающей функции, количество вызовов которой берется за 100%.

Выглядит это примерно так (и тут можно четко видеть что сервер большую часть времени ничего не делает (swapper --> mwait_idle_with_hints.constprop.0) но иногда что-то делает zabbix_server и mariadbd

Samples: 118K of event 'cycles', Event count (approx.): 496275267116
  Children      Self  Command          Shared Object                   Symbol
+   70.97%     0.00%  swapper          [kernel.kallsyms]               [k] secondary_startup_64_no_verify
+   70.96%     0.01%  swapper          [kernel.kallsyms]               [k] cpu_startup_entry
+   70.83%     0.08%  swapper          [kernel.kallsyms]               [k] do_idle
+   67.86%     0.12%  swapper          [kernel.kallsyms]               [k] cpuidle_idle_call
+   66.49%     0.08%  swapper          [kernel.kallsyms]               [k] cpuidle_enter
+   65.89%     0.78%  swapper          [kernel.kallsyms]               [k] cpuidle_enter_state
+   61.02%     0.00%  swapper          [kernel.kallsyms]               [k] start_secondary
+   53.46%    53.46%  swapper          [kernel.kallsyms]               [k] mwait_idle_with_hints.constprop.0
+    9.95%     0.00%  swapper          [kernel.kallsyms]               [k] x86_64_start_kernel
+    9.95%     0.00%  swapper          [kernel.kallsyms]               [k] x86_64_start_reservations
+    9.95%     0.00%  swapper          [kernel.kallsyms]               [k] start_kernel
+    9.95%     0.00%  swapper          [kernel.kallsyms]               [k] arch_call_rest_init
+    9.95%     0.00%  swapper          [kernel.kallsyms]               [k] rest_init
+    8.95%     0.01%  swapper          [kernel.kallsyms]               [k] asm_common_interrupt
+    8.93%     0.06%  swapper          [kernel.kallsyms]               [k] common_interrupt
+    8.12%     0.05%  zabbix_server    [kernel.kallsyms]               [k] entry_SYSCALL_64_after_hwframe
+    8.02%     0.03%  zabbix_server    [kernel.kallsyms]               [k] do_syscall_64
+    7.39%     0.00%  zabbix_server    [unknown]                       [k] 0x000000000000006c
+    7.39%     0.00%  zabbix_server    libevent-2.1.so.7.0.1           [.] 0x00007fdc2a024600
+    6.71%     0.04%  swapper          [kernel.kallsyms]               [k] __common_interrupt
+    6.64%     0.00%  zabbix_server    [unknown]                       [.] 0x0000561ff32d3280
+    6.62%     0.05%  swapper          [kernel.kallsyms]               [k] handle_edge_irq
+    6.60%     0.09%  zabbix_server    libc.so.6                       [.] epoll_wait
+    6.45%     0.02%  swapper          [kernel.kallsyms]               [k] handle_irq_event
+    6.34%     0.04%  swapper          [kernel.kallsyms]               [k] __handle_irq_event_percpu
+    6.23%     0.04%  swapper          [kernel.kallsyms]               [k] hrtimer_interrupt
+    5.63%     0.06%  zabbix_server    [kernel.kallsyms]               [k] __x64_sys_epoll_wait
+    5.49%     0.05%  zabbix_server    [kernel.kallsyms]               [k] do_epoll_wait
+    5.29%     0.10%  zabbix_server    [kernel.kallsyms]               [k] ep_poll
+    5.22%     0.01%  swapper          [kernel.kallsyms]               [k] hpet_msi_interrupt_handler
+    5.00%     0.02%  zabbix_server    [kernel.kallsyms]               [k] schedule_hrtimeout_range
+    4.97%     0.06%  zabbix_server    [kernel.kallsyms]               [k] schedule_hrtimeout_range_clock
+    4.19%     0.04%  zabbix_server    [kernel.kallsyms]               [k] schedule
+    4.10%     0.12%  zabbix_server    [kernel.kallsyms]               [k] __schedule
+    3.87%     0.00%  mariadbd         libc.so.6                       [.] 0x00007fe8000cdac3
+    3.87%     0.00%  mariadbd         mariadbd                        [.] 0x000055b951d36a26
+    3.87%     0.00%  mariadbd         mariadbd                        [.] handle_one_connection
+    3.87%     0.00%  mariadbd         mariadbd                        [.] do_handle_one_connection
+    3.86%     0.01%  mariadbd         mariadbd                        [.] do_command
+    3.79%     0.03%  swapper          [kernel.kallsyms]               [k] clockevents_program_event
+    3.76%     0.01%  mariadbd         mariadbd                        [.] dispatch_command
+    3.73%     3.73%  swapper          [kernel.kallsyms]               [k] hpet_clkevt_set_next_event
+    3.69%     0.00%  mariadbd         mariadbd                        [.] mysql_parse
+    3.49%     0.01%  swapper          [kernel.kallsyms]               [k] tick_program_event
+    3.46%     0.01%  mariadbd         mariadbd                        [.] mysql_execute_command
+    3.02%     0.00%  mariadbd         mariadbd                        [.] 0x000055b9518c29dc
+    3.02%     0.00%  mariadbd         mariadbd                        [.] handle_select
+    3.01%     0.00%  mariadbd         mariadbd                        [.] mysql_select
+    2.54%     0.00%  mariadbd         mariadbd                        [.] JOIN::exec
+    2.54%     0.00%  mariadbd         mariadbd                        [.] JOIN::exec_inner
+    2.54%     0.13%  swapper          [kernel.kallsyms]               [k] __hrtimer_run_queues
+    2.50%     0.00%  mariadbd         mariadbd                        [.] sub_select

`FlameGraph`

Визуально можно представить данные с помощью FlameGraph
Установить:

git clone https://github.com/brendangregg/FlameGraph

Запустить:

perf script --input ./perf.data  | /root/FlameGraph/stackcollapse-perf.pl | /root/FlameGraph/flamegraph.pl > file.svg

perf script --input ./perf.data - преобразует данне в вид, который может понять stackcollapse-perf.pl
--input ./perf.data - это путь по-умолчанию, и указан для того что бы было понятнее откуда взяты данные для анализа.

Заголовок
Flame Chart	Пояснения
Файл кликабельный (нужно кликнуть 2 раза что бы добраться до SVG)	Читать этот график следует так Нижняя линия (красная, без подписи) это 100% времени Вторая снизу - распределение времени по функциям, больше всего времени в функции `swapper` Почти все время в функции swapper проводит в `secondary_startup_64_no_verify` И так далее смотреть вверх по функциям Пробелы в верхней части графика означают что время проведено собственно в функции, а не вызывалась какая-то другая функция

Сравнение производительности разных ядер на реальном тесте

Первый столбец показывает ситуацию с "беспроблемным" ядром 5.4, второй с проблемным ядром 5.15 и третий с ядром 5.15 c опцией intel_idle.max_cstate=0
Для понимания - результат исследования после исправления в третьем столбце.

Заголовок
Ядро 5.4	Ядро 5.15 (проблемное)	Ядро 5.15 (C решенной проблемой)
Файл кликабельный (нужно кликнуть 2 раза что бы добраться до SVG)	Файл кликабельный (нужно кликнуть 2 раза что бы добраться до SVG)	Файл кликабельный (нужно кликнуть 2 раза что бы добраться до SVG)
Ход исследования	Ход исследования	Ход исследования
Тут можно видеть, что используется функция `mwait_idle`	Тут можно видеть, что используется функция `intel_idle`	После того, как ядру передан параметр `intel_idle.max_cstate=0` можно видеть что снова используется функция `mwait_idle`

Рубрика "советы бывалых"

C1 (Halt) - состояние, когда процессор не исполняет инструкции, но готов мгновенно ( с задержкой примерно 10нс) приступить к их исполнению, при этом его энергопотребление составляет примерно 30% от нормы.

Столкнулся совсем недавно, при nosoftlockup intel_idle.max_cstate=0 processor.max_cstate=1 mce=ignore_ce idle=poll температура на CPU0 E5-2660 и включённом Turbo Boost взлетала до 80-81°C. Убрал idle=poll, стало 70-71°C

Удобные утилиты

powertop
i7z

Ещё важно для максимальной производительности, чтобы не было переключения в C-state'ы >1 (для этого нужно делать processor.max_cstate=1 intel_idle.max_cstate=0 idle=poll) но будет есть больше электричества

Изменение CPU Scaling Governor в Linux

На серверах HPE BIOS обязательно нужно включить Collaborative Power Control (CPC) иначе из операционной системы нельзя будет управлять производительностью процессора и не будет этих файлов:

find / -name scaling_governor
find / -name scaling_max_freq

В случае Dell (R710) аналогично - есть пункт в меню

Посмотрим текущее значение всех ядер процессора:

cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor

В моем случае было 4 возможных варианта:

schedutil
performance
ondemand (значение по умолчанию?)
Отсутвовали файлы, посмотреть нельзя

Посмотрим возможные схемы:

cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors

Доступны (там где возможно посмотреть)

conservative
ondemand
userspace
powersave
performance
schedutil

echo performance > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu1/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu2/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu3/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu4/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu5/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu6/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu7/cpufreq/scaling_governor

Либо так:

apt install cpufrequtils
for i in 0 1 2 3 4 5 6 7 8 9 10 11; do cpufreq-set -c $i -g performance; done

Проверим:

cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor

egrep '(MHz)' /proc/cpuinfo

Если предыдущие способы не помогли, то для Intel CPU можно также указать «intel_idle.max_cstate» в grub:

nano /etc/default/grub
GRUB_CMDLINE_LINUX_DEFAULT="... intel_idle.max_cstate=1"
update-grub
reboot

dmesg -T | grep intel_idle

Либо можно полностью отключить энергосберегающие функции CPU и PCIe:

intel_idle.max_cstate=0 processor.max_cstate=1 pcie_aspm=off quiet mitigations=off

В крайнем случае с idle=poll:

intel_idle.max_cstate=0 processor.max_cstate=1 pcie_aspm=off quiet mitigations=off idle=poll

отключить уже ненужную службу энергосбережения:

systemctl is-enabled ondemand
systemctl disable ondemand

Ссылки

https://www.brendangregg.com/perf.html

@@ Строка 8: / Строка 8: @@
 Поиск проблем в ядре, пример.
 =Авторы=
-* Основное исследование провел Денис Миргородский (email to be added!), я сделал только некоторые незначительные дополнения и оформил эту доку.
+* Основное исследование провел <>, я сделал только некоторые незначительные дополнения и оформил эту доку.
 =Зачем это нужно ? =
 Иногда хочется понять, что вообще происходит с системой, в частности мы наблюдали примерно 30-процентное проседание скорости работы хранилища (в IOPS)<BR>
@@ Строка 275: / Строка 275: @@
 intel_idle.max_cstate=0 processor.max_cstate=1 pcie_aspm=off quiet mitigations=off idle=poll
 </PRE>
-Замечу, что если указать idle=poll, то в BIOS или iLo например, может отображаться что CPU используется на 100%, хотя это не так.
-Также отключим уже ненужную службу энергосбережения:
+отключить уже ненужную службу энергосбережения:
 <PRE>
 systemctl is-enabled ondemand

Linux Perf: различия между версиями

Текущая версия на 10:05, 19 марта 2024

Содержание

Linux `perf`

Авторы

Зачем это нужно ?

TL;DR

Введение в `perf`

Сбор данных

Просмотр результатов

`FlameGraph`

Сравнение производительности разных ядер на реальном тесте

Рубрика "советы бывалых"

Изменение CPU Scaling Governor в Linux

Ссылки

Навигация

Действия на странице

Действия на странице

Персональные инструменты

Навигация

Поиск

Инструменты

Linux Perf: различия между версиями

Текущая версия на 10:05, 19 марта 2024

Linux perf

Авторы

Зачем это нужно ?

TL;DR

Введение в perf

Сбор данных

Просмотр результатов

FlameGraph

Сравнение производительности разных ядер на реальном тесте

Рубрика "советы бывалых"

Изменение CPU Scaling Governor в Linux

Ссылки

Навигация

Поиск

Linux `perf`

Введение в `perf`

`FlameGraph`