Fix VLC resume audio sync

This commit is contained in:
dirtydishes 2026-05-27 02:15:07 -04:00
parent ed7a242a47
commit e7ddd6d755
6 changed files with 331 additions and 118 deletions

View file

@ -44,3 +44,4 @@
{"id":"int-3533f9f7","kind":"field_change","created_at":"2026-05-27T04:09:20.72451Z","actor":"dirtydishes","issue_id":"dreamio-ccn","extra":{"field":"status","new_value":"closed","old_value":"in_progress","reason":"Implemented playback-first native startup and background parallel subtitle resolution."}}
{"id":"int-c55d4a7b","kind":"field_change","created_at":"2026-05-27T04:20:08.84278Z","actor":"dirtydishes","issue_id":"dreamio-e2q","extra":{"field":"status","new_value":"closed","old_value":"in_progress","reason":"Fixed by gating native startup loading until VLC readiness and startup subtitle candidate processing both complete."}}
{"id":"int-bfb2d962","kind":"field_change","created_at":"2026-05-27T04:30:15.810274Z","actor":"dirtydishes","issue_id":"dreamio-69r","extra":{"field":"status","new_value":"closed","old_value":"in_progress","reason":"Implemented AVAudioSession warm-up around native VLC pause/resume and validated simulator build."}}
{"id":"int-b32c40f0","kind":"field_change","created_at":"2026-05-27T06:14:56.320425Z","actor":"dirtydishes","issue_id":"dreamio-0pi","extra":{"field":"status","new_value":"closed","old_value":"in_progress","reason":"Implemented MobileVLCKit resume sync changes: removed repeated resume seek-holding, simplified streaming cache options, retained DEBUG resume observation, updated tests, and documented the turn. Real-device validation is tracked in dreamio-yny."}}

View file

