feat(playback): 起播看门狗 + 起播耗时打点

现象(Plastic Love):state=PLAYING、position 恒为 0,75 秒内没有任何
buffering/error 日志,mpv 既不报错也不推进。通用看门狗要求"近期有缓冲",
因此完全没反应。

- 新增起播看门狗:position 持续为 0 超过 15s 且 playing=true → 强制重连
  (不再要求 buffering 事件;暂停时 playing=false,不会误触发)
- 中段卡死判定也放宽为 playing || recentlyBuffering
- 打点:
  * PlaybackService: "open 完成 xxxms,play 完成 xxxms"
  * AudioService: "起播耗时 xxxms(open 完成 -> 出声)"
  下次再出现"下一首很久",日志能直接区分是 open 慢还是数据到得慢。
This commit is contained in:
2026-10-23 21:55:13 +08:00
parent b517c75cdd
commit 111369c20c
2 changed files with 52 additions and 3 deletions
+48 -3
View File
@@ -87,6 +87,7 @@ class AudioService extends ChangeNotifier {
/// 卡死判定阈值 / 节流 /// 卡死判定阈值 / 节流
static const Duration _stallThreshold = Duration(seconds: 30); static const Duration _stallThreshold = Duration(seconds: 30);
static const Duration _startStallThreshold = Duration(seconds: 15);
DateTime? _lastStallRecoveryAt; DateTime? _lastStallRecoveryAt;
/// 最近一次进入 buffering 的时间(用于卡死判定,不能用计时器重置) /// 最近一次进入 buffering 的时间(用于卡死判定,不能用计时器重置)
@@ -101,6 +102,13 @@ class AudioService extends ChangeNotifier {
Duration _lastObservedPosition = Duration.zero; Duration _lastObservedPosition = Duration.zero;
DateTime _lastProgressAt = DateTime.now(); DateTime _lastProgressAt = DateTime.now();
/// 当前歌曲开始加载的时间,用于"起播看门狗":
/// 有些情况下 mpv 的 playing 已经是 true,但 position 永远是 0、
/// 也不发 buffering / error(实测公网链路可静默卡 75s+)。
DateTime? _trackStartAt;
DateTime? _playReadyAt;
bool _firstAudioReported = false;
/// 最近一次播放失败的原因,供 UI 提示;成功播放后自动清空。 /// 最近一次播放失败的原因,供 UI 提示;成功播放后自动清空。
String? _lastPlaybackError; String? _lastPlaybackError;
String? get lastPlaybackError => _lastPlaybackError; String? get lastPlaybackError => _lastPlaybackError;
@@ -306,7 +314,11 @@ class AudioService extends ChangeNotifier {
} }
try { try {
_trackStartAt = DateTime.now();
_playReadyAt = null;
_firstAudioReported = false;
await _playWithHeaders(song.url!); await _playWithHeaders(song.url!);
_playReadyAt = DateTime.now();
} catch (e) { } catch (e) {
// 播放失败(超时/401/网络中断):必须走到 finally 解锁, // 播放失败(超时/401/网络中断):必须走到 finally 解锁,
// 并把错误记下来,供上层提示或下一首重试。 // 并把错误记下来,供上层提示或下一首重试。
@@ -428,15 +440,33 @@ class AudioService extends ChangeNotifier {
return; return;
} }
final player = PlaybackService().player;
// 起播看门狗:playing=true 但 position 一直是 0,且没有任何 buffering/error 事件。
// 这种情况 mpv 不会自己恢复,等 30s 的通用规则又太慢,单独用 15s 阈值。
final stuckAtStart = pos == Duration.zero &&
_trackStartAt != null &&
now.difference(_trackStartAt!) >= _startStallThreshold &&
player.state.playing;
if (stuckAtStart) {
debugPrint('🩺 [AudioService] 起播 '
'${_startStallThreshold.inSeconds}s 仍停在 0s,触发重连');
_trackStartAt = now; // 避免下一次 tick 立刻重复触发
_recoverFromStall(force: true);
return;
}
final stalledFor = now.difference(_lastProgressAt); final stalledFor = now.difference(_lastProgressAt);
final recentlyBuffering = _lastBufferingAt != null && final recentlyBuffering = _lastBufferingAt != null &&
now.difference(_lastBufferingAt!) < const Duration(seconds: 20); now.difference(_lastBufferingAt!) < const Duration(seconds: 20);
if (stalledFor >= _stallThreshold && recentlyBuffering) { // playing==true 也是卡死的充分条件(暂停时 playing 为 false)
if (stalledFor >= _stallThreshold &&
(player.state.playing || recentlyBuffering)) {
debugPrint('🩺 [AudioService] 进度停在 $pos 已 ${stalledFor.inSeconds}s,' debugPrint('🩺 [AudioService] 进度停在 $pos 已 ${stalledFor.inSeconds}s,'
'且近期持续缓冲,触发自愈'); '触发自愈');
_lastProgressAt = now; _lastProgressAt = now;
_recoverFromStall(); _recoverFromStall(force: true);
} }
} }
@@ -463,7 +493,11 @@ class AudioService extends ChangeNotifier {
final resumeAt = positionNotifier.value; final resumeAt = positionNotifier.value;
debugPrint('🩺 [AudioService] 尝试重连:${song.title}(从 ${resumeAt.inSeconds}s 继续)'); debugPrint('🩺 [AudioService] 尝试重连:${song.title}(从 ${resumeAt.inSeconds}s 继续)');
try { try {
_trackStartAt = DateTime.now();
_playReadyAt = null;
_firstAudioReported = false;
await _playWithHeaders(url); await _playWithHeaders(url);
_playReadyAt = DateTime.now();
if (resumeAt > Duration.zero) { if (resumeAt > Duration.zero) {
await PlaybackService().seek(resumeAt); await PlaybackService().seek(resumeAt);
positionNotifier.value = resumeAt; positionNotifier.value = resumeAt;
@@ -816,6 +850,17 @@ class AudioService extends ChangeNotifier {
debugPrint('🎯 [AudioService] positionStream ignored: user seeking'); debugPrint('🎯 [AudioService] positionStream ignored: user seeking');
return; return;
} }
// 首次拿到 >0 的播放位置:这是"真正出声"的时刻,
// 与 play() 发起时间相减即可算出起播延迟。
if (!_firstAudioReported && position > Duration.zero) {
_firstAudioReported = true;
final readyAt = _playReadyAt;
if (readyAt != null) {
final ms = DateTime.now().difference(readyAt).inMilliseconds;
debugPrint('🔊 [AudioService] 起播耗时 ${ms}ms(open 完成 -> 出声)');
_playReadyAt = null;
}
}
positionNotifier.value = position; positionNotifier.value = position;
}), }),
); );
+4
View File
@@ -57,8 +57,12 @@ class PlaybackService {
: Media(url); : Media(url);
try { try {
final sw = Stopwatch()..start();
await _player!.open(media).timeout(_openTimeout); await _player!.open(media).timeout(_openTimeout);
final openMs = sw.elapsedMilliseconds;
await _player!.play().timeout(_controlTimeout); await _player!.play().timeout(_controlTimeout);
debugPrint('⏱️ [PlaybackService] open 完成 ${openMs}ms,'
'play 完成 ${sw.elapsedMilliseconds}ms');
} on TimeoutException { } on TimeoutException {
debugPrint( debugPrint(
'❌ [PlaybackService] open timeout (${_openTimeout.inSeconds}s): ${_shortUrl(url)}'); '❌ [PlaybackService] open timeout (${_openTimeout.inSeconds}s): ${_shortUrl(url)}');