Observabilité Chapitre 18 / 42

Le tracer SQLite & les événements de phase

La salle de contrôle s'ouvre : un tracer qui journalise chaque événement au moment où il arrive, et une base SQLite qui rend chaque run de l'usine requêtable — même les runs plantés.

Hier, votre banc a départagé quatre équipes en trois chiffres : verdict, coût, durée. Mais posez-vous la question : que savez-vous d’un run pendant qu’il tourne, et que vous en reste-t-il une heure après ? Aujourd’hui, la réponse tient dans le défilement de stderr au fond d’un couloir herdr : fermez le terminal, et le run n’a jamais existé. Un SDLC qui vire au rouge en phase 12 vous laisse un scroll à remonter à la main, et un run gelé ne vous laisse rien du tout, puisque son bilan ne s’imprime qu’à la fin.

Ce chapitre ouvre le module Observabilité, la salle de contrôle du plan, et pose sa première pièce : le tracer. À la fin, chaque run de votre usine laissera une trace permanente et requêtable, écrite événement par événement au moment où ils se produisent : un run planté raconte son histoire jusqu’à l’instant du gel. La pièce s’emboîte directement sur le squelette du chapitre 8 : le runner apprend à déclarer ce qu’il fait, et vos ADW n’y changent pas une ligne.

Tracer chaque événement pendant qu’il arrive

L’idée en une phrase

Le tracer enregistre chaque événement du run (ouverture, phase, tentative, verdict) au fil de l’eau, jamais en fin de run : c’est la première pièce de la salle de contrôle, et elle vit entièrement côté code déterministe. Les agents ne savent même pas qu’ils sont tracés.

Points clés

  • Écrire quand ça se passe, pas quand c’est fini. Un run qui plante, gèle ou se fait tuer laisse sa trace jusqu’à l’instant du gel : c’est exactement quand tout va mal que le journal vaut le plus cher. Un bilan imprimé en fin de run ne survit à aucun accident.
  • Deux supports, une vérité. La ligne JSONL (un fichier par run, un événement par ligne) est l’enregistrement brut de référence, SQLite le miroir requêtable, mis à jour dans le même geste. Perdre la base ne perd rien : elle se reconstruit depuis le brut.
  • Un événement est une donnée typée, pas une phrase. Chaque ligne porte son type (phase_start, phase_fail…), son adw_id, sa phase et son horodatage : elle se requête, se compte et se joint. Un print ne fait rien de tout cela.
  • Le runner déclare, vos ADW ne changent pas. C’est le squelette du chapitre 8 qui émet les événements : il connaît déjà les phases, les tentatives et les verdicts. Vos scripts, eux, gardent la même API : PhaseSpec, Run, execute.

Exemple concret

Reprenez le SDLC du chapitre 13 : dix-huit phases, ~40 à 60 centimes, une dizaine de minutes. À la neuvième minute, la phase build épuise ses reprises et le run s’arrête. Sans tracer : un scroll de stderr à remonter, et si le terminal est fermé, rien. Avec le tracer : une commande relit le journal : onze phases vertes, la douzième en échec avec son motif, la tentative où tout a basculé, l’heure exacte. Le surcoût de cette mémoire : zéro token et quelques millisecondes par événement, invisible à côté des minutes que durent les phases agent.

Les événements que le runner émet

ÉvénementÉmis quandCe que la ligne porte
run_startle runner ouvre le runnom de l’ADW, demande de l’ingénieur
phase_startune phase entre en pistenuméro de séquence, côté de la couture (kind)
phase_okune tentative réussitnuméro de la tentative
phase_failune tentative échouenuméro de la tentative, motif de l’échec
run_endle run rend son code retourverdict final, coût total

Config — une ligne du journal brut

Chaque événement part d’abord dans le fichier JSONL du run, sous adws/adw_data/traces/. Une ligne se lit seule, sans outil :

{
  "event_id": "evt_3f9c2a71b04d",
  "ts": "2026-09-02T14:07:31.412+00:00",
  "adw_id": "a1b2c3d4",
  "phase_id": "a1b2c3d4-09",
  "type": "phase_fail",
  "name": "build",
  "payload": {"attempt": 1, "error": "gate tests : 2 verifications en echec"}
}

