En mi artículo anterior, expliqué cómo usar ftrace
para rastrear las funciones del núcleo. Usando ftrace
escribir y leer archivos puede volverse tedioso, así que usé un contenedor para ejecutar comandos con opciones para habilitar y deshabilitar el seguimiento, configurar filtros, ver resultados, borrar resultados y más.
El comando trace-cmd es una utilidad que lo ayuda a hacer precisamente esto. En este artículo, uso trace-cmd
para realizar las mismas tareas que hice en mi ftrace
artículo. Dado que vuelvo a consultar ese artículo con frecuencia, le recomiendo que lo lea antes de leer este.
Instalar trace-cmd
Ejecuto los comandos de este artículo como usuario root.
El ftrace
El mecanismo está integrado en el kernel y puede verificar que está habilitado con:
# mount | grep tracefs
none on /sys/kernel/tracing type tracefs (rw,relatime,seclabel)
Sin embargo, debe instalar el trace-cmd
utilidad manualmente.
# dnf install trace-cmd -y
Lista de trazadores disponibles
Al usar ftrace
, debe ver el contenido de un archivo para ver qué rastreadores están disponibles. Pero con trace-cmd
, puede obtener esta información con:
# trace-cmd list -t
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
Habilitar el rastreador de funciones
En mi artículo anterior, usé dos marcadores y haré lo mismo aquí. Habilite su primer rastreador, function
, con:
$ trace-cmd start -p function
plugin 'function'
Ver el resultado del seguimiento
Una vez que el rastreador está habilitado, puede ver la salida usando el show
argumentos Esto muestra solo las primeras 20 líneas para que el ejemplo sea breve (consulte mi artículo anterior para obtener una explicación del resultado):
# 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
Detener el rastreo y borrar el búfer
El seguimiento continúa ejecutándose en segundo plano y puede seguir viendo el resultado usando show
.
Para detener el seguimiento, ejecute trace-cmd
con el stop
argumento:
# trace-cmd stop
Para borrar el búfer, ejecútelo con clear
argumento:
# trace-cmd clear
Habilitar el rastreador de function_graph
Habilite el segundo rastreador, function_graph
, ejecutando:
# trace-cmd start -p function_graph
plugin 'function_graph'
Una vez más, vea la salida usando show
argumento. Como era de esperar, la salida es ligeramente diferente de la salida de la primera traza. Esta vez incluye una function calls
cadena:
# 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() {
Usa el stop
y clear
Comandos para detener el seguimiento y borrar el búfer:
# trace-cmd stop
# trace-cmd clear
Modificar rastreo para aumentar la profundidad
Si desea ver más profundidad en las llamadas a funciones, puede modificar el rastreador:
# trace-cmd start -p function_graph --max-graph-depth 5
plugin 'function_graph'
Ahora, cuando compare este resultado con lo que vio antes, debería ver más llamadas a funciones anidadas:
# 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() {
Aprender funciones disponibles para rastrear
Si desea rastrear solo ciertas funciones e ignorar el resto, necesita saber los nombres exactos de las funciones. Puedes conseguirlos con la list
argumento seguido de -f
. Este ejemplo busca la función común del núcleo kmalloc
, que se utiliza para asignar memoria en el kernel:
# 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
[...]
Este es el recuento total de funciones disponibles en mi sistema de prueba:
# trace-cmd list -f | wc -l
63165
Rastrear funciones relacionadas con el módulo del kernel
También puede rastrear funciones relacionadas con un módulo de kernel específico. Imagina que quieres rastrear kvm
funciones relacionadas con el módulo del núcleo. Asegúrese de que el módulo esté cargado:
# lsmod | grep kvm_intel
kvm_intel 335872 0
kvm 987136 1 kvm_intel
Ejecute trace-cmd
de nuevo con la list
argumento, y de la salida, grep
para líneas que terminan en ]
. Esto filtrará los módulos del kernel. Entonces grep
el módulo del núcleo kvm_intel
, y debería ver todas las funciones relacionadas con ese módulo del kernel:
# 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]
Más recursos de Linux
- Hoja de trucos de los comandos de Linux
- Hoja de trucos de comandos avanzados de Linux
- Curso en línea gratuito:Descripción general técnica de RHEL
- Hoja de trucos de red de Linux
- Hoja de trucos de SELinux
- Hoja de trucos de los comandos comunes de Linux
- ¿Qué son los contenedores de Linux?
- Nuestros últimos artículos sobre Linux
Funciones específicas de seguimiento
Ahora que sabe cómo encontrar funciones de interés, ponga ese conocimiento a trabajar con un ejemplo. Como en el artículo anterior, intente rastrear las funciones relacionadas con el sistema de archivos. El sistema de archivos que tenía en mi sistema de prueba era ext4
.
Este procedimiento es ligeramente diferente; en lugar de start
, ejecuta el comando con el record
argumento seguido del "patrón" de las funciones que desea rastrear. También debe especificar el rastreador que desea; en este caso, eso es function_graph
. El comando continúa registrando la traza hasta que lo detengas con Ctrl+C . Luego de unos segundos, presiona Ctrl+C para dejar de rastrear:
# 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
[...]
Ver el seguimiento registrado
Para ver el seguimiento que registró anteriormente, ejecute el comando con el report
argumento. De la salida, está claro que el filtro funcionó, y solo ve el seguimiento de la función relacionada con 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();
Rastrear un PID específico
Digamos que desea rastrear funciones relacionadas con un identificador persistente (PID) específico. Abra otra terminal y observe el PID del shell en ejecución:
# echo $$
10885
Ejecute el record
comando de nuevo y pasar el PID usando el -P
opción. Esta vez, deje que la terminal se ejecute (es decir, no presione Ctrl+C todavía):
# trace-cmd record -P 10885 -p function_graph
plugin 'function_graph'
Hit Ctrl^C to stop recording
Ejecutar alguna actividad en el shell
Regrese a la otra terminal donde tenía un shell ejecutándose con un PID específico y ejecute cualquier comando, por ejemplo, ls
para listar archivos:
# ls
Temp-9b61f280-fdc1-4512-9211-5c60f764d702
tracker-extract-3-files.1000
v8-compile-cache-1000
[...]
Regrese a la terminal donde habilitó el rastreo y presione Ctrl+C para dejar de rastrear:
# 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
[...]
En la salida de la traza, puede ver el PID y el shell Bash a la izquierda y las llamadas a funciones relacionadas con él a la derecha. Esto puede ser muy útil para reducir el rastreo:
# 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() {
Pruébalo
Estos breves ejemplos muestran cómo usar trace-cmd
en lugar del ftrace
subyacente El mecanismo es fácil de usar y rico en funciones, incluidas muchas que no cubrí aquí. Para obtener más información y mejorar, consulte su página de manual y pruebe sus otros comandos útiles.