Analizar el kernel de Linux con ftrace

El núcleo de un sistema operativo es una de las piezas de software más escurridizas que existen. Siempre está ejecutándose en segundo plano desde el momento en que se enciende el sistema. Todos los usuarios logran su trabajo informático con la ayuda del núcleo, pero nunca interactúan con él directamente. La interacción con el núcleo ocurre al hacer llamadas al sistema o hacer que esas llamadas sean hechas en nombre del usuario por varias bibliotecas o aplicaciones que usan diariamente.

He cubierto cómo rastrear llamadas al sistema en un artículo anterior usando strace . Sin embargo, con strace , su visibilidad es limitada. Le permite ver las llamadas al sistema invocadas con parámetros específicos y, una vez que se realiza el trabajo, ver el valor de retorno o el estado que indica si pasaron o fallaron. Pero no tenía idea de lo que sucedió dentro del kernel durante este tiempo. Además de atender las llamadas del sistema, hay muchas otras actividades dentro del kernel de las que no se da cuenta.

Introducción a Ftrace

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

Este artículo tiene como objetivo arrojar algo de luz sobre el seguimiento de las funciones del kernel mediante el uso de un mecanismo llamado ftrace . Hace que el seguimiento del kernel sea fácilmente accesible para cualquier usuario de Linux y, con su ayuda, puede aprender mucho sobre las funciones internas del kernel de Linux.

La salida predeterminada generada por ftrace suele ser masivo, dado que el núcleo siempre está ocupado. Para ahorrar espacio, mantuve la salida al mínimo y, en muchos casos, la trunqué por completo.

Estoy usando Fedora para estos ejemplos, pero deberían funcionar en cualquiera de las últimas distribuciones de Linux.

Habilitación de seguimiento

Ftrace ahora es parte del kernel de Linux, y ya no necesita instalar nada para usarlo. Es probable que, si utiliza un sistema operativo Linux reciente, ftrace ya está habilitado. Para verificar que ftrace la instalación está disponible, ejecute el comando de montaje y busque tracefs . Si ve un resultado similar al que se muestra a continuación, ftrace está habilitado, y puede seguir fácilmente los ejemplos de este artículo. Estos comandos deben ejecutarse como usuario raíz (sudo es insuficiente.)

# montaje | grep tracefs
ninguno en /sys/kernel/tracing escriba tracefs (rw,relatime,seclabel)

Para hacer uso de ftrace , primero debe navegar al directorio especial como se especifica en el comando de montaje anterior, desde donde ejecutará el resto de los comandos del artículo:

# cd /sys/kernel/tracing 

Flujo de trabajo general

En primer lugar, debe comprender el flujo de trabajo general de capturar un seguimiento y obtener el resultado. Si está utilizando ftrace directamente, no hay ningún ftrace- especial comandos específicos para ejecutar. En su lugar, básicamente escribe en algunos archivos y lee de algunos archivos usando las utilidades estándar de línea de comandos de Linux.

Los pasos generales:

1. Escriba en algunos archivos específicos para habilitar o deshabilitar el seguimiento.
2. Escriba en algunos archivos específicos para configurar/desactivar filtros para ajustar el seguimiento.
3. Lea la salida de seguimiento generada a partir de archivos basados ​​en 1 y 2.
4. Borrar la salida anterior o el búfer de los archivos.
5. Limítese a su caso de uso específico (funciones del kernel para rastrear) y repita los pasos 1, 2, 3, 4.

Tipos de trazadores disponibles

Hay varios tipos diferentes de marcadores disponibles para usted. Como se mencionó anteriormente, debe estar en un directorio específico antes de ejecutar cualquiera de estos comandos porque los archivos de interés están presentes allí. Uso rutas relativas (en lugar de rutas absolutas) en mis ejemplos.

Puede ver el contenido de los available_tracers archivo para ver todos los tipos de trazadores disponibles. Puede ver algunos enumerados a continuación. No te preocupes por todos ellos todavía:

# pwd
/sys/kernel/tracing

# cat available_tracers
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt función de activación nop

De todos los rastreadores dados, me concentro en tres específicos:function y function_graph para habilitar el seguimiento y nop para deshabilitar el rastreo.

Identificar trazador actual

Por lo general, de forma predeterminada, el rastreador se establece en nop . Es decir, "Sin operación" en el archivo especial current_tracer , lo que normalmente significa que el seguimiento está actualmente desactivado:

# pwd
/sys/kernel/tracing

# cat current_tracer
nop

Ver salida de seguimiento

Antes de habilitar cualquier seguimiento, eche un vistazo al archivo donde se almacena el resultado del seguimiento. Puede ver el contenido del archivo llamado trace usando el comando cat:

#cat trace

# rastreador:nop
#
#entradas-en-búfer/entradas-escritas:0/0   #P:8
# 
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                                   | / __---=> hardirq/softirq
#                              || / _--=> profundidad de preferencia
#                              ||| /     retraso
#           TASK-PID     CPU#  |||| FUNCIÓN DE MARCA DE TIEMPO
#              | | | |||| | |

Habilitar rastreador de funciones

Puede habilitar su primer rastreador llamado function escribiendo function al archivo current_tracer (su contenido anterior era nop , lo que indica que el seguimiento estaba desactivado). Piense en esta operación como una forma de habilitar el seguimiento:

# pwd
/sys/kernel/tracing

# cat current_tracer
nop

# función de eco> current_tracer

# cat current_tracer
función

Ver resultados de seguimiento actualizados para el rastreador de funciones

Ahora que ha habilitado el seguimiento, es hora de ver el resultado. Si ve el contenido del trace archivo, verá que se escriben muchos datos en él continuamente. He canalizado la salida y actualmente estoy viendo solo las 20 líneas principales para mantener las cosas manejables. Si sigue los encabezados en la salida de la izquierda, puede ver qué tarea e ID de proceso se están ejecutando en qué CPU. Hacia el lado derecho de la salida, verá la función del núcleo exacta en ejecución, seguida de su función principal. También hay información de marca de tiempo en el centro:

# rastreo de sudo cat | head -20

# rastreador:función
#
# entradas-en-búfer/entradas-escritas:409936/4276216   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                         | / __---=> hardirq/softirq
#                              || / _--=> profundidad de preferencia
#                              ||| /     retraso
#           TASK-PID     CPU#  |||| FUNCIÓN DE MARCA DE TIEMPO
#              | | | |||| | |
          -0       [000] d...  2088.841739:tsc_verify_tsc_adjust <-arch_cpu_idle_enter
          -0       [000] d...  2088.841739:local_touch_idle 
 inactivo>-0       [000] d...  2088.841740:rcu_nocb_flush_deferred_wakeup <-do_idle
          -0       [000] d...  2088.841740:tick_check_broadcast_expired <-do_idle
          -0       [000] d...  2088.841740:cpuidle_not_disponible <-do_idle
          -0       4 8.08 :cpuidle_select <-do_idle
          -0       [000] d...  2088.841741:menu_select <-do_idle
          -0       [000] d...  2088.841741:c_idlemen_governor <-idlemen_governor /pre> 

 Recuerde que el seguimiento está activado, lo que significa que la salida del seguimiento continúa escribiéndose en el archivo de seguimiento hasta que desactive el seguimiento.
 
Desactivar seguimiento
 

 Desactivar el rastreo es simple. Todo lo que tienes que hacer es reemplazar function rastreador con nop en el current_tracer el archivo y el seguimiento se desactivan:
 
# cat current_tracer
función

# echo nop>
 current_tracer

# cat current_tracer
nop
 
Habilitar rastreador de función_gráfico
 

 Ahora pruebe el segundo rastreador, llamado function_graph . Puede habilitar esto siguiendo los mismos pasos que antes:escriba function_graph al current_tracer archivo:
 
# echo function_graph> current_tracer

# cat current_tracer
function_graph
 
Seguimiento de la salida de function_graph tracer
 

 Tenga en cuenta que el formato de salida del trace el archivo ha cambiado. Ahora, puede ver la ID de la CPU y la duración de la ejecución de la función del kernel. A continuación, verá llaves que indican el comienzo de una función y qué otras funciones se llamaron desde dentro:
 
# rastreo de gato | head -20