Piège courant : « tracer, c’est écrire des logs » est inexact. Un log est une phrase composée pour l’humain qui regarde l’écran maintenant. Une trace est une donnée typée écrite pour la question que vous poserez plus tard, souvent une question que vous ne connaissez pas encore. Le runner continue d’imprimer ses lignes sur stderr pour l’œil, le tracer écrit en parallèle pour la requête.


SQLite comme journal de l’usine

L’idée en une phrase

Le journal de l’usine est un unique fichier SQLite, adws/adw_data/factory.db, en mode WAL, que vous pouvez requêter pendant que l’usine écrit : trois tables, zéro serveur, et le chemin de la donnée est toujours usine → SQLite → lecture, jamais un push vers un service.

Points clés

  • WAL rend la base lisible à chaud. Le mode write-ahead logging laisse les lecteurs travailler pendant qu’un écrivain écrit, et le busy_timeout fait patienter un second écrivain au lieu de le faire échouer. Deux runs en parallèle dans deux couloirs herdr partagent le même journal sans se marcher dessus.
  • Trois tables, trois questions. runs répond à « qui a tourné, verdict, coût », phases à « comment ce run s’est déroulé », events au grain fin : « que s’est-il passé, dans quel ordre ». Tout se joint par adw_id.
  • Le vert se mérite, jusque dans le schéma. status vaut 'fail' par défaut dans runs comme dans phases : une ligne ne devient verte que si le code l’a explicitement décidé. Un crash ne fabriquera jamais un faux succès : la loi de l’usine, gravée en SQL.
  • Le journal est du runtime, jamais commité. factory.db et les JSONL vivent sous adws/adw_data/, couverts par le .gitignore du chapitre 1 depuis le premier jour.

Exemple concret

Lancez un SDLC dans un couloir herdr, puis, pendant qu’il tourne, ouvrez un second couloir et interrogez la base : combien d’événements déjà écrits, quelle phase est en piste, combien de tentatives sur la phase build. La réponse tombe en quelques millisecondes, sans gêner le run : WAL fait exactement ce travail. Une heure plus tard, la même requête raconte la même histoire : le journal, lui, ne défile pas hors de l’écran.

Les trois tables du journal

TableUne ligne =Elle répond à
runsun run d’ADWqui a tourné, quand, verdict, coût total
phasesune phase d’un runle déroulé : séquence, dernier état, tentatives, motif
eventsun événement datéle grain fin : tout, dans l’ordre, à la milliseconde

Commande — interroger le journal

Une seule version suffit ici : le journal est du code déterministe pur, aucun harnais en vue. Avec le client sqlite3 installé, une requête par ligne. Sans lui, ce qui est fréquent sous Windows, la pièce du jour porte son propre lecteur, même information, zéro dépendance :

# les dix derniers runs : verdict et cout, du plus recent au plus ancien
sqlite3 adws/adw_data/factory.db "SELECT adw_id, adw_name, status, cost_usd FROM runs ORDER BY started_at DESC LIMIT 10;"

# le deroule d'un run precis
sqlite3 adws/adw_data/factory.db "SELECT seq, name, kind, status, attempt FROM phases WHERE adw_id='a1b2c3d4' ORDER BY seq;"

# sans client sqlite3 : le lecteur embarque dans la piece du jour
uv run adws/adw_modules/tracer.py --last

Piège courant : « pour observer l’usine, il faut une stack d’observabilité, un serveur, un collecteur, un dashboard » est inexact. Un fichier SQLite en WAL couvre tout le besoin d’une usine locale : écriture au fil de l’eau, lecture à chaud, requêtes arbitraires, zéro processus de plus. Le pont vers une stack existante (OpenTelemetry) viendra au chapitre 20, comme un export, pas comme un prérequis.


Fil rouge — la pièce posée aujourd’hui

La zone « salle de contrôle » du plan ouvre avec sa pièce maîtresse : adws/adw_modules/tracer.py, posée à côté du squelette du chapitre 8, qui évolue pour déclarer ce qu’il fait, sans changer d’API. La couture ne bouge pas : le tracer est du code déterministe qui observe du code déterministe. Les agents proposent comme d’habitude, les gates disposent comme d’habitude, et les événements ne traversent aucune enveloppe : ils longent la couture côté code, là où vivent déjà le séquencement et les verdicts. À l’usage : zéro token, quelques millisecondes par événement. À l’économie : un diagnostic qui coûtait un re-run entier, plusieurs dizaines de centimes et de longues minutes, devient une requête gratuite sur un run déjà payé.


