Skip to content

After a restart whose gate re-aimed below its boundary, the clock runs ahead of the picture by the re-aim — captions early, and further out after each such restart (6.40.0 early-opening gate, loopback-HLS VOD, native path) #418

Description

@rrgomes

Same asset as #408 (h264 MKV, Matroska Cues on non-random-access points), PGS subtitles on, engine 6.41.0 and 6.42.0 (6.42.0 is on our pin; nothing in it touches this path), Apple TV 4K 3rd gen / tvOS 26.6. Two sessions on 2026-08-25, heard on the couch and then read out of the log; the second with AVPlayer's own loaded ranges in the log.

What the viewer sees. Resume from 354.0 s: lip sync fine, captions about four seconds ahead of the dialogue — both sessions. A burst of far seeks, further ahead: in the first session "much more than four seconds" after a landing whose restart re-aimed 14 s; in the second, about eight seconds at 699 s after restarts that re-aimed 3.1 s and 5.0 s. Seeks that landed without a restart did not change it, and no restart put it back.

What the producer did at each restart (#65 ledger, sourceStart − planSource):

session 1
resume 354.0   boundary 352936 not a random-access point; re-aimed 4s → gate actual=349891   seg-88  itemAxis=349.891 planSource=352.936 drift=-3.045s shift=0.000s
seek → 622.0   restart idx=154, gate actual=616074 (no re-aim)                                seg-154 itemAxis=616.074 planSource=616.074 drift= 0.000s
seek → 682.0   boundary 676134 re-aimed 4s, 8s, 16s → gate actual=662078                      seg-169 itemAxis=662.078 planSource=676.134 drift=-14.056s
seek → 992.0   boundary 972847 re-aimed 4s → gate actual=969802                               seg-243 itemAxis=969.802 planSource=972.847 drift=-3.045s
seek → 1102.0  boundary 1084375 re-aimed 4s → gate actual=1083332                             seg-271 itemAxis=1083.332 planSource=1084.375 drift=-1.043s
session 2
resume 354.0   as above                                                                       seg-88  drift=-3.045s shift=0.000s
seek → 519.3   boundary 512053 (first sync sample 0.96s later); re-aimed 4s → actual=508925   seg-128 itemAxis=508.925 planSource=512.053 drift=-3.128s shift=0.000s
seek → 609.3   gate actual=604896 target=604521 (a late opening: shift=375 applied)           seg-151 itemAxis=604.521 sourceStart=604.896 drift=0.375s shift=0.375s
seek → 689.3   boundary 684809 re-aimed 4s, 8s → gate actual=679762                           seg-171 itemAxis=679.762 planSource=684.809 drift=-5.047s shift=0.000s

Every landing read seek#N programmatic landed rendered≈target, VOD shift published: 0.000s … foldShift=0.000s at each re-aimed seam, and the host's 4 Hz sample read frameAhead=0.000 producerShift=0.000 hostShift=0.000 with t == avpClock — except after the one LATE opening, where the shift machinery engaged as designed (producerShift=0.375 hostShift=0.375). The host places each PGS cue at its source time against sourceTime.

Where AVPlayer put the re-aimed segment. At the resume, before playback started, the clock sat on the plan boundary, not on the media the segment carries: t=352.936 avpClock=352.936 … loaded=[352.9-…] while seg-88 itemAxis=349.891 sourceStart=349.891. And the loaded range then grew by the playlist's planned durations, not the media's: +3.6 / +4.5 / +3.2 / +4.8 / +3.5 s as seg89…93 loaded, against plan durations 3.587 / 4.547 / 3.211 / 4.838 / 3.462 s and media durations 2.544 / 4.713 / 2.002 / 5.797 / 5.965 s. So the player's timeline is the manifest axis, and a segment whose media begins 3.045 s before its manifest position is presented 3.045 s later than its timestamps say. Audio and video sit in the same segment, so lip sync survives; the cues are on the file's real axis; and the clock every consumer reads — currentTime, sourceTime, and for a synced-playback host the position it reports to the room — is on the other one. On 6.39.0 the same restarts applied the shift and the clock was consistent (the landing was what was wrong then). In-window seeks in the second session also landed past their targets (seek#2 target=397.30 landed rendered=399.27, seek#5 449.27 → 449.87), which reads as the same disagreement seen from the seek side.

Whether the error is the latest restart's re-aim or accumulates across restarts I cannot say from ears alone (about 4 s → about 8 s over restarts of −3.0, −3.1, +0.4 shifted and −5.0); happy to measure whatever would settle it.

Incidental, from the same run on 6.42.0: the resume start logged landingWithheld=1 on the #357 subtitle-delivery line and no caption overstayed a landing — the #416 refusal doing its job here.

I don't have a view on the right fix. Re-applying the shift for an early-opening gate puts the clock back on the manifest axis and reopens the landing error #408 fixed; the alternatives are a manifest that tells the truth about where the re-aimed segment starts and how long it runs, or a map that carries the re-aim into sourceTime and the landing. Happy to run any of them against this asset on both devices.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions