Analyser le noyau Linux avec ftrace

Le noyau d'un système d'exploitation est l'un des logiciels les plus insaisissables. Il fonctionne toujours en arrière-plan à partir du moment où votre système est allumé. Chaque utilisateur réalise son travail informatique à l'aide du noyau, mais il n'interagit jamais directement avec lui. L'interaction avec le noyau se produit en effectuant des appels système ou en faisant effectuer ces appels au nom de l'utilisateur par diverses bibliothèques ou applications qu'ils utilisent quotidiennement.

J'ai expliqué comment tracer les appels système dans un article précédent en utilisant strace . Cependant, avec strace , votre visibilité est limitée. Il vous permet de visualiser les appels système invoqués avec des paramètres spécifiques et, une fois le travail terminé, de voir la valeur de retour ou l'état indiquant s'ils ont réussi ou échoué. Mais vous n'aviez aucune idée de ce qui s'est passé dans le noyau pendant cette période. En plus de servir des appels système, il y a beaucoup d'autres activités qui se déroulent à l'intérieur du noyau et dont vous n'avez pas conscience.

Ftrace Introduction

Plus de ressources Linux

Aide-mémoire des commandes Linux
Aide-mémoire des commandes Linux avancées
Cours en ligne gratuit :Présentation technique de RHEL
Aide-mémoire sur le réseau Linux
Aide-mémoire SELinux
Aide-mémoire sur les commandes courantes de Linux
Que sont les conteneurs Linux ?
Nos derniers articles Linux

Cet article vise à faire la lumière sur le traçage des fonctions du noyau en utilisant un mécanisme appelé ftrace . Il rend le traçage du noyau facilement accessible à tout utilisateur Linux, et avec son aide, vous pouvez en apprendre beaucoup sur les composants internes du noyau Linux.

La sortie par défaut générée par le ftrace est souvent massive, étant donné que le noyau est toujours occupé. Pour économiser de l'espace, j'ai réduit la sortie au minimum et, dans de nombreux cas, j'ai entièrement tronqué la sortie.

J'utilise Fedora pour ces exemples, mais ils devraient fonctionner sur toutes les dernières distributions Linux.

Activer ftrace

Ftrace fait désormais partie du noyau Linux et vous n'avez plus besoin d'installer quoi que ce soit pour l'utiliser. Il est probable que, si vous utilisez un système d'exploitation Linux récent, ftrace est déjà activé. Pour vérifier que le ftrace est disponible, exécutez la commande mount et recherchez tracefs . Si vous voyez une sortie similaire à ce qui est ci-dessous, ftrace est activé et vous pouvez facilement suivre les exemples de cet article. Ces commandes doivent être exécutées en tant qu'utilisateur root (sudo est insuffisant.)

# montage | grep tracefs
aucun sur /sys/kernel/tracing type tracefs (rw,relatime,seclabel)

Pour utiliser ftrace , vous devez d'abord accéder au répertoire spécial spécifié dans la commande mount ci-dessus, à partir duquel vous exécuterez le reste des commandes de l'article :

# cd /sys/kernel/tracing

Flux de travail général

Tout d'abord, vous devez comprendre le flux de travail général de capture d'une trace et d'obtention de la sortie. Si vous utilisez ftrace directement, il n'y a pas de ftrace- spécial commandes spécifiques à exécuter. Au lieu de cela, vous écrivez essentiellement dans certains fichiers et lisez certains fichiers à l'aide d'utilitaires Linux en ligne de commande standard.

Les étapes générales :

Écrire dans certains fichiers spécifiques pour activer/désactiver le traçage.
Écrivez dans certains fichiers spécifiques pour définir/désactiver des filtres afin d'affiner le traçage.
Lire la sortie de trace générée à partir des fichiers basés sur 1 et 2.
Effacer la sortie ou la mémoire tampon antérieure des fichiers.
Référez-vous à votre cas d'utilisation spécifique (fonctions du noyau à tracer) et répétez les étapes 1, 2, 3, 4.

Types de traceurs disponibles

Plusieurs types de traceurs s'offrent à vous. Comme mentionné précédemment, vous devez vous trouver dans un répertoire spécifique avant d'exécuter l'une de ces commandes car les fichiers qui vous intéressent y sont présents. J'utilise des chemins relatifs (par opposition aux chemins absolus) dans mes exemples.

Vous pouvez afficher le contenu des available_tracers fichier pour voir tous les types de traceurs disponibles. Vous pouvez en voir quelques-uns ci-dessous. Ne vous inquiétez pas pour tous pour l'instant :

# pwd
/sys/kernel/tracing

# cat available_tracers
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt fonction de réveil nop

Parmi tous les traceurs donnés, je me concentre sur trois spécifiques :function et function_graph pour activer le traçage, et nop pour désactiver le traçage.

Identifier le traceur actuel

Habituellement, par défaut, le traceur est défini sur nop . C'est-à-dire "Aucune opération" dans le fichier spécial current_tracer , ce qui signifie généralement que le traçage est actuellement désactivé :