Travaux pratiques — la pièce du jour

Une pièce complète à poser dans le repo compagnon plume-factory, qui devient, chapitre après chapitre, votre usine logicielle agentique. Aujourd’hui, deux fichiers : le tracer, et le runner qui apprend à s’en servir.

Pièce — adws/adw_modules/tracer.py

Le journal de l’usine. Bibliothèque standard uniquement, aucun import des autres modules : il s’importe depuis le runner et se lance aussi tel quel : l’auto-test lui sert de gate, et --last relit le dernier run sans client sqlite3. Entièrement côté déterministe.

# /// script
# requires-python = ">=3.11"
# ///
"""tracer — le journal de l'usine : chaque evenement, au moment ou il arrive.

Deux supports, une verite. Le JSONL est l'enregistrement brut — un fichier
par run, un evenement par ligne, ecrit au fil de l'eau ; SQLite
(factory.db, mode WAL) est le miroir requetable, mis a jour dans le meme
geste. Pas de serveur, pas de push : le chemin est toujours
usine -> sqlite -> lecture.

Lance directement, le module porte sa propre gate :
    uv run adws/adw_modules/tracer.py            # auto-test, zero token
    uv run adws/adw_modules/tracer.py --last     # relire le dernier run
"""
from __future__ import annotations

import json
import sqlite3
import sys
import tempfile
import uuid
from datetime import datetime, timezone
from pathlib import Path

DB_PATH = Path("adws/adw_data/factory.db")
JSONL_DIR = Path("adws/adw_data/traces")

# Le schema du journal : trois tables, une par question.
#   runs   — qui a tourne, quand, verdict, cout ;
#   phases — le deroule d'un run, sequence par sequence ;
#   events — le grain fin : tout ce qui s'est passe, date, type.
# Regle de la maison, gravee en SQL : status vaut 'fail' par defaut —
# le vert se merite, un crash ne fabrique jamais un faux succes.
SCHEMA = """
CREATE TABLE IF NOT EXISTS runs (
  adw_id     TEXT PRIMARY KEY,
  adw_name   TEXT,
  request    TEXT,
  status     TEXT DEFAULT 'fail',
  started_at TEXT,
  ended_at   TEXT,
  cost_usd   REAL DEFAULT 0
);
CREATE TABLE IF NOT EXISTS phases (
  phase_id   TEXT PRIMARY KEY,
  adw_id     TEXT REFERENCES runs,
  seq        INTEGER,
  name       TEXT,
  kind       TEXT,
  status     TEXT DEFAULT 'fail',
  attempt    INTEGER DEFAULT 0,
  retries    INTEGER DEFAULT 0,
  error      TEXT,
  started_at TEXT,
  ended_at   TEXT
);
CREATE TABLE IF NOT EXISTS events (
  event_id     TEXT PRIMARY KEY,
  adw_id       TEXT REFERENCES runs,
  phase_id     TEXT REFERENCES phases,
  type         TEXT,
  name         TEXT,
  payload_json TEXT,
  ts           TEXT
);
"""


def now_iso() -> str:
    """L'heure UTC, milliseconde comprise : triable en SQL comme du texte."""
    return datetime.now(timezone.utc).isoformat(timespec="milliseconds")