# rastreador:function_graph
#
# CPU  DURATION                  LLAMADAS A FUNCIÓN
# | | | | | | |
 6)               | n_tty_write() {
 6)               | down_read() {
 6)               | __cond_resched() {
 6)   0.341 us    | rcu_all_qs();
 6)   1.057 us    | }
 6)   1.807 us    | }
 6)   0,402 us    | process_echoes();
 6)               | add_wait_queue() {
 6)   0.391 us    | _raw_spin_lock_irqsave();
 6)   0,359 us    | _raw_spin_unlock_irqrestore();
 6)   1.757 us    | }
 6)   0,350 us    | tty_colgado_p();
 6)               | mutex_lock() {
 6)               | __cond_resched() {
 6)   0,404 us    | rcu_all_qs();
 6)   1.067 us    | }
 
Habilite la configuración de rastreo para aumentar la profundidad del rastreo
 

 Siempre puede modificar el rastreador ligeramente para ver más profundidad de las llamadas a funciones siguiendo los pasos a continuación. Después de lo cual, puede ver el contenido del trace archivo y vea que la salida es un poco más detallada. Para facilitar la lectura, se omite el resultado de este ejemplo:
 
# cat max_graph_ depth
0

# echo 1> max_graph_ depth ## o:
# echo 2> max_graph_ depth

# sudo cat trace
 
Encontrar funciones para rastrear
 

 Los pasos anteriores son suficientes para comenzar con el rastreo. Sin embargo, la cantidad de salida generada es enorme y, a menudo, puede perderse al tratar de encontrar elementos de interés. A menudo, desea tener la capacidad de rastrear solo funciones específicas e ignorar el resto. Pero, ¿cómo sabe qué procesos rastrear si no sabe sus nombres exactos? Hay un archivo que puede ayudarte con esto:available_filter_functions le proporciona una lista de funciones disponibles para el rastreo:
 
# wc -l funciones_de_filtro_disponibles  
63165 funciones_de_filtro_disponibles
 
Buscar funciones generales del kernel
 

 Ahora intente buscar una función de kernel simple que conozca. El espacio de usuario tiene malloc para asignar memoria, mientras que el kernel tiene su kmalloc función, que proporciona una funcionalidad similar. A continuación se muestran todos los kmalloc funciones relacionadas:
 
# grep kmalloc available_filter_functions
debug_kmalloc
mempool_kmalloc
kmalloc_slab
kmalloc_order
kmalloc_order_trace
kmalloc_fix_flags
kmalloc_large_node
__kmalloc
__kmalloc_track_caller
__kmalloc_node
__kmalloc_node_track_caller
[...]
 
Buscar funciones relacionadas con el controlador o el módulo del kernel
 

 De la salida de available_filter_functions , puede ver algunas líneas que terminan con texto entre corchetes, como [kvm_intel] en el ejemplo siguiente. Estas funciones están relacionadas con el módulo del núcleo kvm_intel , que está cargado actualmente. Puede ejecutar lsmod comando para verificar:
 
# grep kvm available_filter_functions | tail
__pi_post_block [kvm_intel]
vmx_vcpu_pi_load [kvm_intel]
vmx_vcpu_pi_put [kvm_intel]
pi_pre_block [kvm_intel]
pi_post_block [kvm_intel]
pi_wakeup_handler [kvm_intel]
pi_has_pending_interrupt [kvm_intel]
pi_update_irte [kvm_intel]
vmx_dump_dtsel [kvm_intel]
vmx_dump_sel [kvm_intel]

# lsmod  | grep -i kvm
kvm_intel             335872  0
kvm                   987136  1 kvm_intel
irqbypass              16384  1 kvm
 
Rastrear solo funciones específicas
 

 Para habilitar el seguimiento de funciones o patrones específicos, puede utilizar set_ftrace_filter para especificar qué funciones de la salida anterior desea rastrear.

Este archivo también acepta el * patrón, que se expande para incluir funciones adicionales con el patrón dado. Como ejemplo, estoy usando ext4 sistema de archivos en mi máquina. Puedo especificar ext4 funciones específicas del kernel para rastrear usando los siguientes comandos:
 