@ -2,6 +2,8 @@
{"_type":"issue","id":"dreamio-btc","title":"Bound VLC range cache probe startup latency","description":"After enabling MKV range cache probing, some Torrentio/Real-Debrid MKV streams log cache-probe but never reach opening mode before the native-player startup timeout. Add a bounded probe/local-cache startup path that falls back to direct playback when the range probe is slow or inconclusive.","status":"closed","priority":0,"issue_type":"bug","assignee":"dirtydishes","owner":"dishes@dpdrm.com","created_at":"2026-05-26T12:14:02Z","created_by":"dirtydishes","updated_at":"2026-05-26T12:16:53Z","started_at":"2026-05-26T12:14:11Z","closed_at":"2026-05-26T12:16:53Z","close_reason":"Added a short timeout to range-cache probe requests so slow MKV HEAD/range probes fall back to direct VLC startup instead of tripping the native-player startup timeout.","dependency_count":0,"dependent_count":0,"comment_count":0}
{"_type":"issue","id":"dreamio-mun","title":"fix vlc cache loopback port startup","description":"Device logs showed local-cache playback opening http://127.0.0.1:0, because the NWListener ephemeral port was read before the listener reached ready. Wait for the real assigned port before returning the local cache URL.","status":"closed","priority":0,"issue_type":"bug","assignee":"dirtydishes","owner":"dishes@dpdrm.com","created_at":"2026-05-25T22:32:41Z","created_by":"dirtydishes","updated_at":"2026-05-25T22:33:15Z","started_at":"2026-05-25T22:33:14Z","closed_at":"2026-05-25T22:33:15Z","close_reason":"Wait for NWListener ready state before returning the local cache URL; verified tests and simulator build.","dependency_count":0,"dependent_count":0,"comment_count":0}
{"_type":"issue","id":"dreamio-8cz","title":"fix stremio external subtitle loading regression","description":"After adding late subtitle forwarding for native playback, Stremio external subtitle loading is failing. Investigate the injected bridge and native subtitle forwarding path, then adjust behavior so Stremio can still load external subtitles while native playback receives late candidates.","status":"closed","priority":0,"issue_type":"bug","assignee":"dirtydishes","owner":"dishes@dpdrm.com","created_at":"2026-05-25T11:05:42Z","created_by":"dirtydishes","updated_at":"2026-05-25T11:07:35Z","started_at":"2026-05-25T11:05:55Z","closed_at":"2026-05-25T11:07:35Z","close_reason":"Hardened subtitle bridge network observers so non-text Stremio subtitle loads are not touched, and made parser traversal deterministic for metadata preservation.","dependency_count":0,"dependent_count":0,"comment_count":0}
{"_type":"issue","id":"dreamio-yny","title":"Validate VLC resume audio sync on device","description":"Run manual real-device validation for MobileVLCKit direct-stream pause and resume after removing repeated seek-holding. Capture DEBUG resume-observation logs if audio still lags video.","acceptance_criteria":"Problematic direct-file streams are tested on a real iPhone or iPad; resume audio/video timing is recorded; DEBUG resume-observation logs are attached or summarized if lag persists.","status":"open","priority":1,"issue_type":"task","owner":"dishes@dpdrm.com","created_at":"2026-05-27T06:14:11Z","created_by":"dirtydishes","updated_at":"2026-05-27T06:14:11Z","dependency_count":0,"dependent_count":0,"comment_count":0}
{"_type":"issue","id":"dreamio-0pi","title":"Fix MobileVLCKit streaming resume audio sync","description":"Research MobileVLCKit streaming pause/resume behavior and adjust native VLC playback so audio does not lag behind video on every resume.","acceptance_criteria":"MobileVLCKit streaming resume behavior is researched; repeated resume seek-holding is removed or replaced; relevant tests pass; changes are documented.","status":"closed","priority":1,"issue_type":"bug","assignee":"dirtydishes","owner":"dishes@dpdrm.com","created_at":"2026-05-27T05:47:32Z","created_by":"dirtydishes","updated_at":"2026-05-27T06:14:56Z","started_at":"2026-05-27T05:47:35Z","closed_at":"2026-05-27T06:14:56Z","close_reason":"Implemented MobileVLCKit resume sync changes: removed repeated resume seek-holding, simplified streaming cache options, retained DEBUG resume observation, updated tests, and documented the turn. Real-device validation is tracked in dreamio-yny.","dependency_count":0,"dependent_count":0,"comment_count":0}
{"_type":"issue","id":"dreamio-69r","title":"Fix audio lag after native video resume","description":"Audio takes a moment to resume after pausing and playing native video; previous attempts did not resolve the lag.","status":"closed","priority":1,"issue_type":"bug","assignee":"dirtydishes","owner":"dishes@dpdrm.com","created_at":"2026-05-27T04:26:52Z","created_by":"dirtydishes","updated_at":"2026-05-27T04:30:16Z","started_at":"2026-05-27T04:26:56Z","closed_at":"2026-05-27T04:30:16Z","close_reason":"Implemented AVAudioSession warm-up around native VLC pause/resume and validated simulator build.","dependency_count":0,"dependent_count":0,"comment_count":0}
{"_type":"issue","id":"dreamio-e2q","title":"Gate native player readiness on startup subtitle loading","description":"The native VLC player reports ready as soon as VLC enters buffering, which hides the loading overlay before startup subtitle candidates finish resolving and attaching. Keep startup loading active until the initial subtitle batch has completed or no candidates are queued.","status":"closed","priority":1,"issue_type":"bug","assignee":"dirtydishes","owner":"dishes@dpdrm.com","created_at":"2026-05-27T04:16:35Z","created_by":"dirtydishes","updated_at":"2026-05-27T04:20:09Z","started_at":"2026-05-27T04:16:37Z","closed_at":"2026-05-27T04:20:09Z","close_reason":"Fixed by gating native startup loading until VLC readiness and startup subtitle candidate processing both complete.","dependency_count":0,"dependent_count":0,"comment_count":0}
{"_type":"issue","id":"dreamio-5cz","title":"Make VLC range cache non-blocking at startup","description":"Native playback startup currently bypasses Dreamio's local range cache after cache probing caused VLC startup timeouts. Reintroduce cache startup only when preparation is fast and safe, otherwise fall back to direct playback immediately, with focused tests and clear logs.","status":"closed","priority":1,"issue_type":"bug","assignee":"dirtydishes","owner":"dishes@dpdrm.com","created_at":"2026-05-27T00:36:56Z","created_by":"dirtydishes","updated_at":"2026-05-27T00:43:03Z","started_at":"2026-05-27T00:37:03Z","closed_at":"2026-05-27T00:43:03Z","close_reason":"Implemented bounded non-blocking range-cache startup for VLC, with direct fallback on timeout, skipped probes, or local server failures; added focused startup policy tests and updated the turn document.","dependency_count":0,"dependent_count":0,"comment_count":0}

