Cette page a été traduite par l'API Cloud Translation.

Utiliser ftrace

ftrace est un outil de débogage permettant de comprendre ce qui se passe dans le noyau Linux. Les sections suivantes détaillent les fonctionnalités de base de ftrace, l'utilisation de ftrace avec atrace (qui capture les événements du noyau) et ftrace dynamique.

Pour plus de détails sur les fonctionnalités avancées de ftrace qui ne sont pas disponibles depuis systrace, reportez-vous à la documentation de ftrace à l' <kernel tree>/Documentation/trace/ftrace.txt .

Capturer les événements du noyau avec atrace

atrace ( frameworks/native/cmds/atrace ) utilise ftrace pour capturer les événements du noyau. À son tour, systrace.py (ou run_systrace.py dans les versions ultérieures de Catapult ) utilise adb pour exécuter atrace sur l'appareil. atrace effectue les opérations suivantes :

Configure le traçage en mode utilisateur en définissant une propriété ( debug.atrace.tags.enableflags ).
Active la fonctionnalité ftrace souhaitée en écrivant sur les nœuds ftrace sysfs appropriés. Cependant, comme ftrace prend en charge davantage de fonctionnalités, vous pouvez définir vous-même certains nœuds sysfs, puis utiliser atrace.

À l’exception du suivi au démarrage, utilisez atrace pour définir la propriété sur la valeur appropriée. La propriété est un masque de bits et il n'existe aucun bon moyen de déterminer les valeurs correctes autre que de regarder l'en-tête approprié (qui peut changer entre les versions d'Android).

Activation des événements ftace

Les nœuds ftrace sysfs se trouvent dans /sys/kernel/tracing et les événements de trace sont divisés en catégories dans /sys/kernel/tracing/events .

Pour activer les événements par catégorie, utilisez :

echo 1 > /sys/kernel/tracing/events/irq/enable

Pour activer les événements événement par événement, utilisez :

echo 1 > /sys/kernel/tracing/events/sched/sched_wakeup/enable

Si des événements supplémentaires ont été activés en écrivant sur les nœuds sysfs, ils ne seront pas réinitialisés par atrace. Un modèle courant pour l'affichage des appareils Qualcomm consiste à activer les points de trace kgsl (GPU) et mdss (pipeline d'affichage), puis à utiliser atrace ou systrace :

adb shell "echo 1 > /sys/kernel/tracing/events/mdss/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/kgsl/enable"
./systrace.py sched freq idle am wm gfx view binder_driver irq workq ss sync -t 10 -b 96000 -o full_trace.html

