GNU/Linux >> Tutoriales Linux >  >> Linux

Seguimiento del kernel con trace-cmd

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

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.


Linux
  1. Parchear un binario con Dd?

  2. ¿Bloqueando las actualizaciones del kernel con Dpkg?

  3. ¿Error al cargar el módulo Btusb con Kernel 4.10.0-20-generic?

  4. Cómo escribir su propio módulo kernel de Linux con un ejemplo simple

  5. ¿Cómo construir un módulo del kernel de Linux para que sea compatible con todas las versiones del kernel?

Núcleo de Linux vs. Núcleo de Mac

Administre y monitoree los módulos del kernel de Linux con Kmon

¡Parche el kernel Linux de Raspberry Pi con KernelCare GRATIS!

Mostrar información del módulo del kernel de Linux con el comando Modinfo

¿Sistema Linux congelado? Aquí hay 3 formas de lidiar con eso

Linux Centos con marca de tiempo dmesg