From 1b04e002c20af4b8cd7940ba20172f550b09e741 Mon Sep 17 00:00:00 2001 From: foxyz Date: Sat, 10 Oct 2026 21:12:00 +0300 Subject: [PATCH] Player: mpv logs at warn (v only while probing the render mode), 4xx fails at once, load errors show The session player asked libmpv for every v-level message all session and media_kit drains them on the UI thread: a retry storm could freeze the window. ffmpeg reconnects only on 5xx, bounded. A load that fails before a duration is known reports once ('can't play this: HTTP error 403 ...'). Co-Authored-By: Claude Opus 5.5 --- .../lib/src/playback/playback_controller.dart | 75 ++++++++- .../lib/src/session/session_coordinator.dart | 1 + apps/desktop/pubspec.lock | 2 +- apps/desktop/pubspec.yaml | 1 + apps/desktop/test/ytdl_headers_e2e_test.dart | 148 ++++++++++++++++++ docs/ARCHITECTURE.md | 33 +++- 6 files changed, 247 insertions(+), 13 deletions(-) create mode 100644 apps/desktop/test/ytdl_headers_e2e_test.dart diff --git a/apps/desktop/lib/src/playback/playback_controller.dart b/apps/desktop/lib/src/playback/playback_controller.dart index f700c45..289bf55 100644 --- a/apps/desktop/lib/src/playback/playback_controller.dart +++ b/apps/desktop/lib/src/playback/playback_controller.dart @@ -1,6 +1,8 @@ import 'dart:async'; +import 'dart:ffi' show Int8; import 'dart:io'; +import 'package:ffi/ffi.dart' show StringUtf8Pointer, malloc; import 'package:flutter/foundation.dart' show listEquals; import 'package:flutter/widgets.dart'; import 'package:media_kit/media_kit.dart'; @@ -64,6 +66,22 @@ class PlaybackController { /// mpv's yt-dlp hook could not open the current link (its error text). void Function(String error)? onYtdlError; + /// The current media failed to load (the HTTP error when there was one, + /// e.g. a CDN's 403), at most once per [openUrl]. + void Function(String error)? onLoadError; + + // Per opened media: the last HTTP error ffmpeg logged, and whether a + // load error was reported. + String? _httpError; + bool _loadErrorSent = false; + + /// mpv's log level for this app. media_kit drains mpv's log on the UI + /// thread one line at a time, so a chatty level (ffmpeg retrying a + /// refused request logs every attempt) can starve the UI: warnings and + /// errors only, except while the video output starts ([video]), when + /// the render-mode probe needs mpv's verbose GL init lines. + static const logLevel = 'warn'; + /// Points mpv's yt-dlp hook at [path] (the app's managed copy) for web /// page links, at most 1080p, once per player; its cookies /// (`ytdl-raw-options`) whenever they changed. @@ -162,6 +180,7 @@ class PlaybackController { final existing = _video; if (existing != null) return existing; final hwdec = _hwdecOverride; + _requestLog(player, 'v'); // back to [logLevel] by _detectRenderMode // media_kit's video output sets hwdec itself on attach ('auto' unless // configured), which used to override SYNC_RELAY_HWDEC. final video = _video = VideoController( @@ -187,8 +206,7 @@ class PlaybackController { bufferSize: maxBytes, libass: true, vo: Platform.environment['SYNC_RELAY_VO'], - // Verbose: the render-mode probe needs mpv's GL init lines. - logLevel: MPVLogLevel.v, + logLevel: MPVLogLevel.warn, // see [logLevel] )) ..onUserSeek = (d) => onUserSeek?.call(d); _shaders = ''; @@ -243,8 +261,29 @@ class PlaybackController { if (hwdec != null) { await _pin('hwdec', hwdec); } - await _pin('stream-lavf-o', - 'reconnect_streamed=1,reconnect_on_http_error=1,reconnect_delay_max=4'); + await _pin('stream-lavf-o', streamLavfOptions); + } + + /// ffmpeg's HTTP options (mpv `stream-lavf-o`, comma form): reconnect + /// after a dropped connection, also on a streamed (growing) relay + /// response, and a server error (5xx) while connecting; a refused request + /// (4xx) fails at once. At most 3 tries per read, 4 s apart at most. + static const streamLavfOptions = 'reconnect_streamed=1,reconnect_on_http_error=5xx,' + 'reconnect_delay_max=4,reconnect_max_retries=3'; + + // mpv_request_log_messages on [p]'s handle (media_kit has no API for it). + static void _requestLog(Player p, String level) { + try { + final dynamic platform = p.platform; + final name = level.toNativeUtf8(); + try { + platform.mpv.mpv_request_log_messages(platform.ctx, name.cast()); + } finally { + malloc.free(name); + } + } catch (e) { + debugPrint('mpv log level $level not set: $e'); + } } /// Puts the saved shader choice (Settings, Ctrl+0..6, shader button) on @@ -331,7 +370,27 @@ class PlaybackController { void _onLog(PlayerLog log) { if (log.prefix == 'ytdl_hook' && (log.level == 'error' || log.level == 'fatal')) { final text = log.text.trim().replaceFirst(RegExp(r'^ERROR:\s*'), ''); - if (text.isNotEmpty) onYtdlError?.call(text); + if (text.isNotEmpty) { + _loadErrorSent = true; + onYtdlError?.call(text); + } + return; + } + // ffmpeg logs through one mpv instance per process (the first one + // alive), so the HTTP status is a bonus, not a given. + if (log.prefix == 'ffmpeg') { + final http = RegExp(r'HTTP error \d{3}.*').firstMatch(log.text); + if (http != null) _httpError = http[0]!.trim(); + return; + } + // Nothing playable opened (a track of mpv's yt-dlp EDL refused, ...). + if (!_loadErrorSent && + duration.peek() == Duration.zero && + ((log.prefix == 'cplayer' && log.level == 'fatal') || + (log.prefix == 'demux' && log.level == 'error'))) { + _loadErrorSent = true; + final http = _httpError; + onLoadError?.call(http == null ? 'the video stream could not be opened' : 'the video server answered $http'); return; } if (log.prefix != 'libmpv_render') return; @@ -364,10 +423,12 @@ class PlaybackController { Future _detectRenderMode(Player p, VideoController video) async { try { await video.platform.future; + await Future.delayed(const Duration(milliseconds: 1500)); } catch (_) { return; + } finally { + if (identical(p, _player)) _requestLog(p, logLevel); } - await Future.delayed(const Duration(milliseconds: 1500)); if (!identical(p, _player) || renderMode.peek() != RenderMode.unknown) { return; } @@ -451,6 +512,8 @@ class PlaybackController { if (!_ready) return; try { _chapterJson = ''; + _httpError = null; + _loadErrorSent = false; chapters.value = const []; tracks.value = const []; buffered.value = Duration.zero; diff --git a/apps/desktop/lib/src/session/session_coordinator.dart b/apps/desktop/lib/src/session/session_coordinator.dart index 499c7c4..46aba32 100644 --- a/apps/desktop/lib/src/session/session_coordinator.dart +++ b/apps/desktop/lib/src/session/session_coordinator.dart @@ -333,6 +333,7 @@ class SessionCoordinator { try { playback.onFrozen = () => unawaited(reloadVideo(auto: true)); playback.onYtdlError = (e) => health.value = HealthStatus(HealthSeverity.error, "can't open this link: $e"); + playback.onLoadError = (e) => health.value = HealthStatus(HealthSeverity.error, "can't play this: $e"); playback.onUserSeek = (d) => _userSeek(d.inMicroseconds / 1e6); await playback.init(); _playerReady = true; diff --git a/apps/desktop/pubspec.lock b/apps/desktop/pubspec.lock index 539a9f7..4ffb3be 100644 --- a/apps/desktop/pubspec.lock +++ b/apps/desktop/pubspec.lock @@ -138,7 +138,7 @@ packages: source: hosted version: "1.3.3" ffi: - dependency: transitive + dependency: "direct main" description: name: ffi sha256: "6d7fd89431262d8f3125e81b50d3847a091d846eafcd4fdb88dd06f36d705a45" diff --git a/apps/desktop/pubspec.yaml b/apps/desktop/pubspec.yaml index 0396e8b..aee5bc1 100644 --- a/apps/desktop/pubspec.yaml +++ b/apps/desktop/pubspec.yaml @@ -24,6 +24,7 @@ dependencies: image: ^4.9.2 window_manager: ^0.5.2 crypto: ^3.0.6 + ffi: ^2.1.0 # Drag & drop and clipboard files/images (vendored desktop_drop + pasteboard). fox_utils: git: diff --git a/apps/desktop/test/ytdl_headers_e2e_test.dart b/apps/desktop/test/ytdl_headers_e2e_test.dart new file mode 100644 index 0000000..8e843c0 --- /dev/null +++ b/apps/desktop/test/ytdl_headers_e2e_test.dart @@ -0,0 +1,148 @@ +import 'dart:convert'; +import 'dart:io'; + +import 'package:flutter_test/flutter_test.dart'; +import 'package:media_kit/media_kit.dart'; +import 'package:watch_together/src/playback/playback_controller.dart'; + +final _tmp = Platform.environment['WT_TEST_TMP'] ?? Directory.systemTemp.path; +const _referer = 'https://www.bilibili.com/'; + +/// Separate video-only and audio-only files, like Bilibili's DASH .m4s. +Future<(String, String)> _media() async { + final v = '$_tmp/ytdl_headers_v.mp4', a = '$_tmp/ytdl_headers_a.m4a'; + for (final (path, args) in [ + (v, ['-f', 'lavfi', '-i', 'testsrc2=size=320x180:rate=24', '-c:v', 'libx264', '-preset', 'ultrafast']), + (a, ['-f', 'lavfi', '-i', 'sine=frequency=440:sample_rate=48000', '-c:a', 'aac']), + ]) { + if (await File(path).exists()) continue; + final r = await Process.run('ffmpeg', ['-y', '-v', 'error', ...args, '-t', '30', path]); + if (r.exitCode != 0) fail('ffmpeg failed: ${r.stderr}'); + } + return (v, a); +} + +/// A CDN like Bilibili's: 403 without the page's Referer. +class _Cdn { + _Cdn(this._server, this._files) { + _server.listen(_serve); + } + final HttpServer _server; + final Map _files; + int ok = 0, forbidden = 0; + + String url(String name) => 'http://127.0.0.1:${_server.port}/$name'; + + Future _serve(HttpRequest req) async { + final res = req.response; + final file = _files[req.uri.pathSegments.lastOrNull]; + if (file == null || req.headers.value('referer') != _referer) { + forbidden++; + res.statusCode = HttpStatus.forbidden; + await res.close(); + return; + } + ok++; + final bytes = await File(file).readAsBytes(); + var start = 0, end = bytes.length - 1; + final range = RegExp(r'bytes=(\d*)-(\d*)').firstMatch(req.headers.value('range') ?? ''); + res.headers.set('accept-ranges', 'bytes'); + if (range != null) { + start = int.tryParse(range[1]!) ?? 0; + end = int.tryParse(range[2]!) ?? end; + res.statusCode = HttpStatus.partialContent; + res.headers.set('content-range', 'bytes $start-$end/${bytes.length}'); + } + res.contentLength = end - start + 1; + res.add(bytes.sublist(start, end + 1)); + await res.close(); + } +} + +/// A stand-in yt-dlp printing what yt-dlp gives for a split-track page: +/// `requested_formats` with per-format `http_headers`, none at the top. +Future _fakeYtDlp(_Cdn cdn, {required bool headers}) async { + final dir = await Directory('$_tmp/ytdl_headers_fake').create(recursive: true); + final h = headers ? {'Referer': _referer, 'User-Agent': 'fake-agent'} : {}; + final json = jsonEncode({ + 'id': 'BV1', 'title': 'Fake page', 'duration': 30, 'extractor': 'fake', + 'format_id': 'v+a', 'ext': 'mp4', + 'requested_formats': [ + {'format_id': 'v', 'url': cdn.url('v.m4s'), 'protocol': 'https', 'ext': 'mp4', + 'vcodec': 'avc1.64001F', 'acodec': 'none', 'width': 320, 'height': 180, 'http_headers': h}, + {'format_id': 'a', 'url': cdn.url('a.m4s'), 'protocol': 'https', 'ext': 'm4a', + 'vcodec': 'none', 'acodec': 'mp4a.40.2', 'http_headers': h}, + ], + }); + final f = File('${dir.path}/yt-dlp-${headers ? 'h' : 'n'}'); + await f.writeAsString("#!/bin/sh\ncat <<'EOF'\n$json\nEOF\n"); + await Process.run('chmod', ['+x', f.path]); + return f.path; +} + +void main() { + late _Cdn cdn; + late HttpServer server; + + setUpAll(() async { + MediaKit.ensureInitialized(); + final (v, a) = await _media(); + server = await HttpServer.bind(InternetAddress.loopbackIPv4, 0); + cdn = _Cdn(server, {'v.m4s': v, 'a.m4s': a}); + }); + tearDownAll(() => server.close(force: true)); + + test( + "mpv's yt-dlp hook sends each format's Referer to the CDN", + timeout: const Timeout(Duration(minutes: 1)), + () async { + final p = PlaybackController(); + try { + await p.init(); + expect(p.pinMismatches, isEmpty, reason: 'stream-lavf-o and the rest took effect'); + await p.useYtDlp(await _fakeYtDlp(cdn, headers: true)); + await p.openUrl('https://www.bilibili.com/video/BV1fake'); + final end = DateTime.now().add(const Duration(seconds: 20)); + while (DateTime.now().isBefore(end) && p.duration.peek() == Duration.zero) { + await Future.delayed(const Duration(milliseconds: 100)); + } + expect(p.duration.peek(), greaterThan(Duration.zero), reason: 'both tracks opened'); + expect(cdn.forbidden, 0, reason: 'every request had the Referer'); + expect(cdn.ok, greaterThanOrEqualTo(2)); + } finally { + await p.dispose(); + } + }, + skip: Platform.isLinux ? false : 'fake yt-dlp is a shell script', + ); + + test( + 'a 403 is a load error, not a reconnect loop', + timeout: const Timeout(Duration(minutes: 1)), + () async { + final p = PlaybackController(); + final errors = []; + p.onLoadError = errors.add; + try { + await p.init(); + var logs = 0; + final sub = p.player.stream.log.listen((_) => logs++); + await p.useYtDlp(await _fakeYtDlp(cdn, headers: false)); + final before = cdn.forbidden; + await p.openUrl('https://www.bilibili.com/video/BV2fake'); + await Future.delayed(const Duration(seconds: 8)); + await sub.cancel(); + // ignore: avoid_print + print('403s: ${cdn.forbidden - before}, log lines: $logs, errors: $errors'); + expect(cdn.forbidden - before, lessThan(10), reason: 'no retry loop on 403'); + expect(errors, hasLength(1)); + // The status only when ffmpeg logs through this mpv (see _onLog). + expect(errors.single, anyOf(contains('403'), contains('could not be opened'))); + expect(logs, lessThan(30), reason: 'warnings and errors only'); + } finally { + await p.dispose(); + } + }, + skip: Platform.isLinux ? false : 'fake yt-dlp is a shell script', + ); +} diff --git a/docs/ARCHITECTURE.md b/docs/ARCHITECTURE.md index 1c74b45..d09588b 100644 --- a/docs/ARCHITECTURE.md +++ b/docs/ARCHITECTURE.md @@ -256,8 +256,16 @@ mpv settings (`PlaybackController`): `Player` with `bufferSize` 256 MiB read-ahead: rides out short drops, intro skips are instant), `demuxer-max-bytes=268435456` (150 s up to ~14 Mbit/s; a 1.4 GB / 24 min file is ~8), `demuxer-max-back-bytes=67108864`, -`stream-lavf-o=reconnect_streamed=1,reconnect_on_http_error=1,reconnect_delay_max=4` -(comma form; this mpv build rejects colon-joined). The cache is in RAM: +`stream-lavf-o=reconnect_streamed=1,reconnect_on_http_error=5xx,reconnect_delay_max=4,reconnect_max_retries=3` +(comma form; this mpv build rejects colon-joined): a dropped connection +or a 5xx is retried, at most 3 times per read and 4 s apart at most; a +4xx (a CDN refusing a request) fails at once instead of being retried +(older ffmpeg ignores `reconnect_max_retries`). A load that fails (mpv's +fatal "No video or audio streams selected", or an EDL track that cannot +be opened) before a duration is known is reported once per open +(`onLoadError`) and shows as "can't play this: ..." with ffmpeg's HTTP +status when this player gets ffmpeg's log (ffmpeg logs through one mpv +instance per process, the first one alive). The cache is in RAM: media_kit sets `cache-on-disk` without a `cache-dir`, and mpv falls back. mpv ignores invalid values silently, so every pin is read back and a mismatch is logged and kept in `pinMismatches`. Measured against the `/m` endpoint @@ -288,12 +296,18 @@ turns shaders off (saved) with a toast. Render mode: media_kit's Linux/Windows video output creates mpv's render context (OpenGL, else its software renderer) when the `VideoController` is created, and nothing in its API says which. The player therefore requests -mpv logs at `v`: OpenGL init logs `GL_VERSION` under `libmpv_render` +mpv logs at `v` while the controller is created: OpenGL init logs +`GL_VERSION` under `libmpv_render` (`RenderMode.gpu`; "suspected software renderer" means llvmpipe, `softwareGl`); none within 1.5 s of the controller being ready means the software path (`software`, where shaders do nothing; the shader toast, the -menu and Settings say so). After startup the `v` level adds no steady -traffic (measured: 0 messages over 5 s of playback). The hardware path is +menu and Settings say so). Otherwise the session player logs at `warn` +(`PlaybackController.logLevel`, switched with `mpv_request_log_messages` +on media_kit's handle): media_kit drains mpv's log on the UI thread, one +message at a time, so a chatty level, or ffmpeg logging every retry of a +refused request, could starve the UI. Shader and yt-dlp hook errors are +`error` lines and still arrive. The thumbnail and sound players keep +media_kit's default (`error`) and nothing listens to their log. The hardware path is fragile: media_kit borrows whatever EGL context GDK left current on the main thread (upstream media-kit#1404), so an X11 session or a Flutter/GDK change can silently fall back to software. @@ -641,7 +655,14 @@ all three link modes. Nothing is bundled or installed by hand. external link every app points mpv's hook at its managed copy (`script-opts=ytdl_hook-ytdl_path=...`, `ytdl-format=bv*[height<=1080]+ba/b`, once per player), waiting for the download unless the URL names a media - file. A hook error shows as "can't open this link: ...". + file. A hook error shows as "can't open this link: ...". The hook (mpv + 0.41) gives mpv the first requested format's `http_headers` (User-Agent + as `user-agent`; Referer, Cookie, X-Forwarded-For as file-local + `http-header-fields`, which win over the empty list media_kit sets on + load) and its `cookies` (`stream-lavf-o`), for every track of its EDL: + Bilibili's CDN answers 403 without the Referer. The app never opens a + resolved format URL in mpv itself (the putter of "Through me" plays the + page through the hook too); relays read them with yt-dlp's headers. - **Through me**: the putter's probe must give tracks, and a pieces track's playlist must be readable, else the swap is refused ("Live streams can't be passed on", DRM, or nothing a relay can read) with a