On va donc générer des traces composées de spans pour suivre nos requêtes et actions. La documentation officielle d’Opentelemetry explique bien le concept que je vais résumer ici.

Prenons l’exemple précédent. Il va être possible avec Opentelemetry de mesurer le temps d’exécution de chaque étape du parcours de notre action. On veut donc mesurer le temps d’exécution de la requête par le client HTTP original. Puis le temps passé dans l’application A, où l’on peut mesurer le temps de traitement de la requête HTTP par le serveur, qui sera lui même composé du temps d’exécution de la requête SQL et de l’appel HTTP à l’application B. Même chose pour l’application B où l’on mesurera le temps de traitement de la requête HTTP reçue et de la requête SQL exécutée.

Voici une représentation de cela, avec le temps en abscisse:

Il serait également possible de représenter cette série d’action comme un arbre:

On voit ici que chaque action a comme noeud suivant l’action (ou les actions) suivante (et inversement ces actions ont comme parent l’action précédente).

On pourrait également représenter l’exécution de la toute première requête HTTP (HTTP Client) en JSON:

En fait, ce JSON est la représentation d’une span opentelemetry. Comme dit précédemment une trace permet de suivre l’exécution d’actions liées entre elles. Une trace est tout simplement une liste de spans partageant le même trace_id.

Dans cet exemple, ma span a une trace_id égale à 0x5b8aa5a2d2c872e8321cf37308d69df2. Elle a une également une span_id (0x5fb397be34d26b51, permettant de l’identifier de manière unique).

Ma span a également une date de début et de fin (start_time et end_time). La span démarre avant l’exécution de l’appel HTTP, et se termine lorsque la réponse est reçue. On peut comme cela déduire le temps d’exécution total ce cette action.

Vient ensuite le champ parent_id. Rappelez-vous de la représentation en arbre des actions: ici, c’est la première action à être exécutée donc la span n’a aucun parent: c’est ce qu’on appelle la root span.

Viennent ensuite les attributes dont nous allons parler dans la section suivante.

Une span avec juste un nom (comme HTTP Client) et un temps d’exécution serait inutile: il serait impossible d’en faire quelque chose et de comprendre l’action réalisée. C’est là qu’interviennent les attributes.

Dans la span représentée précédemment, les attributes seront liés à la requête HTTP réalisée: route, méthode, status de la réponse, port, url cible…​ cela permet de comprendre immédiatement la requête qui a été exécutée.

Représentons maintenant la span suivante de notre arbre: le serveur HTTP recevant la requête dans l’application A:

Regardons déjà les ID de trace et de span. Le trace_id est le même que la span HTTP CLient: en effet, les deux spans font partie de la même série d’action (de la même trace). Le span_id est par contre unique à la span.

Ici, le parent_id n’est pas null: il est égal à 0x5fb397be34d26b51 qui est la valeur de la span précédente (HTTP Client). Cela est logique car c’est bien cette span qui est parente dans l’arbre.

Les attributs donnent également ici des informations sur la requête HTTP reçue. On peut voir quelques similitudes avec la span HTTP Client.

Conventions de nommage

On a vu l’importance des attributs pour donner du contexte aux spans.

Dans notre exemple du début d’article on aurait par exemple une span pour la requête SQL du service A. Cette span ressemblerait probablement à quelque chose comme:

Ici les attributs seront spécifiques à SQL et nous permettent aussi de facilement identifier l’action réalisée.

Il est important de standardiser les attributs. Nous allons en effet pouvoir faire des recherches sur les traces. Cela serait très difficile si un service nommait un attribute db.statement et l’autre database.statement: il faut des conventions de nommage.

Le standard Opentelemetry fournit déjà une liste de noms et types d’attributs (let attributes sont typés) standards. Vous pouvez trouver cette liste ici.

Tous les attributs techniques "classiques" (en lien avec des technologies comme les base de données, les cloud providers, des protocoles comme HTTP ou gRPC) sont déjà standardisés. Des librairies existent également pour construire ces attributs standards (comme la lib semconv en Golang).

Il est également très important de standardiser vos attributs métiers. Avoir des attributs techniques attachés aux spans est intéressant, mais il est encore plus intéressant d’attacher du contexte métier à vos spans.
Cela peut être des attributs comme <company-name>.user.id, <company-name>.organization.id ou tout autre attribut métier important.

Rappelez vous que les traces sont intéressantes notamment pour découvrir des problèmes de performance: peut être allez-vous vous rendre comme que c’est toujours les requêtes venant d’un utilisateur spécifique qui sont lentes grâce à un attribut contenant son ID. Sans cet attribut, l’investigation du problème pourrait être beaucoup plus lente.

Il est commun dans une span d’avoir également un bloc resource contenant des attributs communs à une application:

