Diagnostic : le lecteur remonte ses freezes dans les logs du serveur

Les freezes (image et son figés puis reprise) se produisent dans le
navigateur de l'utilisateur ; le serveur n'en voyait rien. Le lecteur
envoie désormais chaque coupure (durée, buffer), saut (de → vers),
erreur MPEG-TS/HLS, recréation, repli HLS et changement de profil, plus
un bilan toutes les 60 s, à POST /api/player-log (authentifié). Le
serveur écrit une ligne « [Player] … » par événement.

Entrée filtrée : événements et champs connus seulement, texte borné,
URL masquées (une erreur réseau peut recopier les identifiants Xtream),
pas d'injection de lignes. Envoi jamais bloquant pour la lecture.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

bin/api/player_log.dart

@@ -0,0 +1,70 @@
+import 'dart:convert';
+
+import 'package:shelf/shelf.dart';
+
+/// Journal des incidents de lecture remontés par le lecteur web.
+///
+/// POURQUOI : les freezes (image et son figés puis reprise) se produisent
+/// chez l'utilisateur, dans son navigateur ; le serveur n'en voit rien. Le
+/// lecteur envoie ici chaque coupure, erreur, recréation et saut, et le
+/// serveur les écrit dans `docker logs` (`[Player] …`) : on sait alors si un
+/// freeze vient d'un buffer à sec, d'une erreur du démuxeur ou d'une
+/// relance du flux.
+///
+/// Entrée non fiable : seuls des champs connus, courts et typés passent.
+
+const _events = {
+  'start', 'first_frame', 'stall', 'seek', 'mpegts_error', 'recreate',
+  'fallback_hls', 'hls_error', 'profile', 'error_shown', 'heartbeat',
+};
+
+const _numericFields = {
+  't', 'ms', 'buffer', 'pos', 'from', 'to', 'stalls', 'stallMs', 'seeks',
+  'errors', 'rate',
+};
+
+const _textFields = {'session', 'ch', 'mode', 'profile', 'detail'};
+
+/// Ligne de journal pour l'événement [raw], ou null s'il est invalide.
+String? formatPlayerEvent(Object? raw) {
+  if (raw is! Map) return null;
+  final event = raw['event'];
+  if (event is! String || !_events.contains(event)) return null;
+
+  final parts = <String>[event];
+  for (final key in _textFields) {
+    final value = raw[key];
+    if (value is String && value.isNotEmpty) {
+      // Ni espace, ni retour ligne, ni URL : jamais d'injection de faux
+      // journaux, jamais d'identifiants recopiés depuis une URL d'erreur.
+      final safe = value
+          .replaceAll(RegExp(r'https?://\S+'), '<url>')
+          .replaceAll(RegExp(r'[^\w.\-:/<>]'), '_');
+      parts.add('$key=${safe.length > 60 ? safe.substring(0, 60) : safe}');
+    }
+  }
+  for (final key in _numericFields) {
+    final value = raw[key];
+    if (value is num && value.isFinite) {
+      parts.add('$key=${value is int ? value : value.toStringAsFixed(1)}');
+    }
+  }
+  return '[Player] ${parts.join(' ')}';
+}
+
+Future<Response> handlePlayerLog(Request request) async {
+  final body = await request.readAsString();
+  if (body.length > 4096) return Response(413);
+  Object? decoded;
+  try {
+    decoded = jsonDecode(body);
+  } catch (_) {
+    return Response.badRequest();
+  }
+  final events = decoded is List ? decoded.take(20) : [decoded];
+  for (final event in events) {
+    final line = formatPlayerEvent(event);
+    if (line != null) print(line);
+  }
+  return Response(204);
+}

bin/server.dart

@@ -29,6 +29,7 @@ import 'services/cleanup_service.dart';
 import 'services/recording_scheduler.dart';
 import 'utils/asset_versioning.dart';
 import 'api/upstream_probe.dart';