View file

@ -75,23 +75,11 @@ enum NativePlaybackAudioSessionPolicy {
}
}
enum NativePlaybackResumePolicy {
static let freezeInterval: TimeInterval = 0.08
static let maximumFreezeDuration: TimeInterval = 1.2
static let maximumAllowedSilentAdvance: Int32 = 120
enum NativePlaybackStreamingOptionsPolicy {
static let networkCachingMilliseconds = 1000
static func shouldHoldVideoAtPausedTime(
elapsedSinceResume: TimeInterval,
hasObservedAudioOutput: Bool,
mediaAdvanceMilliseconds: Int32
) -> Bool {
guard !hasObservedAudioOutput else {
return false
}
guard elapsedSinceResume < maximumFreezeDuration else {
return false
}
return mediaAdvanceMilliseconds > maximumAllowedSilentAdvance
static func mediaOptions() -> [String] {
[":network-caching=\(networkCachingMilliseconds)"]
}
}

View file

@ -34,8 +34,8 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
private var externalSubtitleDisplayNamesByTrackID: [Int32: String] = [:]
private var didReportReadyForCurrentMedia = false
private var pausedTimeMilliseconds: Int32?
private var resumeCorrectionGeneration = 0
private var resumeCorrectionStartDate: Date?
private var resumeObservationGeneration = 0
private var resumeObservationStartDate: Date?
private var hasObservedResumeAudioOutput = false
private var lastToggleDate = Date.distantPast
private let minimumToggleInterval: TimeInterval = 0.35
@ -65,7 +65,7 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
pendingExternalSubtitleDisplayNames.removeAll()
externalSubtitleDisplayNamesByTrackID.removeAll()
didReportReadyForCurrentMedia = false
resetResumeCorrectionState()
resetResumeObservationState()
lastToggleDate = .distantPast
let media = VLCMedia(url: request.playbackURL)
let headerValue = request.headers
@ -108,9 +108,9 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
#endif
mediaPlayer.play()
if isResumingFromPause {
beginResumeCorrection()
beginResumeObservation()
} else {
resetResumeCorrectionState()
resetResumeObservationState()
}
#if DEBUG
logPlaybackSnapshot(reason: "after-play-command")
@ -131,9 +131,8 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
return
}
pausedTimeMilliseconds = mediaPlayer.time.intValue
resetResumeCorrectionRuntimeState()
resetResumeObservationRuntimeState()
mediaPlayer.pause()
keepAudioSessionWarmAfterPause()
#if DEBUG
logPlaybackSnapshot(reason: "after-pause-command")
DispatchQueue.main.asyncAfter(deadline: .now() + 0.25) { [weak self] in
@ -249,7 +248,7 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
logPlaybackSnapshot(reason: "before-stop")
#endif
didReportReadyForCurrentMedia = false
resetResumeCorrectionState()
resetResumeObservationState()
mediaPlayer.stop()
mediaPlayer.drawable = nil
mediaPlayer.media = nil
@ -355,11 +354,7 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
#if canImport(MobileVLCKit)
private func addConservativePlaybackOptions(to media: VLCMedia) {
[
":network-caching=1000",
":file-caching=1000",
":live-caching=1000"
].forEach { media.addOption($0) }
NativePlaybackStreamingOptionsPolicy.mediaOptions().forEach { media.addOption($0) }
}
private func prepareAudioSessionForPlayback(reason: String) {
@ -377,83 +372,57 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
}
}
private func keepAudioSessionWarmAfterPause() {
prepareAudioSessionForPlayback(reason: "pause-keep-warm")
DispatchQueue.main.asyncAfter(deadline: .now() + 0.08) { [weak self] in
self?.prepareAudioSessionForPlayback(reason: "pause-keep-warm-follow-up")
}
}
private func beginResumeCorrection() {
private func beginResumeObservation() {
guard let pausedTimeMilliseconds else {
return
}
resetResumeCorrectionRuntimeState()
resumeCorrectionGeneration += 1
let generation = resumeCorrectionGeneration
resumeCorrectionStartDate = Date()
resetResumeObservationRuntimeState()
resumeObservationGeneration += 1
let generation = resumeObservationGeneration
resumeObservationStartDate = Date()
#if DEBUG
print("[DreamioVLC] resume-correction begin pausedTimeMS=\(pausedTimeMilliseconds)")
print("[DreamioVLC] resume-observation begin pausedTimeMS=\(pausedTimeMilliseconds)")
[0.25, 0.75, 1.5].forEach { delay in
DispatchQueue.main.asyncAfter(deadline: .now() + delay) { [weak self] in
self?.logResumeObservation(generation: generation, delay: delay)
}
}
#endif
scheduleResumeCorrectionTick(generation: generation)
}
private func scheduleResumeCorrectionTick(generation: Int) {
DispatchQueue.main.asyncAfter(deadline: .now() + NativePlaybackResumePolicy.freezeInterval) { [weak self] in
self?.performResumeCorrectionTick(generation: generation)
}
}
private func performResumeCorrectionTick(generation: Int) {
guard generation == resumeCorrectionGeneration,
#if DEBUG
private func logResumeObservation(generation: Int, delay: TimeInterval) {
guard generation == resumeObservationGeneration,
let pausedTimeMilliseconds,
let resumeCorrectionStartDate else {
let resumeObservationStartDate else {
return
}
let elapsed = Date().timeIntervalSince(resumeCorrectionStartDate)
let currentTimeMilliseconds = mediaPlayer.time.intValue
let advance = max(0, currentTimeMilliseconds - pausedTimeMilliseconds)
let shouldHold = NativePlaybackResumePolicy.shouldHoldVideoAtPausedTime(
elapsedSinceResume: elapsed,
hasObservedAudioOutput: hasObservedResumeAudioOutput,
mediaAdvanceMilliseconds: advance
)
guard shouldHold else {
#if DEBUG
print("[DreamioVLC] resume-correction release elapsed=\(String(format: "%.3f", elapsed)) audioObserved=\(hasObservedResumeAudioOutput) advanceMS=\(advance)")
#endif
resetResumeCorrectionRuntimeState()
return
let elapsed = Date().timeIntervalSince(resumeObservationStartDate)
let advance = max(0, mediaPlayer.time.intValue - pausedTimeMilliseconds)
print("[DreamioVLC] resume-observation tick delay=\(String(format: "%.2f", delay)) elapsed=\(String(format: "%.3f", elapsed)) audioObserved=\(hasObservedResumeAudioOutput) advanceMS=\(advance)")
logPlaybackSnapshot(reason: "resume-observation-\(String(format: "%.2f", delay))")
}
mediaPlayer.time = VLCTime(int: pausedTimeMilliseconds)
#if DEBUG
print("[DreamioVLC] resume-correction hold elapsed=\(String(format: "%.3f", elapsed)) advanceMS=\(advance) resetToMS=\(pausedTimeMilliseconds)")
#endif
scheduleResumeCorrectionTick(generation: generation)
}
private func noteResumeAudioOutputIfNeeded(reason: String) {
guard resumeCorrectionStartDate != nil else {
guard resumeObservationStartDate != nil else {
return
}
hasObservedResumeAudioOutput = true
#if DEBUG
let loudness = mediaPlayer.momentaryLoudness
print("[DreamioVLC] resume-correction audio-observed reason=\(reason) loudness=\(loudness?.loudnessValue ?? 0) date=\(loudness?.date ?? 0)")
print("[DreamioVLC] resume-observation audio-observed reason=\(reason) loudness=\(loudness?.loudnessValue ?? 0) date=\(loudness?.date ?? 0)")
#endif
}
private func resetResumeCorrectionState() {
private func resetResumeObservationState() {
pausedTimeMilliseconds = nil
resetResumeCorrectionRuntimeState()
resetResumeObservationRuntimeState()
}
private func resetResumeCorrectionRuntimeState() {
resumeCorrectionGeneration += 1
resumeCorrectionStartDate = nil
private func resetResumeObservationRuntimeState() {
resumeObservationGeneration += 1
resumeObservationStartDate = nil
hasObservedResumeAudioOutput = false
}
@ -490,7 +459,7 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
#if DEBUG
private func logPlaybackSnapshot(reason: String) {
let mediaLength = mediaPlayer.media?.length.intValue ?? 0
print("[DreamioVLC] snapshot reason=\(reason) state=\(stateName(mediaPlayer.state)) isPlaying=\(mediaPlayer.isPlaying) canPause=\(mediaPlayer.canPause) seekable=\(mediaPlayer.isSeekable) currentTime=\(String(format: "%.3f", currentTime)) duration=\(String(format: "%.3f", TimeInterval(max(0, mediaLength)) / 1000)) position=\(String(format: "%.4f", mediaPlayer.position)) audioDelay=\(mediaPlayer.currentAudioPlaybackDelay) pausedTimeMS=\(pausedTimeMilliseconds.map(String.init) ?? "nil") resumeActive=\(resumeCorrectionStartDate != nil) audioObserved=\(hasObservedResumeAudioOutput) readyReported=\(didReportReadyForCurrentMedia)")
print("[DreamioVLC] snapshot reason=\(reason) state=\(stateName(mediaPlayer.state)) isPlaying=\(mediaPlayer.isPlaying) canPause=\(mediaPlayer.canPause) seekable=\(mediaPlayer.isSeekable) currentTime=\(String(format: "%.3f", currentTime)) duration=\(String(format: "%.3f", TimeInterval(max(0, mediaLength)) / 1000)) position=\(String(format: "%.4f", mediaPlayer.position)) audioDelay=\(mediaPlayer.currentAudioPlaybackDelay) pausedTimeMS=\(pausedTimeMilliseconds.map(String.init) ?? "nil") resumeActive=\(resumeObservationStartDate != nil) audioObserved=\(hasObservedResumeAudioOutput) readyReported=\(didReportReadyForCurrentMedia)")
}
#endif
@ -655,7 +624,7 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
extension VLCNativePlaybackBackend: VLCMediaPlayerDelegate {
func mediaPlayerTimeChanged(_ aNotification: Notification) {
#if DEBUG
if resumeCorrectionStartDate != nil {
if resumeObservationStartDate != nil {
logPlaybackSnapshot(reason: "time-change-during-resume")
}
#endif

View file

@ -26,7 +26,7 @@ struct StreamResolverTests {
testSubtitleOptionMappingIncludesNone()
testNativePlaybackTogglePolicy()
testNativePlaybackAudioSessionPolicy()
testNativePlaybackResumePolicy()
testNativePlaybackStreamingOptionsPolicy()
print("StreamResolverTests passed")
}
@ -529,39 +529,11 @@ struct StreamResolverTests {
assertEqual(NativePlaybackAudioSessionPolicy.shouldPrepareBeforePlayback(from: .unknown), false)
}
private static func testNativePlaybackResumePolicy() {
assertEqual(
NativePlaybackResumePolicy.shouldHoldVideoAtPausedTime(
elapsedSinceResume: 0.4,
hasObservedAudioOutput: false,
mediaAdvanceMilliseconds: 500
),
true
)
assertEqual(
NativePlaybackResumePolicy.shouldHoldVideoAtPausedTime(
elapsedSinceResume: 0.4,
hasObservedAudioOutput: true,
mediaAdvanceMilliseconds: 500
),
false
)
assertEqual(
NativePlaybackResumePolicy.shouldHoldVideoAtPausedTime(
elapsedSinceResume: 1.3,
hasObservedAudioOutput: false,
mediaAdvanceMilliseconds: 500
),
false
)
assertEqual(
NativePlaybackResumePolicy.shouldHoldVideoAtPausedTime(
elapsedSinceResume: 0.4,
hasObservedAudioOutput: false,
mediaAdvanceMilliseconds: 80
),
false
)
private static func testNativePlaybackStreamingOptionsPolicy() {
assertEqual(NativePlaybackStreamingOptionsPolicy.networkCachingMilliseconds, 1000)
assertEqual(NativePlaybackStreamingOptionsPolicy.mediaOptions(), [":network-caching=1000"])
assertEqual(NativePlaybackStreamingOptionsPolicy.mediaOptions().contains(":file-caching=1000"), false)
assertEqual(NativePlaybackStreamingOptionsPolicy.mediaOptions().contains(":live-caching=1000"), false)
}
private static func assertEqual<T: Equatable>(_ actual: T?, _ expected: T, file: StaticString = #file, line: UInt = #line) {

File diff suppressed because one or more lines are too long