Ces attributs sont souvent utilisés par les base de données de traces pour stocker ensemble les spans d’un même service, car toutes les spans émises par une instance d’un service donné auront les mêmes ressources.

Un autre bloc présent dans une span est le bloc scope. Voici par exemple le contenu de scope pour une span émise par le package Golang otelgin, permettant d’ajouter le support d’Opentelemetry au framework Gin:

Cela permet de voir que cette span a été générée par cette librairies. La documentation officielle d’Opentelemetry explique bien cela.

Il est également possible d’ajouter à une span un status avec un message permettant de très rapidement filtrer les spans en erreur. Une span représentant une erreur de validation de requête HTTP pourrait avoir comme status:

On arrive à un concept que j’adore dans le tracing: les events.

On a étudié précédemment des exemples de spans représentant une action avec une date de début, une date de fin et des attributs.

Il est également possible d’ajouter à une span des messages arbitraires avec un timestamp fixe associé et des attributs: ce sont les events. On peut voir un event comme un log, c’est exactement le même principe.

Reprenons notre exemple de serveur HTTP recevant une requête. Il est commun d’avoir dans des handlers HTTP des logs applicatifs de ce type:

Ces logs sont il est vrai de faible qualité (c’est juste pour l’exemple) mais on voit souvent ce genre de patterns avec de nombreux logs ajoutés "au cas où" et loggant toute sorte de choses en production.

Mais si vous faites du tracing, ces logs peuvent complètement disparaître:

Un exemple:

Comme vous pouvez le voir, un log est devenu un event attaché à ma span et le reste des attributs (user.id et user.mode). Et ça, c’est GENIAL.

Pourquoi c’est genial ? Reprécisons pourquoi le tracing est intéressant: suivre des actions entre services. Les logs sont très souvent utilisés pour ça également. Qui n’a jamais utilisé les logs pour suivre le parcours d’une requête dans une application, ou même entre applications via des recherches plus ou moins complexes ?

En ayant des attributs métiers dans mes spans ET en ajoutant des events lorsque j’ai besoin d’avoir un timestamp exact associé à un message, j’ai le meilleur des deux mondes:

C’est un énorme gain de temps. Je n’ai pas à jongler entre différents outils pour essayer de trouver une information. Du moment que j’ai un ID de trace (ou que je peux le retrouver via une recherche sur un attribut), j’ai accès à toutes les informations sur cette trace (depuis tous mes services) d’une manière unifiée. Je n’ai plus à galérer à corréler des logs entre eux, ma trace et mes spans le font pour moi !

Je prévois dans le futur une fusion des outils de gestion de traces et de logs. Pourquoi garder les deux alors que les traces font déjà un boulot LARGEMENT meilleur tout en étant un format standard ?

Je pense que si je devais reconstruire un système d’information "from scratch" aujourd’hui je:

Cela me permet de rebondir sur le sujet du sampling. On entend toujours dire lorsqu’on parle des traces "conserver 100 % des traces est trop coûteux en stockage car trop de volume", et donc qu’il faut faire du sampling (par exemple, ne conserver que 5 % des traces). Je ne pense pas que ce soit une bonne idée.

Certains outils comme Grafana Tempo ont pour objectif de pouvoir garder 100 % des traces en les stockant sur S3 pour baisser les coûts. Mais le lien entre traces et logs est aussi important.

Les logs aussi sont souvent coûteux à stocker (je vois les utilisateurs Elasticsearch sourire en lisant ça). Pourtant, des applications qui loggent comme des porcs sans que personne ne lève un sourcil ne posent aucun problème dans de nombreuses entreprises, et personne ne veut faire du sampling sur les logs car cela baisse les capacités d’investigations de problèmes.

Pourquoi ne pas voir les traces comme un remplaçant des logs et donc avec un transfert des coûts depuis les logs vers les traces ? Au final, l’information est quasiment la même, les deux sont des hashmaps clé/valeur.
Ne vous dites pas "j’aurai 40TB de traces en plus de mes 40TB de logs", mais plutôt "j’aurai 40TB de traces mais plus que 2TB de logs, et une meilleure capacité à investiguer des problèmes". C’est vraiment vers ça que doit pour moi se tourner l’industrie (et les gens construisant des outils de gestion de logs).

Il y a d’autres champs disponibles dans les spans. Les Links permettent de lier des spans entre elles même si elles font partie d’autres traces (donc d’avoir aussi des relations entre traces et non seulement entre spans d’une même trace). Le champ Kind permet d’ajouter une valeur spéficiant si l’émetteur est un client, un serveur, ou consumer de messages (d’une queue de message par exemple)…​

Bref, la définition des spans est vaste et le mieux est d’explorer la documentation.