class Tracer:
    """Ecrit chaque evenement DEUX fois : la ligne JSONL, puis le miroir SQLite."""

    def __init__(self, db_path: Path = DB_PATH, jsonl_dir: Path = JSONL_DIR):
        db_path = Path(db_path)
        db_path.parent.mkdir(parents=True, exist_ok=True)
        self.jsonl_dir = Path(jsonl_dir)
        self.jsonl_dir.mkdir(parents=True, exist_ok=True)
        # isolation_level=None : autocommit — rien ne reste en l'air si le
        # process meurt, chaque evenement ecrit est un evenement garde.
        self.conn = sqlite3.connect(db_path, isolation_level=None)
        # WAL : lire la base pendant que l'usine ecrit.
        self.conn.execute("PRAGMA journal_mode=WAL;")
        # Deux runs concurrents patientent au lieu d'echouer.
        self.conn.execute("PRAGMA busy_timeout=5000;")
        self.conn.executescript(SCHEMA)

    # ── evenements : le grain fin ────────────────────────────────────────
    def event(self, adw_id: str, type_: str, name: str,
              phase_id: str | None = None, payload: dict | None = None) -> str:
        event_id = f"evt_{uuid.uuid4().hex[:12]}"
        line = {"event_id": event_id, "ts": now_iso(), "adw_id": adw_id,
                "phase_id": phase_id, "type": type_, "name": name,
                "payload": payload or {}}
        # 1. Le brut d'abord : la ligne JSONL est l'enregistrement de reference.
        with (self.jsonl_dir / f"{adw_id}.jsonl").open("a", encoding="utf-8") as f:
            f.write(json.dumps(line, ensure_ascii=False) + "\n")
        # 2. Le miroir ensuite : la meme information, requetable en SQL.
        self.conn.execute(
            "INSERT INTO events (event_id, adw_id, phase_id, type, name,"
            " payload_json, ts) VALUES (?,?,?,?,?,?,?)",
            (event_id, adw_id, phase_id, type_, name,
             json.dumps(payload or {}, ensure_ascii=False), line["ts"]))
        return event_id

    # ── runs ─────────────────────────────────────────────────────────────
    def run_start(self, adw_id: str, adw_name: str, request: str) -> None:
        self.conn.execute(
            "INSERT INTO runs (adw_id, adw_name, request, status, started_at)"
            " VALUES (?,?,?,?,?) ON CONFLICT(adw_id) DO NOTHING",
            (adw_id, adw_name, request, "running", now_iso()))
        self.event(adw_id, "run_start", adw_name, payload={"request": request})

    def run_finish(self, adw_id: str, ok: bool, cost_usd: float) -> None:
        # Un run tue net ne passe jamais ici : il reste 'running' sans
        # ended_at — c'est la signature requetable d'un run interrompu.
        status = "success" if ok else "fail"
        self.conn.execute(
            "UPDATE runs SET status=?, ended_at=?, cost_usd=? WHERE adw_id=?",
            (status, now_iso(), round(cost_usd, 4), adw_id))
        self.event(adw_id, "run_end", status,
                   payload={"cost_usd": round(cost_usd, 4)})

    # ── phases ───────────────────────────────────────────────────────────
    def phase_start(self, adw_id: str, seq: int, name: str, kind: str,
                    retries: int = 0) -> str:
        """Declare une phase AVANT sa premiere tentative ; rend son phase_id."""
        phase_id = f"{adw_id}-{seq:02d}"
        self.conn.execute(
            "INSERT INTO phases (phase_id, adw_id, seq, name, kind, retries,"
            " started_at) VALUES (?,?,?,?,?,?,?) ON CONFLICT(phase_id) DO NOTHING",
            (phase_id, adw_id, seq, name, kind, retries, now_iso()))
        self.event(adw_id, "phase_start", name, phase_id=phase_id,
                   payload={"seq": seq, "kind": kind})
        return phase_id

    def phase_attempt(self, phase_id: str, adw_id: str, name: str,
                      attempt: int, ok: bool, error: str = "") -> None:
        """Le verdict d'une tentative tombe TOUT DE SUITE, jamais en fin de run.

        La ligne de phase garde le DERNIER etat connu ; le detail de chaque
        tentative vit dans events — rien ne s'ecrase, tout se relit.
        """
        status = "success" if ok else "fail"
        self.conn.execute(
            "UPDATE phases SET status=?, attempt=?, error=?, ended_at=?"
            " WHERE phase_id=?",
            (status, attempt, error, now_iso(), phase_id))
        payload = {"attempt": attempt}
        if error:
            payload["error"] = error
        self.event(adw_id, "phase_ok" if ok else "phase_fail", name,
                   phase_id=phase_id, payload=payload)