Vous pouvez également utiliser ftrace sans atrace ou systrace, ce qui est utile lorsque vous souhaitez des traces uniquement sur le noyau (ou si vous avez pris le temps d'écrire manuellement la propriété de traçage en mode utilisateur). Pour exécuter simplement ftace :

Définissez la taille du tampon sur une valeur suffisamment grande pour votre trace :
```
echo 96000 > /sys/kernel/tracing/buffer_size_kb
```

Activer le traçage :

echo 1 > /sys/kernel/tracing/tracing_on

Exécutez votre test, puis désactivez le traçage :
```
echo 0 > /sys/kernel/tracing/tracing_on
```

Vider la trace :

cat /sys/kernel/tracing/trace > /data/local/tmp/trace_output

Le trace_output donne la trace sous forme de texte. Pour le visualiser à l'aide de Catapult, récupérez le référentiel Catapult depuis GitHub et exécutez trace2html :

catapult/tracing/bin/trace2html ~/path/to/trace_file

Par défaut, cela écrit trace_file.html dans le même répertoire.

Événements corrélés

Il est souvent utile de consulter simultanément la visualisation Catapult et le journal des traces ; par exemple, certains événements ftrace (en particulier ceux spécifiques au fournisseur) ne sont pas visualisés par Catapult. Cependant, les horodatages de Catapult sont relatifs soit au premier événement de la trace, soit à un horodatage spécifique vidé par atrace, tandis que les horodatages bruts de la trace sont basés sur une source d'horloge absolue particulière dans le noyau Linux.

Pour rechercher un événement ftrace donné à partir d'un événement Catapult :

Ouvrez le journal des traces brutes. Les traces dans les versions récentes de systrace sont compressées par défaut :
- Si vous avez capturé votre systrace avec --no-compress , cela se trouve dans le fichier html dans la section commençant par BEGIN TRACE.
- Sinon, exécutez html2trace à partir de l' arborescence Catapult ( tracing/bin/html2trace ) pour décompresser la trace.
Recherchez l'horodatage relatif dans la visualisation Catapult.
Recherchez une ligne au début de la trace contenant tracing_mark_sync . Cela devrait ressembler à ceci :
```
<5134>-5134  (-----) [003] ...1    68.104349: tracing_mark_write: trace_event_clock_sync: parent_ts=68.104286
```
Si cette ligne n'existe pas (ou si vous avez utilisé ftrace sans atrace), alors les timings seront relatifs à partir du premier événement du journal ftrace.
1. Ajoutez l'horodatage relatif (en millisecondes) à la valeur dans parent_ts (en secondes).
2. Recherchez le nouvel horodatage.

Ces étapes devraient vous mettre à (ou du moins très près) de l'événement.

Utiliser une trace dynamique

Lorsque systrace et ftrace standard sont insuffisants, il existe un dernier recours : le ftrace dynamique . Le ftrace dynamique implique la réécriture du code du noyau après le démarrage et, par conséquent, n'est pas disponible dans les noyaux de production pour des raisons de sécurité. Cependant, chaque bug de performances difficile en 2015 et 2016 était finalement dû à l'utilisation de ftrace dynamique. Il est particulièrement puissant pour déboguer les mises en veille ininterrompues, car vous pouvez obtenir une trace de pile dans le noyau chaque fois que vous appuyez sur la fonction déclenchant la mise en veille ininterrompue. Vous pouvez également déboguer les sections avec les interruptions et les préemptions désactivées, ce qui peut être très utile pour prouver les problèmes.

Pour activer la trace dynamique, modifiez le fichier defconfig de votre noyau :

Supprimez CONFIG_STRICT_MEMORY_RWX (s'il est présent). Si vous utilisez la version 3.18 ou plus récente et arm64, ce n'est pas là.
Ajoutez les éléments suivants : CONFIG_DYNAMIC_FTRACE=y, CONFIG_FUNCTION_TRACER=y, CONFIG_IRQSOFF_TRACER=y, CONFIG_FUNCTION_PROFILER=y et CONFIG_PREEMPT_TRACER=y
Reconstruisez et démarrez le nouveau noyau.
Exécutez la commande suivante pour vérifier les traceurs disponibles :
```
cat /sys/kernel/tracing/available_tracers
```
Confirmez que la commande renvoie function , irqsoff , preemptoff et preemptirqsoff .

Exécutez la commande suivante pour vous assurer que la trace dynamique fonctionne :

cat /sys/kernel/tracing/available_filter_functions | grep <a function you care about>

Après avoir terminé ces étapes, vous disposez de ftrace dynamique, du profileur de fonctions, du profileur irqsoff et du profileur préemptif. Nous vous recommandons fortement de lire la documentation ftrace sur ces sujets avant de les utiliser car ils sont puissants mais complexes. irqsoff et preemptoff sont principalement utiles pour confirmer que les pilotes peuvent laisser les interruptions ou la préemption désactivées trop longtemps.

Le profileur de fonctions est la meilleure option pour les problèmes de performances et est souvent utilisé pour savoir où une fonction est appelée.

Afficher le problème : photo HDR + viseur rotatif

Dans ce problème, l'utilisation d'un Pixel XL pour prendre une photo HDR+, puis la rotation immédiate du viseur provoquait des problèmes à chaque fois. Nous avons utilisé le profileur de fonctions pour déboguer le problème en moins d'une heure. Pour suivre l'exemple, téléchargez le fichier zip des traces (qui inclut également d'autres traces mentionnées dans cette section), décompressez le fichier et ouvrez le fichier trace_30898724.html dans votre navigateur.

La trace montre plusieurs threads dans le processus cameraserver bloqués en veille ininterrompue sur ion_client_destroy . C'est une fonction coûteuse, mais elle devrait être appelée très rarement car les clients ioniques doivent englober de nombreuses allocations. Initialement, la faute revenait au code Hexagon d'Halide, qui était effectivement l'un des coupables (il créait un nouveau client pour chaque allocation d'ions et détruisait ce client lorsque l'allocation était libérée, ce qui était bien trop cher). Le passage à un seul client ionique pour toutes les allocations Hexagon a amélioré la situation, mais le problème n'a pas été corrigé.

À ce stade, nous devons savoir qui appelle ion_client_destroy , il est donc temps d'utiliser le profileur de fonctions :

Comme les fonctions sont parfois renommées par le compilateur, confirmez ion_client_destroy est là en utilisant :
```
cat /sys/kernel/tracing/available_filter_functions | grep ion_client_destroy
```
Après avoir confirmé qu'il est là, utilisez-le comme filtre de trace :
```
echo ion_client_destroy > /sys/kernel/tracing/set_ftrace_filter
```

Activez le profileur de fonctions :

echo function > /sys/kernel/tracing/current_tracer

Activez les traces de pile chaque fois qu'une fonction de filtre est appelée :
```
echo func_stack_trace > /sys/kernel/tracing/trace_options
```

Augmentez la taille du tampon :

echo 64000 > /sys/kernel/tracing/buffer_size_kb

Activer le traçage :
```
echo 1 > /sys/kernel/tracing/trace_on
```

Exécutez le test et obtenez la trace :

cat /sys/kernel/tracing/trace > /data/local/tmp/trace

Affichez la trace pour voir de nombreuses traces de pile :

    cameraserver-643   [003] ...1    94.192991: ion_client_destroy <-ion_release
    cameraserver-643   [003] ...1    94.192997: <stack trace>
 => ftrace_ops_no_ops
 => ftrace_graph_call
 => ion_client_destroy
 => ion_release
 => __fput
 => ____fput
 => task_work_run
 => do_notify_resume
 => work_pending

Sur la base de l'inspection du pilote ion, nous pouvons voir que ion_client_destroy est spammé par une fonction d'espace utilisateur fermant un fd à /dev/ion , et non par un pilote de noyau aléatoire. En recherchant \"/dev/ion\" dans la base de code Android, nous trouvons plusieurs pilotes de fournisseurs faisant la même chose que le pilote Hexagon et ouvrant/fermant /dev/ion (créant et détruisant un nouveau client ion) à chaque fois qu'ils ont besoin d'un nouvelle allocation d'ions. Les modifier pour utiliser un seul client ionique pendant toute la durée de vie du processus a corrigé le bug.

Si les données du profileur de fonctions ne sont pas suffisamment spécifiques, vous pouvez combiner les points de trace ftrace avec le profileur de fonctions. Les événements ftrace peuvent être activés exactement de la même manière que d'habitude, et ils seront entrelacés avec votre trace. C'est très bien s'il y a une longue veille ininterrompue occasionnelle dans une fonction spécifique que vous souhaitez déboguer : définissez le filtre ftrace sur la fonction souhaitée, activez les points de trace, prenez une trace. Vous pouvez analyser la trace résultante avec trace2html , rechercher l'événement souhaité, puis obtenir les traces de pile à proximité dans la trace brute.

Utiliser LockStat

Parfois, ftrace ne suffit pas et vous devez vraiment déboguer ce qui semble être un conflit de verrouillage du noyau. Il existe une autre option du noyau qui vaut la peine d'être essayée : CONFIG_LOCK_STAT . Il s'agit d'un dernier recours car il est extrêmement difficile de travailler sur des appareils Android, car cela gonfle la taille du noyau au-delà de ce que la plupart des appareils peuvent gérer.

Cependant, lockstat utilise l'infrastructure de verrouillage de débogage, qui est utile pour de nombreuses autres applications. Tous ceux qui travaillent sur l'affichage des appareils devraient trouver un moyen de faire fonctionner cette option sur chaque appareil, car il y aura un moment où vous penserez "Si seulement je pouvais activer LOCK_STAT , je pourrais confirmer ou réfuter ce problème en cinq minutes au lieu de cinq jours."

Afficher le problème : blocage dans SCHED_FIFO lorsque les cœurs sont à charge maximale avec non-SCHED_FIFO

Dans ce problème, le thread SCHED_FIFO s'est bloqué lorsque tous les cœurs étaient à charge maximale avec des threads non SCHED_FIFO. Nous avions des traces montrant un conflit de verrouillage important sur un fd dans les applications VR, mais nous ne pouvions pas facilement identifier le fd utilisé. Pour suivre l'exemple, téléchargez le fichier zip des traces (qui inclut également d'autres traces mentionnées dans cette section), décompressez le fichier et ouvrez le fichier trace_30905547.html dans votre navigateur.

Nous avons émis l'hypothèse que ftrace lui-même était la source d'un conflit de verrouillage, lorsqu'un thread de faible priorité commençait à écrire dans le canal ftrace, puis était préempté avant de pouvoir libérer le verrou. Il s'agit du pire des cas qui a été exacerbé par un mélange de threads de priorité extrêmement faible écrivant sur le marqueur ftrace ainsi que de threads de priorité plus élevée tournant sur les processeurs pour simuler un périphérique complètement chargé.

Comme nous ne pouvions pas utiliser ftrace pour déboguer, nous avons fait fonctionner LOCK_STAT , puis avons désactivé tous les autres traçages depuis l'application. Les résultats ont montré que le conflit de verrouillage provenait en fait de ftrace, car aucun conflit n'apparaissait dans la trace de verrouillage lorsque ftrace n'était pas en cours d'exécution.

Si vous pouvez démarrer un noyau avec l'option config, le traçage des verrous est similaire à ftrace :

Activer le traçage :
```
echo 1 > /proc/sys/kernel/lock_stat
```
Exécutez votre test.
Désactiver le traçage :
```
echo 0 > /proc/sys/kernel/lock_stat
```

Videz votre trace :

cat /proc/lock_stat > /data/local/tmp/lock_stat

Pour obtenir de l'aide sur l'interprétation du résultat résultant, reportez-vous à la documentation de lockstat à l' <kernel>/Documentation/locking/lockstat.txt .

Utilisation des points de trace des fournisseurs

Utilisez d'abord les points de trace en amont, mais vous devrez parfois utiliser les points de trace du fournisseur :

  { "gfx",        "Graphics",         ATRACE_TAG_GRAPHICS, {
        { OPT,      "events/mdss/enable" },
        { OPT,      "events/sde/enable" },
        { OPT,      "events/mali_systrace/enable" },
    } },

Les points de trace sont extensibles par le service HAL, vous permettant d'ajouter des points de trace/catégories spécifiques à un appareil. Les points de trace sont intégrés à Perfetto, Atrace/Systrace et à l'application de traçage du système sur l'appareil.

Les API pour la mise en œuvre des points de trace/catégories sont :

listCategories() génère (catégories vec<TracingCategory>) ;
EnableCategories(vec<string>categories) génère (statut d'état) ;
DisableAllCategories() génère (Statut );

Pour plus d'informations, reportez-vous à la définition HAL et à l'implémentation par défaut dans AOSP :