Profilage de ClickHouse avec XRay de LLVM

LLVM inclut déjà un outil qui instrumente le code et permet de faire du profilage par instrumentation. À la différence du profilage par échantillonnage ou du profilage statistique, il est très précis et ne manque aucun appel, au prix de la nécessité d'instrumenter le code et d'une consommation de ressources plus élevée.

En quelques mots, un profiler par instrumentation ajoute du code pour suivre les appels à toutes les fonctions. Les profilers statistiques permettent d'exécuter le code sans aucune modification, en prenant périodiquement des instantanés pour observer l'état de l'application. Ainsi, seules les fonctions en cours d'exécution au moment de la prise de l'instantané sont prises en compte. perf est un profiler statistique très connu.

Dans ClickHouse 25.12, XRay est intégré pour ajouter de manière transparente de nouveaux points d’instrumentation aux fonctions. Ainsi, toute version officielle inclut déjà cette fonctionnalité, qui peut être déclenchée à la demande, sans affecter les performances globales lorsqu’elle n’est pas activée. L’idée est d’activer le minimum de points d’instrumentation nécessaires pour obtenir des informations utiles.

Nous pouvons ajouter un nouveau point d’instrumentation de profilage à l’aide de l’instruction SYSTEM INSTRUMENT ADD PROFILE. Les fonctions à instrumenter peuvent être récupérées dans la table système system.symbols. Supposons que nous voulions profiler la fonction sleepForNanoseconds, une fonction pratique pour vérifier combien de temps son exécution prend.

SYSTEM INSTRUMENT ADD 'sleepForNanoseconds' PROFILE

Ensuite, nous le laissons s'exécuter pendant la durée à analyser, puis nous l'arrêtons.

SYSTEM INSTRUMENT REMOVE ALL

Nous convertissons les données collectées dans system.trace_log au format Chrome afin de les visualiser dans Perfetto. Notez query_id, cpu_id et stacktrace pour chaque entrée.

La section suivante est conservée à titre de référence pour comprendre le fonctionnement interne de XRay et comment l'utiliser tel quel pour profiler une application native.

Imaginez le code source suivant :

#include <chrono>
#include <cstdio>
#include <thread>

void one()
{
    std::this_thread::sleep_for(std::chrono::milliseconds(10));
}

void two()
{
    std::this_thread::sleep_for(std::chrono::milliseconds(5));
}

int main()
{
    printf("Start\n");

    for (int i = 0; i < 10; ++i)
    {
        one();
        two();
    }

    printf("Finish\n");
}

Pour instrumenter avec XRay, il faut ajouter certaines options :

clang++ -o test test.cpp -fxray-instrument -fxray-instruction-threshold=1

• -fxray-instrument est nécessaire pour instrumenter le code.
• -fxray-instruction-threshold=1 est utilisé pour instrumenter toutes les fonctions, même si elles sont très petites, comme dans notre exemple. Par défaut, il instrumente les fonctions contenant au moins 200 instructions.

On peut vérifier que le code a bien été instrumenté en s’assurant de la présence d’une nouvelle section dans le binaire :

objdump -h -j xray_instr_map test

test:     file format elf64-x86-64

Sections:
Idx Name          Size      VMA               LMA               File off  Algn
 17 xray_instr_map 000005c0  000000000002f91c  000000000002f91c  0002f91c  2**0
                  CONTENTS, ALLOC, LOAD, READONLY, DATA

Par défaut, il n’y a pas de collecte par le profiler, sauf si elle est explicitement demandée. Autrement dit, tant que nous n’effectuons pas de profilage, le surcoût est négligeable. Nous pouvons définir différentes valeurs pour XRAY_OPTIONS afin de configurer à quel moment le profiler commence à collecter des données et comment il le fait.

XRAY_OPTIONS="patch_premain=true xray_mode=xray-basic verbosity=1" ./test
==74394==XRay: Log file in 'xray-log.test.14imlN'
Start
Finish
==74394==Cleaned up log for TID: 74394

Les traces de XRay peuvent être converties en plusieurs formats. Le format trace_event est très utile, car il est facile à analyser et de nombreux outils le prennent déjà en charge. Nous allons donc utiliser celui-ci :

llvm-xray convert --symbolize --instr_map=./test --output-format=trace_event xray-log.test.14imlN | gzip > test-trace.txt.gz

Nous pouvons utiliser des UI web comme speedscope.app ou Perfetto.

Si Perfetto facilite la visualisation de plusieurs threads et l’interrogation des données, speedscope est plus adapté à la génération d’un flamegraph et d’une vue en sandwich de vos données.

• SYSTEM INSTRUMENT — Ajoutez ou supprimez des points d’instrumentation.
• system.instrumentation — Inspectez les points instrumentés.
• system.symbols — Inspectez les symboles afin d’ajouter des points d’instrumentation.
• system.trace_log — Inspectez les données collectées à l’aide des points d’instrumentation.
• XRay Instrumentation
• Documentation Debugging with XRay pour plus de détails.