Conception d'un système de journalisation asynchrone embarqué

Conception d'un système de journalisation asynchrone embarqué : le débogage sans compromettre la réactivité ⚙️

Vous êtes-vous déjà retrouvé dans une situation où un appareil redémarre inexplicablement, le chien de garde désactive la tâche principale, mais vous ne trouvez aucun goulot d'étranglement dans le code ? Et pour découvrir finalement que le coupable était quelques lignes de printf ?

😅 Ne riez pas, c'est très courant dans le développement embarqué. Surtout lorsque vous exécutez plusieurs tâches à haute priorité sur un RTOS, et qu'une entrée de journal arrive soudainement pour écrire sur Flash ou sur le port série, tout le système semble se "bloquer". Pire encore, essayer de générer un journal dans une routine de service d'interruption (ISR) pour vérifier l'état, et finir par un HardFault direct en appelant une fonction non réentrante...

Nous ne construisons pas des jouets, mais des terminaux intelligents, des contrôleurs industriels ou des passerelles edge qui doivent fonctionner de manière stable 7 jours sur 7, 24 heures sur 24. Dans ce cas, les journaux ne doivent pas être un fardeau pour le système, mais doivent en devenir le "système nerveux" — capable de détecter les anomalies sans interférer avec le fonctionnement normal.

La question se pose donc : comment implémenter un mécanisme de journalisation efficace, sûr et évolutif dans un MCU aux ressources limitées ?

La réponse est : journalisation asynchrone.

Pourquoi la journalisation doit-elle être "asynchrone" ? ⏱️→⚡

Allons droit au but : journalisation synchrone = poison lent pour les systèmes temps réel.

L'approche traditionnelle est simple et directe :

void sensor_task(void) {
    int val = read_sensor();
    if (val < 0) {
        printf("[ERROR] Sensor read failed: %d\n", val); // ← Le piège ici
    }
}

Cela semble correct, n'est-ce pas ? Mais printf peut impliquer :