+import 'api/player_log.dart';
 
 void main(List<String> args) async {
   // Parse command line arguments
@@ -221,6 +222,14 @@ void main(List<String> args) async {
           .addMiddleware(authMiddleware(db))
           .addHandler(logoApi.handle),
     )
+    // Incidents de lecture remontés par le lecteur web (freezes, erreurs),
+    // écrits dans les logs pour le diagnostic.
+    ..post(
+      '/api/player-log',
+      const Pipeline()
+          .addMiddleware(authMiddleware(db))
+          .addHandler(handlePlayerLog),
+    )
     // EPG - guide TV (auth required)
     ..mount(
       '/api/epg',

bin/test/player_log_test.dart

@@ -0,0 +1,47 @@
+import 'package:test/test.dart';
+import '../api/player_log.dart';
+
+void main() {
+  group('formatPlayerEvent', () {
+    test('écrit une coupure avec sa durée et le buffer', () {
+      expect(
+        formatPlayerEvent({
+          'event': 'stall',
+          'session': 'ab12',
+          'ch': '554034',
+          'ms': 5230,
+          'buffer': 0.04,
+        }),
+        '[Player] stall session=ab12 ch=554034 ms=5230 buffer=0.0',
+      );
+    });
+
+    test('refuse un événement inconnu ou un payload invalide', () {
+      expect(formatPlayerEvent({'event': 'rm -rf'}), isNull);
+      expect(formatPlayerEvent('stall'), isNull);
+      expect(formatPlayerEvent(null), isNull);
+    });
+
+    test('pas d\'injection de lignes ni d\'URL (identifiants Xtream)', () {
+      final line = formatPlayerEvent({
+        'event': 'mpegts_error',
+        'detail': 'NetworkError http://panel/live/user/pass/1.ts\n[Player] faux',
+      })!;
+      expect(line, isNot(contains('\n')));
+      expect(line, isNot(contains('user/pass')));
+      expect(line, contains('<url>'));
+    });
+
+    test('ignore les champs inattendus et les nombres non finis', () {
+      final line = formatPlayerEvent({
+        'event': 'seek',
+        'from': 10,
+        'to': double.infinity,
+        'cookie': 'secret',
+      })!;
+      expect(line, contains('from=10'));
+      expect(line, isNot(contains('to=')));
+      expect(line, isNot(contains('secret')));
+    });
+  });
+}

test/web/xf_player_core_test.mjs

@@ -101,6 +101,54 @@ test('live : le retard est résorbé en douceur (liveSync) plutôt que par sauts
   assert.ok(c.liveSyncMaxLatency <= c.liveBufferLatencyMaxLatency);
 });
 
+test('télémétrie : une coupure (waiting → playing) est remontée avec sa durée', async () => {
+  const sent = [];
+  const listeners = {};
+  const video = {
+    addEventListener(type, fn) { (listeners[type] ||= []).push(fn); },
+    removeEventListener() {},
+    canPlayType: () => '',
+    play: () => Promise.resolve(),
+    buffered: { length: 0 },
+    seekable: { length: 0 },
+    currentTime: 12,
+    playbackRate: 1,
+  };
+  const fire = (type) => (listeners[type] || []).forEach((fn) => fn());
+  const window = {
+    addEventListener() {}, removeEventListener() {},
+    console: { log() {} },
+    location: { origin: 'https://xf.test', href: 'https://xf.test/', search: '' },
+    parent: { postMessage() {} },
+    localStorage: { getItem: () => 'tok' },
+  };
+  let now = 1000;
+  const context = vm.createContext({
+    window,
+    location: window.location,
+    document: { addEventListener() {}, removeEventListener() {} },
+    URLSearchParams,
+    setInterval: () => 0,
+    clearInterval() {},
+    setTimeout,
+    Date: { now: () => now },
+    fetch: (url, opts) => { sent.push({ url, body: JSON.parse(opts.body) }); return Promise.resolve(); },
+  });
+  vm.runInContext(source, context);
+  const player = new window.XFPlayer({ video, url: '/api/live/554034/turbo.ts', type: 'live' });
+  player._wireVideoEvents();
+
+  fire('playing');            // premier affichage
+  now += 1000; fire('waiting');
+  now += 4200; fire('playing'); // reprise 4,2 s plus tard
+
+  const stall = sent.map((s) => s.body).find((b) => b.event === 'stall');
+  assert.ok(stall, 'aucun événement stall envoyé');
+  assert.equal(stall.ms, 4200);
+  assert.equal(stall.ch, '554034');
+  assert.equal(sent[0].url, '/api/player-log');
+});
+
 test('live : le buffer déjà lu est purgé (sinon QuotaExceeded en séance longue)', () => {
   const c = liveMpegtsConfig();
   assert.equal(c.autoCleanupSourceBuffer, true);

web/xf-player-core.js

@@ -190,8 +190,75 @@
     // ça, une relance après échec laisserait l'ancienne instance réagir aux
     // commandes du parent et republier des positions périmées.
     this._listeners = [];
+
+    // Télémétrie des incidents (voir _report) : chaque freeze vécu par
+    // l'utilisateur finit dans les logs du serveur, avec sa cause.
+    this._t0 = Date.now();
+    this._session = Math.random().toString(36).slice(2, 8);
+    var idMatch = /\/api\/(?:live|vod|recordings\/stream)\/([^/?#.]+)/.exec(this.url || '');
+    this._channel = idMatch ? idMatch[1] : '';
+    this._stallSince = null;
+    this._stats = { stalls: 0, stallMs: 0, seeks: 0, errors: 0 };
+    this._lastPos = 0;
+    var self = this;
+    var userOnError = this.onError;
+    this.onError = function (msg) {
+      self._report('error_shown', { detail: String(msg) });
+      userOnError(msg);
+    };
   }
 
+  // ---------------- Télémétrie ----------------
+
+  /** Secondes d'avance dans le buffer à la position courante. */
+  XFPlayer.prototype._bufferAhead = function () {
+    var v = this.video;
+    try {
+      for (var i = 0; i < v.buffered.length; i++) {
+        if (v.buffered.start(i) <= v.currentTime + 0.5 &&
+            v.buffered.end(i) >= v.currentTime) {
+          return v.buffered.end(i) - v.currentTime;
+        }
+      }
+    } catch (e) {}
+    return 0;
+  };
+
+  /**
+   * Remonte un incident au serveur (`POST /api/player-log`, écrit dans les
+   * logs `[Player] …`). Jamais bloquant : erreurs ignorées, aucun envoi
+   * sans session.
+   */
+  XFPlayer.prototype._report = function (event, data) {
+    try {
+      var token = null;
+      try { token = global.localStorage.getItem('auth_token'); } catch (e) {}
+      if (!token || typeof fetch !== 'function') return;
+      var payload = {
+        event: event,
+        session: this._session,
+        ch: this._channel,
+        t: (Date.now() - this._t0) / 1000,
+        mode: this.hls ? 'hls' : (this.mpegts ? 'ts' : 'direct'),
+        profile: this.profile.name,
+        buffer: this._bufferAhead(),
+        pos: this.video.currentTime || 0
+      };
+      for (var k in data) {
+        if (Object.prototype.hasOwnProperty.call(data, k)) payload[k] = data[k];
+      }
+      fetch('/api/player-log', {
+        method: 'POST',
+        keepalive: true,
+        headers: {
+          'Content-Type': 'application/json',
+          'Authorization': 'Bearer ' + token
+        },
+        body: JSON.stringify(payload)
+      }).catch(function () {});
+    } catch (e) {}
+  };
+
   /** addEventListener + mémorisation pour un retrait propre. */
   XFPlayer.prototype._on = function (target, type, handler, options) {
     target.addEventListener(type, handler, options);
@@ -224,6 +291,7 @@
     var isLive = this.type === 'live';
 
     this.onLoading('Ouverture du flux');
+    this._report('start', {});
 
     // Safari / iOS : HLS natif = le chemin le plus rapide, aucune lib à charger.
     if (isHls && this._canPlayNativeHls()) {
@@ -345,6 +413,8 @@
       hls.on(Hls.Events.ERROR, function (e, d) {
         if (!d.fatal) return;
         self.log('Erreur HLS fatale : ' + d.details);
+        self._stats.errors++;
+        self._report('hls_error', { detail: d.type + '/' + d.details });
         if (d.type === Hls.ErrorTypes.NETWORK_ERROR) {
           // Playlist jamais obtenue (transcodeur en échec → 502, serveur trop
           // chargé → délai dépassé), après les relances internes de hls.js.
@@ -462,6 +532,7 @@
 
       self._audioFallbackDone = true;
       self.log('Aucune piste audio démuxée (codec non supporté) — bascule HLS');
+      self._report('fallback_hls', { detail: 'no_audio' });
       self.onLoading('Piste audio incompatible — réencodage');
 
       try {
@@ -479,6 +550,8 @@
     player.on(mpegts.Events.ERROR, function (type, detail) {
       self.log('Erreur MPEG-TS : ' + type + ' / ' + detail);
       if (self._destroyed) return;
+      self._stats.errors++;
+      self._report('mpegts_error', { detail: type + '/' + detail });
 
       // Chaque recréation relance un FFmpeg côté serveur : sur un serveur
       // déjà saturé, recréer sans fin toutes les 1,2 s ne faisait
@@ -503,6 +576,7 @@
           return;
         }
         self.log('Erreurs MPEG-TS répétées — bascule HLS');
+        self._report('fallback_hls', { detail: 'repeated_mpegts_errors' });
         self.onLoading('Ouverture du flux');
         self.url = hlsUrl;
         if (self._canPlayNativeHls()) self._playDirect(hlsUrl);
@@ -519,6 +593,7 @@
           player.detachMediaElement();
           player.destroy();
         } catch (e) {}
+        self._report('recreate', {});
         self._createMpegts(self._mpegtsIsLive);
       }, 1200);
     });
@@ -585,6 +660,7 @@
     var next = PROFILES[ORDER[idx + 1]];
     this.profile = next;
     this.log('Escalade buffer → ' + next.name + ' (' + reason + ')');
+    this._report('profile', { detail: reason });
     this.onProfileChange(next.name, reason);
 
     // HLS : les fenêtres de buffer sont modifiables à chaud, pas besoin de
@@ -628,6 +704,19 @@
     });
 
     this._on(v, 'playing', function () {
+      if (!self._started) {
+        self._report('first_frame', { ms: Date.now() - self._t0 });
+      }
+      if (self._stallSince !== null) {
+        var stallMs = Date.now() - self._stallSince;
+        self._stallSince = null;
+        // < 250 ms : imperceptible, ne pas noyer les logs.
+        if (stallMs >= 250) {
+          self._stats.stalls++;
+          self._stats.stallMs += stallMs;
+          self._report('stall', { ms: stallMs });
+        }
+      }
       self._started = true;
       self.onReady();
       self.send({ type: 'playback_status', status: 'playing' });
@@ -637,9 +726,36 @@
       self.send({ type: 'playback_status', status: 'paused' });
     });
 
-    this._on(v, 'waiting', function () { self._noteStall(); });
+    this._on(v, 'waiting', function () {
+      if (self._started && self._stallSince === null) {
+        self._stallSince = Date.now();
+      }
+      self._noteStall();
+    });
     this._on(v, 'stalled', function () { self._noteStall(); });
 
+    // Sauts (rattrapage du direct, recherche) : d'où, vers où.
+    this._on(v, 'timeupdate', function () {
+      if (!v.seeking) self._lastPos = v.currentTime;
+    });
+    this._on(v, 'seeking', function () {
+      if (!self._started) return;
+      self._stats.seeks++;
+      self._report('seek', { from: self._lastPos, to: v.currentTime });
+    });
+
+    // Bilan toutes les 60 s : nombre et durée cumulée des coupures.
+    this._beatTimer = setInterval(function () {
+      if (!self._started) return;
+      self._report('heartbeat', {
+        stalls: self._stats.stalls,
+        stallMs: self._stats.stallMs,
+        seeks: self._stats.seeks,
+        errors: self._stats.errors,
+        rate: v.playbackRate
+      });
+    }, 60000);
+
     this._on(v, 'ended', function () {
       self.send({
         type: 'playback_ended',
@@ -806,6 +922,7 @@
   XFPlayer.prototype.destroy = function () {
     this._destroyed = true;
     clearInterval(this._posTimer);
+    clearInterval(this._beatTimer);
     this._listeners.forEach(function (l) {
       try { l.target.removeEventListener(l.type, l.handler); } catch (e) {}
     });