Трассировка ядра с помощью Trace-CMD
Trace-cmd — это простая в использовании и многофункциональная утилита для отслеживания функций ядра Linux.
В моей предыдущей статье я объяснил, как использовать ftrace для отслеживания функций ядра. Использование ftrace при записи и чтении файлов может оказаться утомительным, поэтому я использовал его оболочку для запуска команд с параметрами включения и отключения трассировки, установки фильтров, просмотра вывода, очистки вывода и т. д.
Команда трассировки-cmd — это утилита, которая поможет вам сделать это. В этой статье я использую trace-cmd для выполнения тех же задач, что и в своей статье о ftrace. Поскольку я часто возвращаюсь к этой статье, я рекомендую вам прочитать ее, прежде чем читать эту.
Установите трассировку-cmd
Я запускаю команды, описанные в этой статье, от имени пользователя root.
Механизм ftrace встроен в ядро, и вы можете проверить его работу с помощью:
# mount | grep tracefs
none on /sys/kernel/tracing type tracefs (rw,relatime,seclabel)Однако вам необходимо установить утилиту trace-cmd вручную.
# dnf install trace-cmd -yСписок доступных трассировщиков
При использовании ftrace необходимо просмотреть содержимое файла, чтобы узнать, какие трассировщики доступны. Но с помощью trace-cmd вы можете получить эту информацию с помощью:
# trace-cmd list -t
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nopВключить трассировщик функций
В моей предыдущей статье я использовал два трассировщика и сделаю то же самое здесь. Включите свой первый трассировщик, function, с помощью:
$ trace-cmd start -p function
plugin 'function'Просмотр результатов трассировки
После включения трассировщика вы можете просмотреть выходные данные, используя аргументы show. Здесь показаны только первые 20 строк, чтобы пример был коротким (см. мою предыдущую статью для объяснения вывода):
# trace-cmd show | head -20
## tracer: function
#
# entries-in-buffer/entries-written: 410142/3380032 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
gdbus-2606 [004] ..s. 10520.538759: __msecs_to_jiffies <-rebalance_domains
gdbus-2606 [004] ..s. 10520.538760: load_balance <-rebalance_domains
gdbus-2606 [004] ..s. 10520.538761: idle_cpu <-load_balance
gdbus-2606 [004] ..s. 10520.538762: group_balance_cpu <-load_balance
gdbus-2606 [004] ..s. 10520.538762: find_busiest_group <-load_balance
gdbus-2606 [004] ..s. 10520.538763: update_group_capacity <-update_sd_lb_stats.constprop.0
gdbus-2606 [004] ..s. 10520.538763: __msecs_to_jiffies <-update_group_capacity
gdbus-2606 [004] ..s. 10520.538765: idle_cpu <-update_sd_lb_stats.constprop.0
gdbus-2606 [004] ..s. 10520.538766: __msecs_to_jiffies <-rebalance_domainsОстановить трассировку и очистить буфер
Трассировка продолжает выполняться в фоновом режиме, и вы можете продолжать просматривать выходные данные с помощью show.
Чтобы остановить трассировку, запустите trace-cmd с аргументом stop:
# trace-cmd stopЧтобы очистить буфер, запустите его с аргументом clear:
# trace-cmd clearВключить трассировщик function_graph
Включите второй трассировщик, function_graph, выполнив:
# trace-cmd start -p function_graph
plugin 'function_graph'Еще раз просмотрите вывод, используя аргумент show. Как и ожидалось, выходные данные немного отличаются от результатов первой трассировки. На этот раз он включает цепочку вызовов функций:
# trace-cmd show | head -20
## tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
4) 0.079 us | } /* rcu_all_qs */
4) 0.327 us | } /* __cond_resched */
4) 0.081 us | rcu_read_unlock_strict();
4) | __cond_resched() {
4) 0.078 us | rcu_all_qs();
4) 0.243 us | }
4) 0.080 us | rcu_read_unlock_strict();
4) | __cond_resched() {
4) 0.078 us | rcu_all_qs();
4) 0.241 us | }
4) 0.080 us | rcu_read_unlock_strict();
4) | __cond_resched() {
4) 0.079 us | rcu_all_qs();
4) 0.235 us | }
4) 0.095 us | rcu_read_unlock_strict();
4) | __cond_resched() {Используйте команды stop и clear, чтобы остановить трассировку и очистить буфер:
# trace-cmd stop
# trace-cmd clearНастройте трассировку для увеличения глубины
Если вы хотите увидеть больше глубины в вызовах функций, вы можете настроить трассировщик:
# trace-cmd start -p function_graph --max-graph-depth 5
plugin 'function_graph'Теперь, когда вы сравните этот вывод с тем, что видели раньше, вы должны увидеть больше вложенных вызовов функций:
# trace-cmd show | head -20
## tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
6) | __fget_light() {
6) 0.804 us | __fget_files();
6) 2.708 us | }
6) 3.650 us | } /* __fdget */
6) 0.547 us | eventfd_poll();
6) 0.535 us | fput();
6) | __fdget() {
6) | __fget_light() {
6) 0.946 us | __fget_files();
6) 1.895 us | }
6) 2.849 us | }
6) | sock_poll() {
6) 0.651 us | unix_poll();
6) 1.905 us | }
6) 0.475 us | fput();
6) | __fdget() {Изучите доступные функции для отслеживания
Если вы хотите отслеживать только определенные функции и игнорировать остальные, вам необходимо знать точные имена функций. Вы можете получить их с помощью аргумента list, за которым следует -f. В этом примере выполняется поиск общей функции ядра kmalloc, которая используется для выделения памяти в ядре:
# trace-cmd list -f | grep kmalloc
bpf_map_kmalloc_node
mempool_kmalloc
__traceiter_kmalloc
__traceiter_kmalloc_node
kmalloc_slab
kmalloc_order
kmalloc_order_trace
kmalloc_large_node
__kmalloc
__kmalloc_track_caller
__kmalloc_node
__kmalloc_node_track_caller
[...]Вот общее количество функций, доступных в моей тестовой системе:
# trace-cmd list -f | wc -l
63165Функции трассировки модуля ядра
Вы также можете отслеживать функции, связанные с конкретным модулем ядра. Представьте, что вы хотите отслеживать функции, связанные с модулем ядра kvm. Убедитесь, что модуль загружен:
# lsmod | grep kvm_intel
kvm_intel 335872 0
kvm 987136 1 kvm_intelСнова запустите trace-cmd с аргументом list и на выходе grep для строк, оканчивающихся на ] . Это позволит отфильтровать модули ядра. Затем grep модуль ядра kvm_intel, и вы должны увидеть все функции, связанные с этим модулем ядра:
# trace-cmd list -f | grep ]$ | grep kvm_intel
vmx_can_emulate_instruction [kvm_intel]
vmx_update_emulated_instruction [kvm_intel]
vmx_setup_uret_msr [kvm_intel]
vmx_set_identity_map_addr [kvm_intel]
handle_machine_check [kvm_intel]
handle_triple_fault [kvm_intel]
vmx_patch_hypercall [kvm_intel]
[...]
vmx_dump_dtsel [kvm_intel]
vmx_dump_sel [kvm_intel]Отслеживание конкретных функций
Теперь, когда вы знаете, как находить интересующие функции, примените эти знания на примере. Как и в предыдущей статье, попробуйте отследить функции, связанные с файловой системой. В моей тестовой системе использовалась файловая система ext4.
Эта процедура немного отличается; вместо start вы запускаете команду с аргументом record, за которым следует «шаблон» функций, которые вы хотите отслеживать. Вам также необходимо указать нужный трассировщик; в данном случае это function_graph. Команда продолжает запись трассировки, пока вы не остановите ее нажатием Ctrl+C. Итак, через несколько секунд нажмите Ctrl+C, чтобы остановить отслеживание:
# trace-cmd list -f | grep ^ext4_
# trace-cmd record -l ext4_* -p function_graph
plugin 'function_graph'
Hit Ctrl^C to stop recording
^C
CPU0 data recorded at offset=0x856000
8192 bytes in size
[...]Просмотр записанной трассировки
Чтобы просмотреть записанную ранее трассировку, запустите команду с аргументом report. Из вывода видно, что фильтр сработал, и вы видите только трассировку функции, связанной с ext4:
# trace-cmd report | head -20
[...]
cpus=8
trace-cmd-12697 [000] 11303.928103: funcgraph_entry: | ext4_show_options() {
trace-cmd-12697 [000] 11303.928104: funcgraph_entry: 0.187 us | ext4_get_dummy_policy();
trace-cmd-12697 [000] 11303.928105: funcgraph_exit: 1.583 us | }
trace-cmd-12697 [000] 11303.928122: funcgraph_entry: | ext4_create() {
trace-cmd-12697 [000] 11303.928122: funcgraph_entry: | ext4_alloc_inode() {
trace-cmd-12697 [000] 11303.928123: funcgraph_entry: 0.101 us | ext4_es_init_tree();
trace-cmd-12697 [000] 11303.928123: funcgraph_entry: 0.083 us | ext4_init_pending_tree();
trace-cmd-12697 [000] 11303.928123: funcgraph_entry: 0.141 us | ext4_fc_init_inode();
trace-cmd-12697 [000] 11303.928123: funcgraph_exit: 0.931 us | }
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.081 us | ext4_get_dummy_policy();
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.133 us | ext4_get_group_desc();
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.115 us | ext4_free_inodes_count();
trace-cmd-12697 [000] 11303.928124: funcgraph_entry: 0.114 us | ext4_get_group_desc();Отслеживание определенного PID
Допустим, вы хотите отслеживать функции, связанные с определенным постоянным идентификатором (PID). Откройте другой терминал и запишите PID работающей оболочки:
# echo $$
10885Снова запустите команду record и передайте PID, используя опцию -P. На этот раз дайте терминалу поработать (т. е. пока не нажимайте Ctrl+C):
# trace-cmd record -P 10885 -p function_graph
plugin 'function_graph'
Hit Ctrl^C to stop recordingЗапустите некоторые действия в оболочке
Вернитесь к другому терминалу, где у вас была запущена оболочка с определенным PID, и запустите любую команду, например, ls, чтобы просмотреть файлы:
# ls
Temp-9b61f280-fdc1-4512-9211-5c60f764d702
tracker-extract-3-files.1000
v8-compile-cache-1000
[...]Вернитесь к терминалу, где вы включили трассировку, и нажмите Ctrl+C, чтобы остановить трассировку:
# trace-cmd record -P 10885 -p function_graph
plugin 'function_graph'
Hit Ctrl^C to stop recording
^C
CPU1 data recorded at offset=0x856000
618496 bytes in size
[...]В выводе трассировки вы можете увидеть PID и оболочку Bash слева, а связанные с ними вызовы функций — справа. Это может быть очень удобно, чтобы сузить трассировку:
# trace-cmd report | head -20
cpus=8
<idle>-0 [001] 11555.380581: funcgraph_entry: | switch_mm_irqs_off() {
<idle>-0 [001] 11555.380583: funcgraph_entry: 1.703 us | load_new_mm_cr3();
<idle>-0 [001] 11555.380586: funcgraph_entry: 0.493 us | switch_ldt();
<idle>-0 [001] 11555.380587: funcgraph_exit: 7.235 us | }
bash-10885 [001] 11555.380589: funcgraph_entry: 1.046 us | finish_task_switch.isra.0();
bash-10885 [001] 11555.380591: funcgraph_entry: | __fdget() {
bash-10885 [001] 11555.380592: funcgraph_entry: 2.036 us | __fget_light();
bash-10885 [001] 11555.380594: funcgraph_exit: 3.256 us | }
bash-10885 [001] 11555.380595: funcgraph_entry: | tty_poll() {
bash-10885 [001] 11555.380597: funcgraph_entry: | tty_ldisc_ref_wait() {
bash-10885 [001] 11555.380598: funcgraph_entry: | ldsem_down_read() {
bash-10885 [001] 11555.380598: funcgraph_entry: | __cond_resched() {Попробуйте
Эти краткие примеры показывают, как использование trace-cmd вместо базового механизма ftrace одновременно просто в использовании и богато возможностями, включая многие, которые я здесь не рассмотрел. Чтобы узнать больше и стать лучше, обратитесь к его справочной странице и попробуйте другие полезные команды.