Formatage de chaînes (intensif en CPU)
Écriture de registres UART (attente de la fin de transmission)
Écriture sur carte SD/Firmware (effacement de bloc + programmation, latence de l'ordre de la milliseconde)

Si ces opérations se produisent sur le chemin critique, cela ne fera qu'augmenter la latence des interruptions, ou pire, entraîner des dépassements de délai des tâches à haute priorité, des désordres dans la planification, voire déclencher un redémarrage par le chien de garde.

💡 Nous devons donc adopter une approche différente : transformer l'action d'"enregistrement du journal" de "exécution immédiate" en "traitement par file d'attente".

C'est comme lorsque vous commandez au restaurant ; le serveur ne vous demande pas de cuisiner vous-même dans la cuisine, mais note votre commande et la confie à l'arrière-cuisine pour qu'elle soit préparée tranquillement – vous continuez à manger et à discuter, sans aucune perturbation.

C'est l'idée fondamentale du modèle "producteur-consommateur".

Tampon circulaire : un "relais de messages" léger et efficace 🔄

Puisqu'il s'agit d'une file d'attente, il faut un endroit pour stocker temporairement les données. Dans un environnement embarqué, l'une des structures les plus appropriées est le tampon circulaire (Ring Buffer).

Il s'agit essentiellement d'un tableau de taille fixe, utilisant deux pointeurs dans un jeu de "chasse" :

head : la prochaine position d'écriture (contrôlée par le producteur)
tail : la prochaine position de lecture (contrôlée par le consommateur)

Lorsque head rattrape tail, cela signifie qu'il est plein ; lorsqu'ils sont égaux, cela signifie qu'il est vide.

Pourquoi est-il adapté aux systèmes embarqués ?

Caractéristique	Avantage
Allocation statique de mémoire	Allouée une seule fois au démarrage, pas de frais malloc/free
Insertion/suppression en O(1)	La vitesse est constante, quelle que soit la quantité de données
Support monoproducteur-monoconsommateur sans verrou	Pas besoin de sémaphore en mode bare-metal ou RTOS monocœur
Comportement clair en cas de tampon plein/vide	Option de suppression des anciennes données ou de retour d'erreur

Voici une implémentation typique :

#define LOG_BUFFER_SIZE 1024

typedef struct {
    char buffer[LOG_BUFFER_SIZE];
    volatile uint16_t head;
    volatile uint16_t tail;
} ring_buffer_t;

void ring_buffer_init(ring_buffer_t *rb) {
    rb->head = rb->tail = 0;
}

int ring_buffer_write(ring_buffer_t *rb, char c) {
    uint16_t next = (rb->head + 1) % LOG_BUFFER_SIZE;
    if (next == rb->tail) return -1;  // Plein !

    rb->buffer[rb->head] = c;
    __DMB();  // Barrière mémoire ARM, empêche l'exécution dans le désordre
    rb->head = next;
    return 0;
}

int ring_buffer_read(ring_buffer_t *rb, char *c) {
    if (rb->head == rb->tail) return -1;  // Vide !

    *c = rb->buffer[rb->tail];
    __DMB();
    rb->tail = (rb->tail + 1) % LOG_BUFFER_SIZE;
    return 0;
}

📌 Notez quelques détails :

volatile est nécessaire pour indiquer au compilateur de ne pas optimiser ces variables (sinon l'accès multi-contexte causera des problèmes) ;
__DMB() est une instruction de barrière mémoire pour ARM Cortex-M, garantissant que l'ordre d'écriture dans le tampon et de mise à jour de head n'est pas réordonné par le processeur ;
Si vous avez plusieurs producteurs (par exemple, plusieurs tâches peuvent générer des journaux), vous aurez besoin de verrous mutuels ou d'opérations atomiques.

Cependant, dans la plupart des cas, nous adoptons une architecture monoproducteur (tâche/interruption quelconque), monoconsommateur (tâche de journalisation), ce qui permet une conception sans verrou, extrêmement légère.

Tâche asynchrone : le "transporteur de journaux" travaillant silencieusement en arrière-plan 🧳

Avoir un tampon ne suffit pas ; il faut quelqu'un pour "consommer" ces données. C'est la tâche de journalisation asynchrone (Log Task).

C'est généralement une tâche de faible priorité qui ne fait qu'une seule chose : 👉 Vérifie continuellement si le tampon circulaire contient de nouveaux journaux. Si oui, elle les récupère et les envoie là où ils doivent aller.

void log_task(void *pvParameters) {
    char line[128];
    int len;

    for (;;) {
        if (log_buffer_get_line(line, sizeof(line), &len) == 0) {
            // Sortie vers le port série (pour le débogage)
            uart_send((uint8_t*)line, len);

            // Les erreurs critiques sont immédiatement enregistrées
            if (is_critical_error(line)) {
                storage_immediate_write(line, len);
            }
            // Journalisation ordinaire traitée par lots
            else {
                storage_buffer_append(line, len);
            }
        } else {
            // Si aucune donnée, mise en veille pendant un court instant
            vTaskDelay(pdMS_TO_TICKS(10));
        }
    }
}

🎯 Les principes clés de conception de cette tâche sont :

Faible priorité : ne jamais préempter la logique métier ;
Contrôle du débit : éviter les réveils fréquents qui causent des frais de planification ;
Support événementiel : utiliser des sémaphores pour signaler "nouveau journal" au lieu d'une attente passive ;
Tolérance aux pannes robuste : même si une écriture échoue, le système ne doit pas planter et doit pouvoir traiter les journaux suivants.

Par exemple, vous pouvez optimiser le mécanisme de réveil comme suit :

// Après que le producteur ait écrit le journal
xSemaphoreGiveFromISR(xLogReadySem, &xHigherPriorityTaskWoken);

// Le consommateur attend maintenant de manière bloquante
xSemaphoreTake(xLogReadySem, portMAX_DELAY);

Ainsi, le CPU ne tourne pas inutilement en rond, économisant de l'énergie, ce qui est particulièrement important pour les appareils alimentés par batterie.

🔋 À propos de la consommation d'énergie : si votre système entre en mode Stop ou Standby, n'oubliez pas de suspendre cette tâche ; reprenez-la après le réveil pour traiter les journaux incomplets. Sinon, dormir tout en essayant désespérément d'écrire des journaux serait un véritable "anti-économie d'énergie".

Formatage des journaux : plus que de simples impressions, mais des informations structurées 🧾

Beaucoup pensent que les journaux ne sont que printf, mais ce n'est pas le cas.

De bons journaux doivent avoir les caractéristiques suivantes :

✅ Horodatage intégré (précis à la milliseconde)
✅ Inclure le niveau (DEBUG/INFO/WARN/ERROR)
✅ Indiquer le module ou la source du fichier
✅ Support du formatage à variables multiples (similaire à printf)
✅ Sortie standardisée pour une analyse ultérieure facile

Par exemple, ce journal est très "professionnel" :

[2025-04-05 14:32:10.123][ERROR][SENSOR][temp_sensor.c:45] Read timeout

Il contient l'heure, le niveau, le nom du module, l'emplacement du code source et les détails spécifiques. Il est clair de comprendre ce qui s'est passé en un coup d'œil.

Comment générer un tel journal ? Nous pouvons encapsuler une interface universelle :

#include <stdarg.h>

void log_printf(log_level_t level, const char *tag, const char *fmt, ...) {
    char temp[96], final[128];
    va_list args;
    int len;

    uint32_t ms = get_system_ms();  // Obtient l'horodatage en millisecondes
    split_timestamp(ms, &year, &mon, &day, &hour, &min, &sec);  // Décompose la date

    va_start(args, fmt);
    vsnprintf(temp, sizeof(temp), fmt, args);
    va_end(args);

    len = snprintf(final, sizeof(final),
                   "[%04lu-%02u-%02u %02u:%02u:%02u.%03lu][%s][%s] %s\n",
                   year, mon, day, hour, min, sec, ms % 1000,
                   log_level_str(level), tag, temp);

    log_buffer_write_string(final, len);  // Ajout asynchrone à la file d'attente !
}

🧠 Quelques conseils pratiques :

Utilisez vsnprintf au lieu de vsprintf pour éviter les dépassements de tampon ;
L'horodatage doit idéalement provenir d'une RTC ou d'un compteur de ticks système, n'allez pas lire l'horloge matérielle à chaque fois ;
Si vous appelez cette fonction dans une ISR, assurez-vous que toutes les sous-fonctions sont réentrantes et non bloquantes ;
Pour les plateformes sans prise en charge des nombres à virgule flottante, envisagez de désactiver %f ou d'utiliser une version personnalisée de la bibliothèque mini_printf.

Soit dit en passant, certaines équipes préfèrent utiliser la sérialisation binaire au lieu des journaux texte (par exemple, format TLV). L'avantage est une petite taille et une analyse rapide, l'inconvénient est qu'ils ne sont pas lisibles par l'homme. À moins que vous n'ayez des contraintes strictes de bande passante ou de stockage, je vous suggère d'utiliser d'abord le format texte – après tout, c'est vous qui les lirez la plupart du temps.

À quoi ressemble l'architecture réelle ? Examinons la conception de bout en bout 🔗

Assemblons tous les composants précédents pour voir comment fonctionne un système de journalisation asynchrone complet.

+------------------+
|   Application    |
|  log_error("...")|
+--------+---------+
         |
         v
+--------v---------+     +--------------------+
| Log Formatter    | --> | Ring Buffer (RAM)  |
| - Ajouter temps/niveau |     | - Taille fixe, utilisation cyclique |
| - Formater en chaîne |     +----------+---------+
+------------------+              |
                                  |
                      +-----------v------------+
                      |   Async Log Task       |
                      |   (Priorité basse)     |
                      +-----------+------------+
                                  |
          +-----------------------+--------------------------+
          |                       |                          |
          v                       v                          v
   +------+------+     +----------+----------+    +----------+----------+
   |   UART      |     |     SPI NOR Flash   |    |     Wi-Fi/MQTT      |
   | (Console)   |     | (Stockage persistant)|    | (Téléchargement Cloud)|
   +-------------+     +---------------------+    +---------------------+

Le processus complet est le suivant :

Le code utilisateur appelle log_error("Sensor %d failed", id);
Le module de formatage génère une chaîne de journal avec des métadonnées ;
La chaîne est écrite octet par octet dans le tampon circulaire (si plein, la plus ancienne est écrasée) ;
Un sémaphore est déclenché pour notifier la tâche de journalisation ;
La tâche de journalisation est réveillée, extrait la ligne de journal complète ;
La stratégie de distribution décide de la destination de sortie (port série toujours actif, Flash uniquement pour ERROR, MQTT uniquement lorsqu'il est connecté) ;
Une fois le traitement terminé, la tâche se remet en veille.

Cela ressemble un peu à un bus de messages dans les microservices, mais nous l'implémentons sur un MCU avec quelques centaines d'octets de RAM 😎

Défis d'ingénierie et solutions 💣➡️🛡️

L'idéal est souvent loin de la réalité. Voici quelques pièges dans lesquels je suis tombé et que vous pourriez rencontrer.

❌ Problème 1 : Impossible d'appeler log_xxx() dans une interruption

Raison : snprintf peut utiliser des tampons globaux ou de la mémoire dynamique, ce qui n'est pas réentrant.

✅ Solution :

Fournir des macros spécifiques pour la sécurité des interruptions, comme log_isr_debug() ;
Effectuer un traitement minimal à l'intérieur : regrouper les paramètres bruts dans une structure, la copier directement dans le tampon ;
Ou simplement autoriser l'enregistrement de "flags d'événements" dans les interruptions, que la tâche complétera ultérieurement.

Par exemple :

#define LOG_ISR_EVENT(ev) do { \
    isr_event_buffer[ev_head++] = ev; \
    ev_head %= EV_BUF_SIZE; \
} while(0)

La tâche de journalisation traduira ensuite cela en informations lisibles.

❌ Problème 2 : La durée de vie de la Flash est trop courte, elle grille après quelques écritures par jour

La durée de vie typique d'un cycle d'effacement/programmation pour une SPI Flash est de 100 000. Si vous écrivez une fois par seconde, elle sera inutilisable en moins de deux jours.

✅ Combinaison de solutions :

Écriture par lots : accumuler une certaine quantité avant de flasher une fois ;
Équilibrage d'usure (Wear Leveling) : utiliser des secteurs différents à tour de rôle ;
Fusion de journaux : ne conserver que les N derniers journaux critiques ;
Écriture immédiate des journaux critiques, mise en cache et rafraîchissement des journaux ordinaires

Par exemple, vous pouvez concevoir un simple gestionnaire de fichiers journaux :

#define LOG_SECTOR_COUNT 8
static uint8_t current_sector = 0;

void storage_write_log(const char *log, int len) {
    if (sector_full(current_sector)) {
        erase_next_sector();  // Efface le secteur suivant
        current_sector = (current_sector + 1) % LOG_SECTOR_COUNT;
    }
    spi_flash_write(sector_addr(current_sector), log, len);
    update_sector_offset(len);
}

Cela permet de répartir les opérations d'écriture sur plusieurs zones physiques, prolongeant la durée de vie globale.

❌ Problème 3 : Trop de journaux entraînent un dépassement du tampon, des informations critiques sont perdues

Surtout à l'instant précédant le crash du système, les journaux sont les plus importants, mais ils sont écrasés car le tampon est plein.

✅ Solution :

Définir une "zone de rétention d'urgence" : les 256 derniers octets sont réservés aux journaux de niveau CRITICAL ;
Forcer l'écriture en cas de crash : dans le gestionnaire HardFault ou Reset Handler, essayer d'écrire rapidement les journaux restants ;
Utiliser un mécanisme de double tampon : l'un pour l'enregistrement quotidien, l'autre spécifiquement pour les instantanés de panne.

Vous pouvez même combiner cela avec la NVRAM (comme la SRAM de sauvegarde) pour stocker les quelques derniers journaux, qui ne seront pas perdus même en cas de coupure de courant.

❌ Problème 4 : Les journaux de plusieurs modules sont mélangés, impossible de savoir qui a fait quoi

Une douzaine de fichiers .c génèrent des journaux, tous sont [INFO] Init done, impossible de savoir quel module a terminé son initialisation.

✅ Solution : introduire le mécanisme de Tag

#define LOG_TAG "NETWORK"
log_info("Connected to AP: %s", ssid);

Vous verrez alors sur le port série :

[2025-04-05 10:12:34.567][INFO][NETWORK][wifi_mgr.c:123] Connected to AP: HomeWiFi

Beaucoup plus clair, n'est-ce pas ? Vous pouvez également filtrer à l'exécution :

// Désactiver dynamiquement les journaux de certains modules
log_set_tag_filter("BLE", LOG_LEVEL_WARN);
// Ou configurer via la ligne de commande

Activer les journaux détaillés lors du débogage et les dégrader automatiquement lors de la publication, c'est très flexible.

❌ Problème 5 : L'écriture intensive de journaux se poursuit en mode basse consommation

Vous pensez que l'appareil dort, mais la tâche de journalisation tourne toujours en arrière-plan, maintenant le courant élevé.

✅ Solution :

Enregistrer des rappels de gestion de l'alimentation, suspendre la tâche de journalisation avant d'entrer en mode veille ;
Utiliser un événement déclencheur au lieu d'un polling périodique ;
Activer une stratégie de "soumission différée" pour les journaux non critiques, qui seront traités en bloc au réveil.

Dans FreeRTOS, vous pouvez le faire comme suit :

void enter_low_power_mode(void) {
    suspend_log_task();           // Suspendre la tâche
    disable_log_interrupts();     // Masquer les interruptions liées aux journaux
    enter_stop_mode();
    resume_log_task();            // Reprendre après le réveil
}

Comment équilibrer performances et ressources ? 📊

Toute conception doit faire face à des contraintes réelles. Voici les valeurs recommandées basées sur mon expérience dans plusieurs projets :

Paramètre	Valeur recommandée	Description
Taille du tampon circulaire	1 Ko ~ 4 Ko	Moins de 1 Ko entraîne une perte de journaux, plus de 4 Ko gaspille de la RAM
Période de la tâche de journalisation	10 ms ~ 100 ms	Trop court augmente la charge de planification, trop long entraîne une latence notable
Longueur maximale d'une seule ligne de journal	≤ 128 octets	Suffisant pour exprimer la plupart des informations, évite les grandes chaînes
Niveau de journalisation	DEBUG/INFO/WARN/ERROR/CRITICAL	Cinq niveaux suffisent pour distinguer la gravité
Utilisation de la notification par sémaphore	✅ Fortement recommandé	Plus économe en énergie et plus réactif que le polling
Prise en charge de l'activation/désactivation à l'exécution	✅ Obligatoire	Activer DEBUG pendant le débogage, désactiver en production

💡 Rappel spécial : ne pas accumuler de fonctionnalités pour une "complétude fonctionnelle". Par exemple, si vous n'êtes qu'un bracelet Bluetooth, vous n'avez pas besoin de la transmission MQTT, alors n'intégrez pas le module réseau. La simplicité est la beauté des systèmes embarqués.

Faire en sorte que les journaux soient vraiment utiles : plus que du débogage 🔍

Beaucoup considèrent les journaux comme un outil temporaire pendant la phase de développement et les désactivent une fois en production. Cependant, en réalité, les journaux en environnement de production ont encore plus de valeur.

Imaginez :

Un appareil fonctionne en continu pendant trois mois sur le terrain puis tombe en panne, le client appelle pour demanedr "Que s'est-il passé ?"
Vous déployez à distance une commande : "Veuillez redémarrer et activer le mode diagnostic"
L'appareil télécharge les 100 derniers journaux, et vous découvrez qu'un capteur a continuellement dépassé le délai, entraînant une accumulation de tâches.
Correction du firmware, mise à jour OTA, problème résolu.

L'ensemble du processus ne nécessite pas de support sur site, ce qui permet d'économiser considérables coûts d'exploitation et de maintenance.

Par conséquent, n'hésitez pas à ajouter des "fonctionnalités avancées" à votre système de journalisation :

✅ Réglage dynamique du niveau de journalisation

Ajustez le niveau de sortie en temps réel via des commandes série, des caractéristiques Bluetooth BLE ou une configuration cloud.

// Réception du paquet de configuration
void on_config_received(uint8_t new_level) {
    g_global_log_level = new_level;
}

✅ Téléchargement sécurisé des journaux

Les journaux des appareils sensibles (comme ceux utilisés dans les secteurs médical ou financier) ne doivent pas être transmis en clair. Utilisez le chiffrement AES avant l'envoi.

✅ Compression des journaux

Compressez avec un algorithme simple (comme LZSS) avant de télécharger pour économiser de la bande passante.

✅ Classification automatique et alertes

Connectez-vous à ELK ou Prometheus côté cloud, définissez des règles pour identifier automatiquement les mots-clés comme HardFault, OOM et déclenchez des alertes.

✅ Retour de journaux par OTA

Permettez aux utilisateurs de télécharger les derniers journaux en un clic pour le diagnostic de pannes, améliorant ainsi l'expérience utilisateur.

Une dernière réflexion : les journaux sont la "capacité d'introspection" du système 🧠

En écrivant ceci, je veux dire : un bon système embarqué ne doit pas seulement agir, il doit aussi savoir ce qu'il a fait.

C'est comme pour les humains : non seulement avoir des actions, mais aussi avoir une conscience. Sinon, ce n'est qu'une machine aveugle.

Et les journaux sont le composant clé qui donne au périphérique sa capacité "d'auto-observation".

Ils nous permettent de localiser rapidement les problèmes dans des environnements complexes, de tester des hypothèses et d'itérer pour l'optimisation. Surtout sur les appareils edge sans surveillance, ils sont les seuls "yeux" et "oreilles".

Bien sûr, tout cela suppose que : les journaux eux-mêmes ne doivent pas devenir un fardeau pour le système.

C'est pourquoi nous avons besoin de mécanismes asynchrones, de tampons circulaires, de formatage à faible coût... Derrière tous ces détails techniques, il y a un seul objectif :

Permettre au système de fonctionner à grande vitesse tout en exprimant clairement son état.

C'est la posture que devrait adopter le développement embarqué moderne.

Maintenant, revenons à la question initiale : Osez-vous encore faire un printf n'importe où dans la boucle principale ?

😏 Je parie que vous avez appris une meilleure façon.

Étiquettes: embarqué RTOS journalisation asynchrone tampon circulaire

Publié le 21 juillet à 06h14

L'Atelier Monstre

Conception d'un système de journalisation asynchrone embarqué