# montaje | grep home
/dev/mapper/fedora-home on /home type ext4 (rw,relatime,seclabel)

# pwd
/sys/kernel/tracing
 
# cat set_ftrace_filter

#### todas las funciones habilitadas ####
$
$ echo ext4_*> set_ftrace_filter
$
 $ cat set_ftrace_filter
ext4_has_free_clusters
ext4_validate_block_bitmap
ext4_get_group_number
ext4_get_group_no_and_offset
ext4_get_group_desc
[...]
 

 Ahora, cuando vea la salida de seguimiento, solo podrá ver las funciones ext4 relacionado con las funciones del núcleo para las que había establecido un filtro anteriormente. Todos los demás resultados se ignoran:
 
# cat trace |head -20

## rastreador:función
#
# entradas-en-búfer/entradas-escritas:3871/3871   #P:8 / __---=> hardirq/softirq
#                              || / _--=> profundidad de preferencia
#                              ||| /     retraso
#           TASK-PID     CPU#  |||| FUNCIÓN DE MARCA DE TIEMPO
#              | | | |||| | 
 CUPSD-1066 [004] .... 3308.989545:ext4_file_getattr <-vfs_fstat 
 CUPSD-1066 [004] ... 3308.989547:ext4_getattr <-ext4_file_getattr 
 CUPSD-1066 [004 ] .... 3308.989552:ext4_file_getattr <-vfs_fstat 
 CUPSD-1066 [004] .... 3308.989553:ext4_getattr <-ext4_file_getattr 
 CUPSD-1066 [004] ... 3308.990097:ext4_file_open <- do_dentry_open 
 CUPSD-1066 [004] .... 3308.990111:ext4_file_getattr <-vfs_fstat 
 CUPSD-1066 [004] ... 3308.990111:ext4_getattr <-ext4_file_getattr 
 CUPSD-1066 [004 ] ....  3308.990122:ext4_llseek <-ksys_lseek
           cupsd-1066    [004] ....  3308.990130:ext4_file_read_iter <-new_sync_read
 
Excluir funciones del seguimiento
 

 No siempre sabes lo que quieres rastrear, pero seguramente sabes lo que no quieres rastrear. Para eso, existe este archivo llamado acertadamente set_ftrace_notrace —Fíjate en el "no" ahí. Puede escribir su patrón deseado en este archivo y habilitar el rastreo, sobre el cual se rastrea todo excepto el patrón mencionado. Esto suele ser útil para eliminar funciones comunes que saturan nuestra salida:
 
# cat set_ftrace_notrace
#### ninguna función deshabilitada ####
 
Rastreo dirigido
 

 Hasta ahora, ha estado rastreando todo lo que ha sucedido en el kernel. Pero eso no nos ayudará si desea rastrear eventos relacionados con un comando específico. Para lograr esto, puede activar y desactivar el seguimiento a pedido y, entre ellos, ejecutar nuestro comando de elección para que no obtenga resultados adicionales en su salida de seguimiento. Puede habilitar el rastreo escribiendo 1 a tracing_on y 0 para apagarlo:
 
# seguimiento de gato_en
0

# eco 1> seguimiento_en

# seguimiento de gato_en
1

## # Ejecute algún comando específico que deseemos rastrear aquí ###

# echo 0> tracing_on

# cat tracing_on
0
 
Rastreo de PID específico
 

 Si desea rastrear la actividad relacionada con un proceso específico que ya se está ejecutando, puede escribir ese PID en un archivo llamado set_ftrace_pid y luego habilite el rastreo. De esa forma, el rastreo se limita solo a este PID, lo que es muy útil en algunos casos:
 
# echo $PID > set_ftrace_pid 
 
Conclusión
 

 Ftrace es una excelente manera de aprender más sobre el funcionamiento interno del kernel de Linux. Con un poco de práctica, puedes aprender a ajustar ftrace y reduce tus búsquedas. Para entender ftrace con más detalle y su uso avanzado, vea estos excelentes artículos escritos por el autor principal de ftrace él mismo:Steven Rostedt.
 
 
Depuración del kernel de Linux, parte 1
 
Depuración del kernel de Linux, parte 2
 
Depuración del kernel de Linux, parte 3