From 74a0052431ae913b0e04f64c7f8db93cf542915e Mon Sep 17 00:00:00 2001 From: Nicolas Date: Tue, 25 Aug 2026 21:34:40 +0200 Subject: [PATCH] feat(recipes): journalise chaque input/output du pipeline NLP MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Ajoute un logging JSON structure (meme convention que LoggerService cote apps/api) a services/tech-step-intent-service : chaque appel POST /v1/process journalise locale/texte en entree et entites/intent/score en sortie, chaque POST /v1/train journalise les uid entraines et les compteurs resultants. Chatter interne de spaCy mis a WARNING pour ne pas noyer ces lignes. Bug trouve et corrige en verifiant les octets bruts d'un log reel (pas juste son affichage terminal) : l'encodage par defaut de sys.stdout sur Windows produisait de vrais octets UTF-8 invalides pour tout texte accentue journalise (le francais des etapes de recette) — corrige par sys.stdout.reconfigure(encoding="utf-8") au demarrage. LOG_LEVEL configurable (INFO par defaut), documente dans le README du service et .env.example. Verifie : 30/30 pytest (3 nouveaux tests sur le formateur JSON), smoke test HTTP reel confirmant au niveau des octets que les caracteres accentues sont preserves, lint complet du monorepo. Co-Authored-By: Claude Sonnet 5 --- .../tech-step-intent-service/.env.example | 6 ++ services/tech-step-intent-service/README.md | 16 ++++ .../intent_service/config.py | 7 ++ .../intent_service/logging_config.py | 76 +++++++++++++++++++ .../intent_service/main.py | 7 ++ .../intent_service/pipeline_registry.py | 6 ++ .../intent_service/routes/process.py | 20 +++++ .../intent_service/routes/train.py | 20 +++++ .../tests/test_logging_config.py | 56 ++++++++++++++ 9 files changed, 214 insertions(+) create mode 100644 services/tech-step-intent-service/intent_service/logging_config.py create mode 100644 services/tech-step-intent-service/tests/test_logging_config.py diff --git a/services/tech-step-intent-service/.env.example b/services/tech-step-intent-service/.env.example index c2599f6..71df986 100644 --- a/services/tech-step-intent-service/.env.example +++ b/services/tech-step-intent-service/.env.example @@ -3,3 +3,9 @@ # apps/api/.env (voir apps/api/src/config/env.ts). Requis, pas de valeur par # défaut : `Settings` (intent_service/config.py) refuse de démarrer sans. INTENT_SERVICE_SECRET=changeme-generate-a-real-random-secret-at-least-32-chars + +# Optionnel — niveau du logging JSON structuré (intent_service/logging_config.py). +# INFO par défaut : chaque appel /v1/process et /v1/train journalise son +# input (locale/texte, entrées d'entraînement) et son output (entités, +# intent, score) à ce niveau. +# LOG_LEVEL=INFO diff --git a/services/tech-step-intent-service/README.md b/services/tech-step-intent-service/README.md index fa4fb36..b501bc6 100644 --- a/services/tech-step-intent-service/README.md +++ b/services/tech-step-intent-service/README.md @@ -56,6 +56,22 @@ Voir `intent_service/schemas.py` pour le détail exact. En résumé : (voir `intent_service/security.py`), qui doit matcher `INTENT_SERVICE_SECRET` côté `apps/api`. +## Logs + +`intent_service/logging_config.py` branche un format JSON structuré (une +ligne par évènement — `timestamp`/`level`/`message` + champs métier fusionnés +— même convention que `LoggerService` côté `apps/api`) sur toute la +journalisation de ce service, niveau `LOG_LEVEL` (`INFO` par défaut, voir +`.env.example`). `routes/process.py` et `routes/train.py` journalisent +chaque appel avec son input et son output complets : + +```json +{"timestamp": "...", "level": "info", "message": "tech-step NLP process", "locale": "fr", "text": "faire fondre le beurre", "entities": [{"uid": "melt", "start": 6, "end": 13}], "intent": "melt", "score": 0.93} +``` + +Le chatter interne de spaCy (`"spacy"` logger — chargement de vocabulaire, +etc.) est explicitement mis à `WARNING` pour ne pas noyer ces lignes. + ## Setup Ce service utilise [`uv`](https://docs.astral.sh/uv/) pour ses dépendances diff --git a/services/tech-step-intent-service/intent_service/config.py b/services/tech-step-intent-service/intent_service/config.py index e5c0475..4e2c492 100644 --- a/services/tech-step-intent-service/intent_service/config.py +++ b/services/tech-step-intent-service/intent_service/config.py @@ -40,5 +40,12 @@ class Settings(BaseSettings): # jamais lu depuis `Settings` — une variable d'env dupliquant ce que la # commande de démarrage fixe déjà explicitement n'aurait aucun lecteur. + # Niveau du logging structuré (`logging_config.py`) — voir ce module pour + # le format. `INFO` par défaut : c'est à ce niveau que `routes/process.py` + # et `routes/train.py` journalisent chaque input/output du pipeline NLP, + # pour qu'un déploiement par défaut les voie sans configuration + # supplémentaire (`docker logs`/Portainer). + log_level: str = "INFO" + settings = Settings() diff --git a/services/tech-step-intent-service/intent_service/logging_config.py b/services/tech-step-intent-service/intent_service/logging_config.py new file mode 100644 index 0000000..9019662 --- /dev/null +++ b/services/tech-step-intent-service/intent_service/logging_config.py @@ -0,0 +1,76 @@ +"""Logging structuré — même convention que `LoggerService` côté `apps/api` +(`apps/api/src/lib/logger.service.ts`) : une ligne JSON par évènement +(`timestamp`, `level`, `message`, + le reste des champs fournis fusionné), +jamais du texte libre, pour rester grep/parse-able par `docker logs`/ +Portainer ou un agrégateur de logs — cohérent avec le reste du repo plutôt +qu'un format propre à ce seul service. + +Configuré une fois au démarrage (`main.py`) plutôt que par un `print()` ad +hoc dans chaque route — `routes/process.py`/`routes/train.py` appellent +`logging.getLogger(__name__)` normalement, ce module ne fait que brancher le +formateur JSON sur la racine du logging Python. +""" + +import json +import logging +import sys +from datetime import UTC, datetime +from typing import Any + + +class _JsonFormatter(logging.Formatter): + """Sérialise chaque `LogRecord` en une ligne JSON. Les champs + supplémentaires passés via `logger.info(msg, extra={...})` sont fusionnés + tels quels dans l'objet — c'est ce que `routes/process.py` utilise pour + joindre `locale`/`text`/`entities`/`intent`/`score` à la ligne.""" + + # Attributs standards de `LogRecord` — tout le reste posé sur le record + # (via `extra=`) est un champ métier ajouté par l'appelant, à fusionner + # dans la sortie JSON. + _STANDARD_ATTRS = frozenset(logging.LogRecord("", 0, "", 0, "", None, None).__dict__.keys()) + + def format(self, record: logging.LogRecord) -> str: + payload: dict[str, Any] = { + "timestamp": datetime.fromtimestamp(record.created, tz=UTC).isoformat(), + "level": record.levelname.lower(), + "message": record.getMessage(), + } + extra_fields = { + key: value for key, value in record.__dict__.items() if key not in self._STANDARD_ATTRS + } + payload.update(extra_fields) + if record.exc_info: + payload["error"] = self.formatException(record.exc_info) + return json.dumps(payload, ensure_ascii=False, default=str) + + +def configure_logging(level: str) -> None: + """Branche le formateur JSON sur la racine du logging Python — appelé + une fois au démarrage (`main.py`), avant que `routes/*` ne journalisent + quoi que ce soit.""" + # L'encodage par défaut de `sys.stdout` suit la locale de l'OS/console, + # pas forcément UTF-8 — sur Windows en particulier, garder ce défaut + # produit de vrais octets invalides (pas juste un affichage terminal + # trompeur) pour tout texte accentué journalisé par `routes/process.py` + # (le texte réel des étapes de recette, en français) — trouvé en + # vérifiant les octets bruts d'un log réel, pas juste son affichage. + # `reconfigure` existe sur `sys.stdout` dans toute exécution Python + # normale (pas dans certains contextes embarqués/redirigés exotiques) — + # protégé par `hasattr` pour ne jamais faire planter le démarrage pour un + # souci de confort d'affichage. + if hasattr(sys.stdout, "reconfigure"): + sys.stdout.reconfigure(encoding="utf-8") + handler = logging.StreamHandler(sys.stdout) + handler.setFormatter(_JsonFormatter()) + root = logging.getLogger() + root.handlers = [handler] + root.setLevel(level) + + # spaCy/thinc journalisent leur propre chatter interne ("Created + # vocabulary", "Finished initializing nlp object"...) sur le logger + # `"spacy"`, qui propage jusqu'à la racine et se retrouverait donc + # mélangé aux lignes input/output de `routes/process.py`/`routes/train.py` + # — ce sont ces dernières que ce service existe pour rendre visibles, pas + # le détail interne de spaCy. `WARNING` laisse quand même remonter un + # vrai problème (dépréciation, échec partiel) sans le bruit `INFO`. + logging.getLogger("spacy").setLevel(logging.WARNING) diff --git a/services/tech-step-intent-service/intent_service/main.py b/services/tech-step-intent-service/intent_service/main.py index ec1fa10..9f8d95d 100644 --- a/services/tech-step-intent-service/intent_service/main.py +++ b/services/tech-step-intent-service/intent_service/main.py @@ -12,9 +12,16 @@ from contextlib import asynccontextmanager from fastapi import FastAPI +from .config import settings +from .logging_config import configure_logging from .pipeline_registry import registry from .routes import health, process, train +# Avant tout le reste : `routes/process.py`/`routes/train.py` journalisent +# dès la première requête, `preload_all()` ci-dessous journalise aussi (voir +# `pipeline_registry.py`) — le formateur JSON doit déjà être en place. +configure_logging(settings.log_level) + @asynccontextmanager async def lifespan(app: FastAPI): diff --git a/services/tech-step-intent-service/intent_service/pipeline_registry.py b/services/tech-step-intent-service/intent_service/pipeline_registry.py index d3c9cbd..1f35dfe 100644 --- a/services/tech-step-intent-service/intent_service/pipeline_registry.py +++ b/services/tech-step-intent-service/intent_service/pipeline_registry.py @@ -10,8 +10,12 @@ requête — même séparation de responsabilité que `TechStepClassifierService via node-nlp, explicitée ici puisque spaCy charge un modèle par langue. """ +import logging + from .locale_pipeline import SUPPORTED_LOCALES, LocalePipeline, ProcessResult, TrainEntry, UnsupportedLocaleError +logger = logging.getLogger(__name__) + class PipelineRegistry: def __init__(self) -> None: @@ -24,8 +28,10 @@ class PipelineRegistry: une fois au démarrage du process (`main.py`), pas paresseusement au premier appel, pour que `GET /health` ne réponde `200` qu'une fois ce coût payé (voir `LocalePipeline.preload`).""" + logger.info("tech-step NLP preloading base pipelines", extra={"locales": list(self._pipelines)}) for pipeline in self._pipelines.values(): pipeline.preload() + logger.info("tech-step NLP base pipelines ready", extra={"locales": list(self._pipelines)}) def train(self, locale: str, entries: list[TrainEntry]) -> tuple[int, int, int]: pipeline = self._pipelines.get(locale) diff --git a/services/tech-step-intent-service/intent_service/routes/process.py b/services/tech-step-intent-service/intent_service/routes/process.py index 99a0b19..8596266 100644 --- a/services/tech-step-intent-service/intent_service/routes/process.py +++ b/services/tech-step-intent-service/intent_service/routes/process.py @@ -4,18 +4,38 @@ en remplacement direct de l'ancien `NlpManager.process(locale, text)`. Voir `text` vide -> résultat vide, jamais une erreur). """ +import logging + from fastapi import APIRouter, Depends from ..pipeline_registry import registry from ..schemas import EntityPayload, ProcessRequest, ProcessResponse from ..security import require_valid_secret +logger = logging.getLogger(__name__) + router = APIRouter(dependencies=[Depends(require_valid_secret)]) @router.post("/v1/process", response_model=ProcessResponse) def process(request: ProcessRequest) -> ProcessResponse: result = registry.process(request.locale, request.text) + + # Une ligne par appel — input (`locale`/`text`) et output (`entities`/ + # `intent`/`score`) réunis dans la même ligne JSON, pour pouvoir suivre + # exactement ce que le pipeline a décidé pour un texte donné (voir + # `logging_config.py` pour le format). + logger.info( + "tech-step NLP process", + extra={ + "locale": request.locale, + "text": request.text, + "entities": [{"uid": entity.uid, "start": entity.start, "end": entity.end} for entity in result.entities], + "intent": result.intent, + "score": result.score, + }, + ) + return ProcessResponse( entities=[EntityPayload(uid=entity.uid, start=entity.start, end=entity.end) for entity in result.entities], intent=result.intent, diff --git a/services/tech-step-intent-service/intent_service/routes/train.py b/services/tech-step-intent-service/intent_service/routes/train.py index 56b3535..cd0795c 100644 --- a/services/tech-step-intent-service/intent_service/routes/train.py +++ b/services/tech-step-intent-service/intent_service/routes/train.py @@ -5,6 +5,8 @@ locale. Voir `LocalePipeline.train` pour ce que "reconstruit à neuf" signifie concrètement. """ +import logging + from fastapi import APIRouter, Depends, HTTPException, status from ..locale_pipeline import TrainEntry, UnsupportedLocaleError @@ -12,6 +14,8 @@ from ..pipeline_registry import registry from ..schemas import TrainRequest, TrainResponse from ..security import require_valid_secret +logger = logging.getLogger(__name__) + router = APIRouter(dependencies=[Depends(require_valid_secret)]) @@ -21,15 +25,31 @@ def train(request: TrainRequest) -> TrainResponse: TrainEntry(uid=entry.uid, synonyms=entry.synonyms, utterances=entry.utterances) for entry in request.entries ] + + logger.info( + "tech-step NLP train starting", + extra={"locale": request.locale, "uids": [entry.uid for entry in entries]}, + ) try: label_count, utterance_count, synonym_count = registry.train(request.locale, entries) except UnsupportedLocaleError as err: + logger.warning("tech-step NLP train rejected", extra={"locale": request.locale, "error": str(err)}) # 422, pas 500 : une locale non supportée dans une requête de # `apps/api` est une erreur de configuration/version-skew entre les # deux services (voir le contrat documenté dans le plan de # migration), pas un échec inattendu du service lui-même. raise HTTPException(status_code=status.HTTP_422_UNPROCESSABLE_ENTITY, detail=str(err)) from err + logger.info( + "tech-step NLP train done", + extra={ + "locale": request.locale, + "labelCount": label_count, + "utteranceCount": utterance_count, + "synonymCount": synonym_count, + }, + ) + return TrainResponse( locale=request.locale, label_count=label_count, diff --git a/services/tech-step-intent-service/tests/test_logging_config.py b/services/tech-step-intent-service/tests/test_logging_config.py new file mode 100644 index 0000000..ad85bf1 --- /dev/null +++ b/services/tech-step-intent-service/tests/test_logging_config.py @@ -0,0 +1,56 @@ +"""Vérifie le format des lignes de log produites par +`logging_config._JsonFormatter` — ce que `routes/process.py`/`routes/train.py` +utilisent pour journaliser l'input/l'output de chaque appel NLP.""" + +import json +import logging + +from intent_service.logging_config import _JsonFormatter + + +def _make_record(**extra: object) -> logging.LogRecord: + record = logging.LogRecord( + name="intent_service.routes.process", + level=logging.INFO, + pathname=__file__, + lineno=1, + msg="tech-step NLP process", + args=(), + exc_info=None, + ) + for key, value in extra.items(): + setattr(record, key, value) + return record + + +def test_formats_a_record_as_json_with_timestamp_level_and_message(): + record = _make_record() + payload = json.loads(_JsonFormatter().format(record)) + assert payload["message"] == "tech-step NLP process" + assert payload["level"] == "info" + assert "timestamp" in payload + + +def test_merges_extra_fields_into_the_top_level_payload(): + record = _make_record( + locale="fr", + text="faire fondre le beurre", + entities=[{"uid": "melt", "start": 0, "end": 12}], + intent="melt", + score=0.93, + ) + payload = json.loads(_JsonFormatter().format(record)) + assert payload["locale"] == "fr" + assert payload["text"] == "faire fondre le beurre" + assert payload["entities"] == [{"uid": "melt", "start": 0, "end": 12}] + assert payload["intent"] == "melt" + assert payload["score"] == 0.93 + + +def test_preserves_accented_characters_literally_not_escaped(): + # `ensure_ascii=False` — un `docker logs` humain doit pouvoir lire + # directement "poêle", pas "poêle". + record = _make_record(text="Dans une poêle chaude") + line = _JsonFormatter().format(record) + assert "poêle" in line + assert "\\u00ea" not in line