# ── lecture : le dernier run, sans client sqlite3 ────────────────────────
def last_run(db_path: Path = DB_PATH) -> int:
    """Relit le dernier run trace : verdict, phases, volume d'evenements."""
    if not Path(db_path).is_file():
        print("aucun journal — lancez un ADW, puis revenez", file=sys.stderr)
        return 1
    conn = sqlite3.connect(db_path)
    row = conn.execute(
        "SELECT adw_id, adw_name, request, status, cost_usd, started_at"
        " FROM runs ORDER BY started_at DESC LIMIT 1").fetchone()
    if row is None:
        print("journal vide — lancez un ADW, puis revenez", file=sys.stderr)
        return 1
    adw_id, adw_name, request, status, cost, started = row
    print(f"run {adw_id} ({adw_name}) — {status} — ~{cost:.4f} $ — {started}")
    print(f"  demande : {request or '—'}")
    for seq, name, kind, pstatus, attempt in conn.execute(
            "SELECT seq, name, kind, status, attempt FROM phases"
            " WHERE adw_id=? ORDER BY seq", (adw_id,)):
        print(f"  {seq:02d} {name:<22} {kind:<6} {pstatus:<8} tentative {attempt}")
    total = conn.execute("SELECT COUNT(*) FROM events WHERE adw_id=?",
                         (adw_id,)).fetchone()[0]
    print(f"  {total} evenements dans le journal")
    return 0


def selftest() -> int:
    """La gate du module : un run synthetique dans une base jetable, zero token."""
    with tempfile.TemporaryDirectory() as tmp:
        tracer = Tracer(db_path=Path(tmp) / "test.db",
                        jsonl_dir=Path(tmp) / "traces")
        tracer.run_start("selftest", "tracer_selftest", "auto-test du tracer")
        phase_id = tracer.phase_start("selftest", 1, "demo", "code")
        tracer.phase_attempt(phase_id, "selftest", "demo", 1, ok=True)
        tracer.run_finish("selftest", ok=True, cost_usd=0.0)
        runs = tracer.conn.execute("SELECT COUNT(*) FROM runs").fetchone()[0]
        events = tracer.conn.execute("SELECT COUNT(*) FROM events").fetchone()[0]
        status = tracer.conn.execute(
            "SELECT status FROM runs WHERE adw_id='selftest'").fetchone()[0]
        lines = (Path(tmp) / "traces" / "selftest.jsonl").read_text(
            encoding="utf-8").strip().splitlines()
        ok = (runs == 1 and events == 4 and status == "success"
              and len(lines) == events)
        print(f"tracer {'OK' if ok else 'KO'}{runs} run, {events} evenements,"
              f" {len(lines)} lignes JSONL, statut {status}")
        return 0 if ok else 1


if __name__ == "__main__":
    if "--last" in sys.argv:
        raise SystemExit(last_run())
    raise SystemExit(selftest())

Pièce — adws/adw_modules/runner.py

Cette version remplace celle du chapitre 8. Le squelette apprend à déclarer ce qu’il fait : run, phases, tentatives et verdicts partent au tracer au moment où ils se produisent. Tout le reste est inchangé : PhaseFailure, PhaseSpec, l’API de Run, les messages stderr et la ligne de bilan que lit le banc du chapitre 17. Vos ADW et adw_bench tournent tels quels.

"""runner — le squelette de l'usine : phases, sequencement, retries, traces.

Un ADW declare ses phases ; le runner les execute dans l'ordre, mesure,
retente les phases agent en session vivante, et rend un code retour.
Le succes se merite : toute PhaseFailure marque la tentative en echec,
et un run n'est vert que si toutes ses phases le sont.

Version chapitre 18 : chaque run laisse sa trace. Le runner declare le
run, chaque phase et chaque tentative au tracer AU MOMENT ou ils se
produisent — un run plante raconte son histoire jusqu'au gel. L'API ne
bouge pas : vos ADW des chapitres 8 a 17 tournent tels quels.
"""
from __future__ import annotations

import sys
import time
from dataclasses import dataclass, field
from pathlib import Path
from typing import Any, Callable

from .tracer import Tracer


class PhaseFailure(Exception):
    """L'echec motive d'une phase — le runner decide s'il retente."""


@dataclass(frozen=True)
class PhaseSpec:
    """Ce qu'un ADW declare : un nom, un cote de la couture, une action."""
    name: str
    kind: str                              # "agent" ou "code"
    action: Callable[["Run", int], Any]    # (run, tentative) -> resultat
    retries: int = 0                       # phases agent : reprises en session vivante


