Files
adam-acs/docs/troubleshooting/tr069-exchange-viewer.md
T
Kevin L'Hereec 0c83a4ccb2 feat: TR-069 Exchange Viewer - structured MongoDB storage with SSE streaming and sequence diagram UI
- MongoDB storage: cwmp_exchanges collection with indexes (deviceId+timestamp, deviceId+sequenceNumber unique, TTL 24h)
- ExchangeStoreService: CWMP method extraction, per-device queue for ordering, retry logic, message cap (5000/device)
- Exchange API: GET/DELETE/SSE stream endpoints with Last-Event-ID reconnection
- CwmpLoggerMiddleware: dual-write (MongoDB + legacy files) with fire-and-forget
- Frontend: SequenceViewer (CPE↔ACS lifelines, arrows, auto-scroll, virtual scroll) + InspectorPanel (formatted XML, copy, syntax highlighting)
- Tr069Trace page: integrated new viewer with col-6/col-6 layout
- DeviceDetail page: collapsible exchange section when device is traced
- 14 property-based tests, 40+ unit tests, 5 integration tests
- Health check includes index verification
- Config: feature flags, SSE timeouts, retry policy
2026-06-03 15:52:44 +02:00

487 lines
15 KiB
Markdown

# Troubleshooting Guide: TR-069 Exchange Viewer
Ce guide documente les problèmes courants du système de visualisation des échanges TR-069/CWMP, leurs causes et solutions.
## Table des matières
1. [Déconnexions SSE](#1-déconnexions-sse)
2. [Timeouts MongoDB et récupération](#2-timeouts-mongodb-et-récupération)
3. [Diagnostic de perte de messages](#3-diagnostic-de-perte-de-messages)
4. [Vérification des index et du TTL](#4-vérification-des-index-et-du-ttl)
5. [Problèmes frontend (SequenceViewer)](#5-problèmes-frontend-sequenceviewer)
6. [Feature flags et rollback](#6-feature-flags-et-rollback)
---
## 1. Déconnexions SSE
### 1.1 Causes courantes
| Cause | Symptôme | Fréquence |
|-------|----------|-----------|
| **Timeout d'inactivité (5 min)** | Déconnexion après 5 minutes sans nouvel échange | Normal — par design |
| **Timeout absolu (2 h)** | Déconnexion après 2 heures de connexion continue | Normal — par design |
| **Proxy/reverse-proxy buffering** | Messages SSE arrivent en burst au lieu de temps réel | Courant avec nginx |
| **Perte réseau** | Indicateur "disconnected" dans le viewer | Variable |
| **SSE désactivé (feature flag)** | Erreur 503 à la connexion SSE | Intentionnel |
| **Device non tracé** | Erreur 404 à la connexion SSE | Erreur utilisateur |
### 1.2 Solutions
#### Timeout d'inactivité / absolu
Le système est conçu pour fermer les connexions inactives. Le client se reconnecte automatiquement via le mécanisme `Last-Event-ID` — aucun message n'est perdu.
Pour ajuster les timeouts :
```bash
# Augmenter le timeout d'inactivité (défaut: 300000ms = 5 min)
EXCHANGE_STORE_SSE_INACTIVITY_TIMEOUT_MS=600000
# Augmenter le timeout absolu (défaut: 7200000ms = 2h)
EXCHANGE_STORE_SSE_ABSOLUTE_TIMEOUT_MS=14400000
```
#### Proxy/reverse-proxy buffering
Si un reverse-proxy (nginx, HAProxy) est en place, il peut bufferiser les réponses SSE. Le header `X-Accel-Buffering: no` est déjà envoyé par le serveur, mais vérifiez aussi la configuration nginx :
```nginx
location /api/v1/tr069-trace/ {
proxy_buffering off;
proxy_cache off;
proxy_set_header Connection '';
proxy_http_version 1.1;
chunked_transfer_encoding off;
}
```
#### Client qui ne se reconnecte pas
Le composable `useExchangeStream` utilise l'`EventSource` natif avec retry automatique (3 secondes par défaut). Si la reconnexion ne fonctionne pas :
1. Vérifiez que le device est toujours en trace active
2. Vérifiez les logs serveur pour des erreurs 404 ou 503
3. Vérifiez la valeur `retry` dans la configuration SSE :
```bash
# Intervalle de reconnexion envoyé au client (défaut: 3000ms)
EXCHANGE_STORE_SSE_RETRY_INTERVAL_MS=3000
```
### 1.3 Diagnostic dans les logs
Cherchez les entrées `[SSE]` dans les logs applicatifs :
```bash
docker compose logs app | grep '\[SSE\]'
```
Messages attendus :
- `[SSE] Connection closed { deviceId: "...", reason: "inactivity" }` — timeout normal
- `[SSE] Connection closed { deviceId: "...", reason: "absolute" }` — timeout absolu normal
- `[SSE] Connection closed { deviceId: "...", reason: "client_disconnect" }` — client a fermé
- `[SSE] Error fetching missed exchanges for reconnection` — problème MongoDB lors du rattrapage
---
## 2. Timeouts MongoDB et récupération
### 2.1 Scénarios de timeout
| Scénario | Impact | Comportement |
|----------|--------|--------------|
| **Write timeout (persistance)** | Message potentiellement perdu | Retry (critique) ou discard (non-critique) |
| **Read timeout (API >5s)** | Résultats partiels retournés | `isTruncated: true` dans la réponse |
| **Connection lost** | Toutes les opérations échouent | Les sessions CWMP continuent sans log |
### 2.2 Write timeout — Retry automatique
Le `ExchangeStoreService` gère les échecs d'écriture selon la criticité du message :
**Messages critiques** (Inform, GetParameterValues, SetParameterValuesResponse, Fault, etc.) :
- 3 tentatives avec backoff exponentiel : 1s, 2s, 4s
- Si toutes échouent : log error + discard (session CWMP non impactée)
**Messages non-critiques** (Empty, Unknown) :
- Aucun retry — discard immédiat + log warning
Vérifier les échecs de retry :
```bash
docker compose logs app | grep '\[ExchangeStore\] All retries exhausted'
docker compose logs app | grep '\[ExchangeStore\] Critical message persistence failed'
```
Pour ajuster la politique de retry :
```bash
# Nombre max de tentatives (défaut: 3)
EXCHANGE_STORE_RETRY_MAX_ATTEMPTS=3
# Délai de base en ms pour le backoff (défaut: 1000)
# Résultat : 1000ms, 2000ms, 4000ms
EXCHANGE_STORE_RETRY_BASE_DELAY_MS=1000
```
### 2.3 Read timeout — Résultats partiels
Si une requête API dépasse 5 secondes, le contrôleur retourne les résultats partiels avec un flag :
```json
{
"exchanges": [...],
"metadata": {
"isTruncated": true,
"total": 4500
}
}
```
**Causes courantes :**
- Index manquant sur `(deviceId, timestamp)` — voir section 4
- Trop de documents pour le device (proche du cap 5000)
- Charge MongoDB élevée (vérifier les métriques)
Pour ajuster le timeout de lecture :
```bash
# Timeout en ms (défaut: 5000)
EXCHANGE_STORE_READ_TIMEOUT_MS=5000
```
### 2.4 Vérifier la connectivité MongoDB
```bash
# Se connecter au shell MongoDB
docker compose exec mongodb mongosh
# Vérifier le statut
db.adminCommand({ serverStatus: 1 }).connections
# Vérifier la latence
db.adminCommand({ ping: 1 })
```
---
## 3. Diagnostic de perte de messages
### 3.1 Arbre de décision
```
Message manquant dans le viewer ?
│
├─ Le device est-il en trace ?
│ └─ Non → Activer la trace d'abord. Les messages ne sont PAS persistés hors trace.
│
├─ Le feature flag FEATURE_EXCHANGE_PERSISTENCE est-il à true ?
│ └─ Non → Activer la persistance : FEATURE_EXCHANGE_PERSISTENCE=true
│
├─ Le message apparaît-il dans MongoDB mais pas dans le viewer ?
│ └─ Oui → Problème SSE (voir section 1) ou problème frontend (voir section 5)
│
├─ Le message n'apparaît PAS dans MongoDB ?
│ ├─ Vérifier les logs de retry : grep "All retries exhausted"
│ ├─ Vérifier le cap (5000 messages) : les anciens messages sont supprimés
│ └─ Vérifier le TTL (24h) : les messages >24h sont auto-supprimés
│
└─ Message tronqué (XML incomplet) ?
└─ Le rawXml dépassait 2MB → grep "rawXml exceeds 2MB" dans les logs
```
### 3.2 Vérifier les messages en base
```bash
# Se connecter au shell MongoDB
docker compose exec mongodb mongosh
# Compter les messages pour un device
use adam_acs
db.cwmp_exchanges.countDocuments({ deviceId: "<DEVICE_ID>" })
# Voir les derniers messages
db.cwmp_exchanges.find({ deviceId: "<DEVICE_ID>" }).sort({ timestamp: -1 }).limit(5).pretty()
# Voir la séquence max (dernier message)
db.cwmp_exchange_counters.findOne({ _id: "<DEVICE_ID>" })
```
### 3.3 Vérifier les logs de persistance
```bash
# Chercher les erreurs de persistance
docker compose logs app | grep '\[ExchangeStore\]'
# Messages spécifiques
docker compose logs app | grep 'Failed to persist exchange'
docker compose logs app | grep 'Non-critical message persistence failed'
docker compose logs app | grep 'All retries exhausted'
docker compose logs app | grep 'Message cap enforced'
docker compose logs app | grep 'rawXml exceeds 2MB'
```
### 3.4 Message supprimé par le cap
Le système maintient un maximum de 5000 messages par device. Quand ce cap est dépassé, les messages les plus anciens sont supprimés.
```bash
# Vérifier si le cap a été atteint
docker compose logs app | grep 'Message cap enforced'
```
Pour ajuster le cap :
```bash
# Nombre max de messages par device (défaut: 5000)
EXCHANGE_STORE_MAX_MESSAGES=5000
```
### 3.5 Message supprimé par le TTL
MongoDB supprime automatiquement les documents dont `createdAt` dépasse 24 heures (via l'index TTL).
```bash
# Vérifier les documents les plus anciens
docker compose exec mongodb mongosh --eval "
use adam_acs;
db.cwmp_exchanges.find({}, { createdAt: 1, deviceId: 1 }).sort({ createdAt: 1 }).limit(3).pretty()
"
```
---
## 4. Vérification des index et du TTL
### 4.1 Lister les index existants
```bash
docker compose exec mongodb mongosh --eval "
use adam_acs;
db.cwmp_exchanges.getIndexes().forEach(idx => printjson(idx))
"
```
**Index attendus :**
| Nom | Champs | Options |
|-----|--------|---------|
| `_id_` | `{ _id: 1 }` | — |
| `idx_deviceId_timestamp` | `{ deviceId: 1, timestamp: 1 }` | — |
| `idx_deviceId_sequenceNumber` | `{ deviceId: 1, sequenceNumber: 1 }` | `unique: true` |
| `idx_createdAt_ttl` | `{ createdAt: 1 }` | `expireAfterSeconds: 86400` |
### 4.2 Vérifier l'index TTL
```bash
docker compose exec mongodb mongosh --eval "
use adam_acs;
const indexes = db.cwmp_exchanges.getIndexes();
const ttlIdx = indexes.find(i => i.name === 'idx_createdAt_ttl');
if (ttlIdx) {
print('TTL index OK — expireAfterSeconds:', ttlIdx.expireAfterSeconds);
} else {
print('ERREUR: TTL index manquant !');
}
"
```
### 4.3 Recréer les index manuellement (si manquants)
Si des index sont manquants après un incident :
```bash
docker compose exec mongodb mongosh --eval "
use adam_acs;
// Index composite (deviceId + timestamp)
db.cwmp_exchanges.createIndex(
{ deviceId: 1, timestamp: 1 },
{ name: 'idx_deviceId_timestamp' }
);
// Index unique (deviceId + sequenceNumber)
db.cwmp_exchanges.createIndex(
{ deviceId: 1, sequenceNumber: 1 },
{ unique: true, name: 'idx_deviceId_sequenceNumber' }
);
// Index TTL (24h)
db.cwmp_exchanges.createIndex(
{ createdAt: 1 },
{ expireAfterSeconds: 86400, name: 'idx_createdAt_ttl' }
);
print('Tous les index recréés.');
"
```
### 4.4 Vérifier le statut du TTL monitor
Le TTL monitor de MongoDB tourne par défaut toutes les 60 secondes. Pour vérifier qu'il fonctionne :
```bash
docker compose exec mongodb mongosh --eval "
const status = db.adminCommand({ serverStatus: 1 });
print('TTL deletedDocuments:', status.metrics.ttl.deletedDocuments);
print('TTL passes:', status.metrics.ttl.passes);
"
```
Si `passes` n'augmente pas, le TTL monitor pourrait être bloqué (rare, nécessite un restart MongoDB).
### 4.5 Modifier le TTL
Pour changer la durée du TTL sans recréer l'index :
```bash
docker compose exec mongodb mongosh --eval "
use adam_acs;
db.runCommand({
collMod: 'cwmp_exchanges',
index: {
name: 'idx_createdAt_ttl',
expireAfterSeconds: 172800 // 48h
}
});
"
```
N'oubliez pas de mettre à jour la variable d'environnement pour cohérence :
```bash
EXCHANGE_STORE_TTL_SECONDS=172800
```
### 4.6 Vérifier la collection counters
La collection `cwmp_exchange_counters` stocke les séquences atomiques par device :
```bash
docker compose exec mongodb mongosh --eval "
use adam_acs;
db.cwmp_exchange_counters.find().forEach(doc => {
print(doc._id, '→ seq:', doc.seq);
})
"
```
Si un compteur est incohérent avec les données réelles :
```bash
# Recalculer le max sequenceNumber pour un device
docker compose exec mongodb mongosh --eval "
use adam_acs;
const deviceId = '<DEVICE_ID>';
const maxSeq = db.cwmp_exchanges.find({ deviceId }).sort({ sequenceNumber: -1 }).limit(1).toArray();
if (maxSeq.length > 0) {
db.cwmp_exchange_counters.updateOne(
{ _id: deviceId },
{ \$set: { seq: maxSeq[0].sequenceNumber } }
);
print('Counter reset to', maxSeq[0].sequenceNumber);
}
"
```
---
## 5. Problèmes frontend (SequenceViewer)
### 5.1 Le viewer ne se connecte pas au SSE
**Causes possibles :**
1. Le device n'est pas en trace → activer la trace d'abord
2. Le feature flag `FEATURE_SSE_ENABLED` est à `false` → erreur 503
3. Problème CORS si accès depuis un domaine différent
**Diagnostic :** Ouvrir la console navigateur (F12) et chercher les erreurs EventSource.
### 5.2 Les messages ne s'affichent pas en temps réel
Si les messages arrivent dans MongoDB mais pas dans le viewer :
1. Vérifier l'indicateur de connexion : doit être "connected" (vert)
2. Si "disconnected" (rouge) : voir section 1
3. Si "paused" (jaune) : l'auto-scroll est désactivé car l'utilisateur a scrollé vers le haut — cliquer "Resume auto-scroll"
### 5.3 Performance lente avec beaucoup de messages
Le viewer utilise du virtual scrolling pour >200 messages. Si la performance se dégrade :
- Le cap client est fixé à 1000 messages en mémoire (les plus anciens sont purgés côté client)
- Si le nombre total dépasse 5000 en base, les plus anciens sont purgés côté serveur
- Utiliser "Clear exchanges" pour repartir d'un état vide
### 5.4 L'inspecteur XML affiche du contenu brut (non formaté)
Si le XML n'est pas mis en forme :
- Le XML est peut-être malformé → l'inspecteur affiche le contenu brut en fallback
- Vérifier si le message a un `rawXml` vide (cas "Empty")
---
## 6. Feature flags et rollback
### 6.1 Flags disponibles
| Variable d'environnement | Défaut | Effet si `false`/`file` |
|--------------------------|--------|-------------------------|
| `FEATURE_EXCHANGE_PERSISTENCE` | `true` | Les échanges ne sont pas écrits en MongoDB |
| `FEATURE_SSE_ENABLED` | `true` | L'endpoint SSE retourne 503, le client utilise le REST polling (5s) |
| `FEATURE_EXCHANGE_API_SOURCE` | `mongodb` | Si `file`, l'API lit depuis l'ancien système de fichiers |
### 6.2 Procédure de rollback rapide
En cas de problème critique :
```bash
# 1. Désactiver la persistance (les sessions CWMP continuent normalement)
FEATURE_EXCHANGE_PERSISTENCE=false
# 2. Désactiver le SSE (le frontend utilise le polling REST)
FEATURE_SSE_ENABLED=false
# 3. Revenir à la source fichier pour l'API
FEATURE_EXCHANGE_API_SOURCE=file
```
Redémarrer l'application après modification :
```bash
docker compose restart app
```
### 6.3 Vérifier l'état actuel des flags
Les valeurs actives sont loguées au démarrage de l'application. Vous pouvez aussi interroger le health check :
```bash
curl -s http://localhost:8080/api/v1/health/tr069-exchanges | python3 -m json.tool
```
---
## Commandes utiles — Résumé rapide
```bash
# Status général
docker compose logs app --tail 20 | grep -E '\[ExchangeStore\]|\[SSE\]'
# Compter les échanges d'un device
docker compose exec mongodb mongosh --eval "use adam_acs; db.cwmp_exchanges.countDocuments({deviceId:'<ID>'})"
# Vérifier les index
docker compose exec mongodb mongosh --eval "use adam_acs; db.cwmp_exchanges.getIndexes().forEach(i=>printjson(i))"
# Vérifier le TTL monitor
docker compose exec mongodb mongosh --eval "printjson(db.adminCommand({serverStatus:1}).metrics.ttl)"
# Tester la connexion SSE manuellement
curl -N -H "Accept: text/event-stream" http://localhost:8080/api/v1/tr069-trace/<DEVICE_ID>/exchanges/stream
# Tester la reconnexion avec Last-Event-ID
curl -N -H "Accept: text/event-stream" -H "Last-Event-ID: 42" http://localhost:8080/api/v1/tr069-trace/<DEVICE_ID>/exchanges/stream
# Purger les échanges d'un device
curl -X DELETE http://localhost:8080/api/v1/tr069-trace/<DEVICE_ID>/exchanges
```