# pwd
/sys/kernel/tracing

# cat current_tracer
nop

Afficher la sortie de traçage

Avant d'activer le traçage, examinez le fichier dans lequel la sortie du traçage est stockée. Vous pouvez afficher le contenu du fichier nommé trace en utilisant la commande cat :

# cat trace

# traceur :non
#
# entrées-dans-le-tampon/entrées-écrites :0/0   #P:8
# 
#                                _-----=> irqs-off
#                               / _----=> besoin-resched
#                                  / _---=> hardirq/softirq
#                              || / _--=> profondeur de préemption
#                              ||| /     délai
#           TASK-PID     CPU#  |||| HORODATAGE  FONCTION
#              | | | |||| | |

Activer le traceur de fonction

Vous pouvez activer votre premier traceur appelé function en écrivant function au fichier current_tracer (son contenu antérieur était nop , indiquant que le traçage était désactivé.) Considérez cette opération comme un moyen d'activer le traçage :

# pwd
/sys/kernel/tracing

# cat current_tracer
nop

# echo function> current_tracer

# cat current_tracer
fonction

Afficher la sortie de traçage mise à jour pour le traceur de fonction

Maintenant que vous avez activé le traçage, il est temps d'afficher la sortie. Si vous affichez le contenu de la trace fichier, vous voyez que beaucoup de données y sont écrites en continu. J'ai canalisé la sortie et je ne visualise actuellement que les 20 premières lignes pour que les choses restent gérables. Si vous suivez les en-têtes dans la sortie à gauche, vous pouvez voir quelle tâche et quel ID de processus s'exécutent sur quel processeur. Vers le côté droit de la sortie, vous voyez la fonction exacte du noyau en cours d'exécution, suivie de sa fonction parent. Il y a aussi des informations d'horodatage au centre :

# trace de chat sudo | head -20

# traceur :fonction
#
# entrées-dans-le-tampon/entrées-écrites :409936/4276216   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> besoin-resched
#                          / _---=> hardirq/softirq
#                              || / _--=> profondeur de préemption
#                              ||| /     délai
#           TASK-PID     CPU#  |||| HORODATAGE  FONCTION
#              | | | |||| | idle>-0       [000] d...  2088.841740 :rcu_nocb_flush_deferred_wakeup <-do_idle
          -0       [000] d...  2088.841740 :tick_check_broadcast_expired <-do_idle
    ] d...  2088.841740 :cpuidle_get_cpu_driver <-do_idle
          -0       [000] d...  2088.841740 :cpuidle_not_available <-do_idle
          -0     4 [000] d... :cpuidle_select <-do_idle
          -0       [000] d...  2088.841741 :menu_select <-do_idle
          -0       [000] d...  2088.841741 :cpuidle_governor_menu_select<-latency_req /pré> 
 N'oubliez pas que le suivi est activé, ce qui signifie que la sortie du suivi continue d'être écrite dans le fichier de suivi jusqu'à ce que vous le désactiviez.
 Désactiver le traçage
 
 Désactiver le traçage est simple. Tout ce que vous avez à faire est de remplacer function tracer avec nop dans le current_tracer le fichier et le traçage sont désactivés :
 # cat current_tracer
fonction

# echo nop>
 current_tracer

# cat current_tracer
nop
 Activer le traceur function_graph
 
 Essayez maintenant le deuxième traceur, appelé function_graph . Vous pouvez l'activer en suivant les mêmes étapes qu'auparavant :écrivez function_graph au current_tracer fichier :
 # echo function_graph> current_tracer

# cat current_tracer
function_graph
 Tracer la sortie du traceur function_graph
 
 Notez que le format de sortie de la trace fichier a changé. Maintenant, vous pouvez voir l'ID CPU et la durée d'exécution de la fonction noyau. Ensuite, vous voyez des accolades indiquant le début d'une fonction et quelles autres fonctions ont été appelées depuis l'intérieur :
 # trace de chat | head -20

# traceur :function_graph
#
# CPU  DURATION                  APPELS DE FONCTION
# | | | | | | |
 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_hung_up_p();
 6)               | mutex_lock() {
 6)               | __cond_resched() {
 6)   0,404 us    | rcu_all_qs();
 6)   1.067 us    | } Activer les paramètres de traçage pour augmenter la profondeur du traçage
 
 Vous pouvez toujours modifier légèrement le traceur pour voir plus en profondeur les appels de fonction en suivant les étapes ci-dessous. Après quoi, vous pouvez visualiser le contenu de la trace fichier et voyez que la sortie est légèrement plus détaillée. Pour des raisons de lisibilité, la sortie de cet exemple est omise :
 # cat max_graph_depth
0

# echo 1> max_graph_depth ## or :
# echo 2> max_graph_depth