@dataclass
class Run:
    """L'etat partage d'un run : resultats des phases, sessions, cout."""
    adw_id: str
    results: dict[str, Any] = field(default_factory=dict)
    sessions: dict[str, str] = field(default_factory=dict)  # phase -> session_id
    cost_usd: float = 0.0
    tracer: Tracer | None = None    # injectable pour les tests ; None = journal standard

    def __post_init__(self) -> None:
        if self.tracer is None:
            self.tracer = Tracer()

    def execute(self, phases: list[PhaseSpec]) -> int:
        """Sequence les phases declarees. Arret a la premiere phase en echec definitif."""
        if not phases:
            print("aucune phase declaree — un ADW vide n'est pas un ADW", file=sys.stderr)
            return 1
        # Le nom de l'ADW et la demande sont releves sur la ligne de commande :
        # zero changement dans vos scripts, et la trace sait deja qui tourne.
        adw_name = Path(sys.argv[0]).stem if sys.argv and sys.argv[0] else ""
        request = " ".join(sys.argv[1:])[:500]
        self.tracer.run_start(self.adw_id, adw_name, request)
        for seq, spec in enumerate(phases, start=1):
            if spec.kind not in ("agent", "code"):
                print(f"[{self.adw_id}] {spec.name} : kind inconnu {spec.kind!r}",
                      file=sys.stderr)
                self.tracer.run_finish(self.adw_id, ok=False, cost_usd=self.cost_usd)
                return 1
            if not self._run_phase(seq, spec):
                print(f"[{self.adw_id}] ECHEC en phase {spec.name} — arret du run",
                      file=sys.stderr)
                self.tracer.run_finish(self.adw_id, ok=False, cost_usd=self.cost_usd)
                return 1
        # La ligne de bilan reste l'API de l'oeil et du banc (ch. 17) —
        # la trace s'ajoute, elle ne retire rien.
        print(f"[{self.adw_id}] run vert — cout total ~{self.cost_usd:.4f} $",
              file=sys.stderr)
        self.tracer.run_finish(self.adw_id, ok=True, cost_usd=self.cost_usd)
        return 0

    def _run_phase(self, seq: int, spec: PhaseSpec) -> bool:
        # Retenter une phase code n'a pas de sens : meme entree, meme sortie.
        # Seules les phases agent ont droit aux reprises — en session vivante.
        attempts = 1 + (spec.retries if spec.kind == "agent" else 0)
        phase_id = self.tracer.phase_start(self.adw_id, seq, spec.name,
                                           spec.kind, retries=attempts - 1)
        for attempt in range(attempts):
            clock = time.monotonic()
            label = f"{spec.name} ({spec.kind}, tentative {attempt + 1}/{attempts})"
            try:
                # L'action recoit le run (etat partage) et le numero de tentative :
                # a la tentative 1, une phase agent envoie la demande ; ensuite,
                # elle envoie la correction dans la MEME session.
                self.results[spec.name] = spec.action(self, attempt)
            except PhaseFailure as error:
                print(f"[{self.adw_id}] {label} : echec — {error}", file=sys.stderr)
                self.tracer.phase_attempt(phase_id, self.adw_id, spec.name,
                                          attempt + 1, ok=False, error=str(error))
                continue
            duration = time.monotonic() - clock
            print(f"[{self.adw_id}] {label} : OK en {duration:.1f} s", file=sys.stderr)
            self.tracer.phase_attempt(phase_id, self.adw_id, spec.name,
                                      attempt + 1, ok=True)
            return True
        return False

La gate du TP

Trois commandes, une par ligne, depuis la racine de plume-factory :

uv run adws/adw_modules/tracer.py
uv run adws/adw_prompt.py "Quels fichiers composent apps/plume ? Reponds en une phrase."
uv run adws/adw_modules/tracer.py --last

Attendu : la première imprime tracer OK — 1 run, 4 evenements, 4 lignes JSONL, statut success (zéro token), la deuxième trace un vrai run, la troisième le relit : run success, ses phases vertes, son coût. En tout : ~quelques centimes, ~1 minute, et votre usine ne perdra plus jamais la mémoire.


Quiz — teste tes connaissances
Observabilité 7 questions Objectif : 5/7 minimum
0/7
bonnes reponses
Objectif non atteint (minimum 5/7 requis).
Remonte relire la fiche memo en pretant attention aux points manques, puis cliquer sur « Recommencer » pour retenter.