Linux Perf: различия между версиями
Материал из noname.com.ua
Перейти к навигацииПерейти к поискуSirmax (обсуждение | вклад) (→Ссылки) |
Sirmax (обсуждение | вклад) |
||
Строка 32: | Строка 32: | ||
</PRE> |
</PRE> |
||
* Опция -g fractal нужна для того, чтобы проценты, отражающие количество сэмплов с этой функцией и показываемые perf, были относительны вызывающей функции, количество вызовов которой берется за 100%. |
* Опция -g fractal нужна для того, чтобы проценты, отражающие количество сэмплов с этой функцией и показываемые perf, были относительны вызывающей функции, количество вызовов которой берется за 100%. |
||
+ | |||
+ | <PRE> |
||
+ | 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 |
||
+ | </PRE> |
||
=11= |
=11= |
Версия 12:15, 18 марта 2024
Linux perf
Поиск проблем в ядре, пример.
Авторы
- Основное исследование провел Денис Миргородский (email to be added!), я сделал только некоторые незначительные дополнения и оформил эту доку.
Зачем это нужно ?
Иногда хочется понять, что вообще происходит с системой, в частности мы наблюдали примерно 30-процентное проседание скорости работы хранилища (в IOPS)
после обновления Compute Node (OpenStack) с ядра 5.4
до 5.15
Введение в perf
Для тестирования, просто что бы понимать какие данные можно получить, и как с ними работать, запускаю сбор данных на "просто сервере"
Сбор данных
perf record -a -F 99 -g
-a, --all-cpus
- собрать данные со всех процессоров-F, --freq=
- частота, лучше выбирать нечетную что бы избежать ситуации когда регулярные события с происходящие частотой равной или кратной частоте семплирования, не будут записаны.-g
нужна для захвата стек трейсов- Результат будет записан в файл
perf.data
(не указано, это значение по-умолчанию)
Другие опции сбора можно подсмотреть например здесь: Хабр
Просмотр результатов
Посмотреть полученный результат можно командой:
perf report -g fractal
- Опция -g fractal нужна для того, чтобы проценты, отражающие количество сэмплов с этой функцией и показываемые perf, были относительны вызывающей функции, количество вызовов которой берется за 100%.
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