# sudo cat trace Rechercher des fonctions à tracer
 
 Les étapes ci-dessus sont suffisantes pour démarrer avec le traçage. Cependant, la quantité de résultats générés est énorme et vous pouvez souvent vous perdre en essayant de trouver des éléments qui vous intéressent. Souvent, vous souhaitez pouvoir tracer uniquement des fonctions spécifiques et ignorer le reste. Mais comment savoir quels processus suivre si vous ne connaissez pas leurs noms exacts ? Il existe un fichier qui peut vous aider :available_filter_functions vous fournit une liste des fonctions disponibles pour le traçage :
 # wc -l available_filter_functions  
63165 available_filter_functions
 Rechercher les fonctions générales du noyau
 
 Essayez maintenant de rechercher une fonction simple du noyau que vous connaissez. L'espace utilisateur a malloc pour allouer de la mémoire, alors que le noyau a son kmalloc fonction, qui fournit des fonctionnalités similaires. Vous trouverez ci-dessous tous les kmalloc fonctions associées :
 # 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
[...]
 Rechercher un module de noyau ou des fonctions liées au pilote
 
 À partir de la sortie de available_filter_functions , vous pouvez voir certaines lignes se terminant par du texte entre crochets, comme [kvm_intel] dans l'exemple ci-dessous. Ces fonctions sont liées au module noyau kvm_intel , qui est actuellement chargé. Vous pouvez exécuter le lsmod commande pour vérifier :
 # 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
 Tracer uniquement les fonctions spécifiques
 
 Pour activer le traçage de fonctions ou de modèles spécifiques, vous pouvez utiliser le set_ftrace_filter fichier pour spécifier les fonctions de la sortie ci-dessus que vous souhaitez tracer.

Ce fichier accepte également le * pattern, qui se développe pour inclure des fonctions supplémentaires avec le modèle donné. Par exemple, j'utilise le ext4 système de fichiers sur ma machine. Je peux spécifier ext4 fonctions spécifiques du noyau à tracer à l'aide des commandes suivantes :
 # montage | grep home
/dev/mapper/fedora-home sur /home type ext4 (rw,relatime,seclabel)

# pwd
/sys/kernel/tracing
 
# cat set_ftrace_filter

#### toutes les fonctions activées ####
$
$ 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
[...]
 
 Maintenant, lorsque vous voyez la sortie de traçage, vous ne pouvez voir que les fonctions ext4 liées aux fonctions du noyau pour lesquelles vous aviez précédemment défini un filtre. Toutes les autres sorties sont ignorées :
 # cat trace |head -20

## traceur :fonction
#
# entrées-dans-le-tampon/entrées-écrites :3871/3871   #P:8 
#
#                             _-----=> irqs-off
#                               / _----=> besoin-resched
#                    / _---=> hardirq/softirq
#                              || / _--=> profondeur de préemption
#                              ||| /     délai
#           TASK-PID     CPU#  |||| HORODATAGE  FONCTION
#              | | | |||| | | 
 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
 Exclure les fonctions du suivi
 
 Vous ne savez pas toujours ce que vous voulez tracer mais, vous savez sûrement ce que vous ne voulez pas tracer. Pour cela, il y a ce fichier bien nommé set_ftrace_notrace -remarquez le "non" là-dedans. Vous pouvez écrire le modèle souhaité dans ce fichier et activer le traçage, sur lequel tout sauf le modèle mentionné est tracé. Cela est souvent utile pour supprimer les fonctionnalités courantes qui encombrent notre sortie :
 # cat set_ftrace_notrace
#### aucune fonction désactivée ####
 Suivi ciblé
 
 Jusqu'à présent, vous avez suivi tout ce qui s'est passé dans le noyau. Mais cela ne nous aidera pas si vous souhaitez tracer des événements liés à une commande spécifique. Pour ce faire, vous pouvez activer et désactiver le traçage à la demande et, entre eux, exécuter la commande de votre choix afin de ne pas obtenir de sortie supplémentaire dans votre sortie de trace. Vous pouvez activer le traçage en écrivant 1 à tracing_on , et 0 pour le désactiver :
 # cat tracing_on
0

# echo 1> tracing_on

# cat tracing_on
1

## # Exécutez une commande spécifique que nous souhaitons tracer ici ###

# echo 0> tracing_on

# cat tracing_on
0
 Tracer un PID spécifique
 
 Si vous souhaitez suivre l'activité liée à un processus spécifique déjà en cours d'exécution, vous pouvez écrire ce PID dans un fichier nommé set_ftrace_pid puis activez le traçage. De cette façon, le traçage est limité à ce PID uniquement, ce qui est très utile dans certains cas :
 # echo $PID > set_ftrace_pid 
 Conclusion
 
 Ftrace est un excellent moyen d'en savoir plus sur le fonctionnement interne du noyau Linux. Avec un peu de pratique, vous pouvez apprendre à affiner ftrace et affinez vos recherches. Pour comprendre ftrace plus en détail et son utilisation avancée, voir ces excellents articles écrits par l'auteur principal de ftrace lui-même—Steven Rostedt.
  Débogage du noyau Linux, partie 1
 Débogage du noyau Linux, partie 2
 Débogage du noyau Linux, partie 3