Skip to content

Fix seek A/V desync, seek latency and segment-boundary media loss - #2093

Open
larena1 wants to merge 6 commits into
xbmc:Piersfrom
larena1:fix/seek-av-desync
Open

Fix seek A/V desync, seek latency and segment-boundary media loss#2093
larena1 wants to merge 6 commits into
xbmc:Piersfrom
larena1:fix/seek-av-desync

Conversation

@larena1

@larena1 larena1 commented Jul 24, 2026

Copy link
Copy Markdown

Description

Fixes several defects around seeking and segment-boundary handling. The
seek-landing part is MPEG-TS specific, but the segment-buffering, segment
selection and audio co-timing fixes live in the shared layers and apply to
fMP4 (DASH/Smooth) as well.

Shared layers (affect fMP4/DASH/Smooth and TS):

  • Co-time the audio streams to the actually delivered video reader PTS after a
    seek, instead of routing them through the manifest offset
    (ISampleReader::TimeSeekReaderPts).
  • Select the segment with a half-open range [startPTS_, m_endPts), so a PTS on
    a boundary resolves to the segment that starts there instead of the previous
    one.
  • Deliver a partial read of a segment tail instead of failing, so a read
    spanning a segment boundary is satisfied across both segments.
  • Do not drop a segment the reader has only caught up with: wait for the ongoing
    download to deliver more data (or leave the QUEUED/DOWNLOADING state) before
    popping it.
  • Bound that wait (poll with an overall timeout, then fall through to the
    previous behaviour) so it can degrade but never hang the demuxer thread.

MPEG-TS seek landing (TS-specific):

  • Land TS seeks on the segment-start keyframe instead of scanning forward, so
    the reported PTS matches what is delivered and no extra segment is downloaded.
    Audio-only TS keeps the forward scan (no keyframes to snap to).
  • Honour the result of the byte-stream seek instead of ignoring it.
  • Reject a seek that lands before the buffered segment rather than wrapping the
    forward-only byte stream.

Motivation and context

Seeking produced audible/visible defects:

  • A/V desync after a seek – the video lands on its segment-start sync sample,
    but each audio representation was positioned through its own manifest timing
    plus a frozen per-stream PTS diff. Deep into a recording the timelines drift
    apart by a fixed offset, so audio emitted a PTS ~1.8 s from the video and the
    picture started seconds before the sound. Hit on every skip seek and on
    resume-from-position. Observed on fMP4 (DASH/Smooth) and TS.
  • Wrong segment on a boundary seekCSegContainer::FindByPTSOrNext treated
    m_endPts as inclusive, so a PTS landing exactly on a segment boundary matched
    the segment that ends there and selected the previous segment; the audio
    started up to a full segment ahead. Format-agnostic, hit on every seek.
  • Segment-boundary media loss during playback and after a seek – the shared
    AdaptiveStream layer dropped a segment the reader had only caught up with
    (treating "downloaded so far" as "fully read"), and discarded the unread tail
    of a segment when a read straddled its end. Both punch multi-second holes into
    the delivered media with no read error, no failed seek and no IO error –
    starving the player into a stillframe/decoder reset while audio keeps playing.
  • TS seek latency / overshoot and desync – the TS seek scanned forward for a
    keyframe; the parser read-ahead pushed the next recognised keyframe to the
    following segment boundary, downloading the whole current segment, overshooting
    the target, and reporting a PTS that did not match the delivered frame.

How has this been tested?

Built for Android and exercised on-device daily for over a week across a variety
of streams, with no regressions observed. On the primary HLS/TS test stream (one
keyframe per ~10 s segment, 188-byte aligned, separate AAC audio): scrub and skip
seeks land on the correct frame, audio and video stay in sync, and there is no
segment-boundary media loss during plain playback or after a seek. The A/V
co-timing path was additionally verified against fMP4 (DASH/Smooth), where the
same desync was reproducible before the change.

Screenshots (if appropriate):

N/A

Types of change

  • Bug fix (non-breaking change which fixes an issue)
  • Clean up (non-breaking change which removes non-working, unmaintained functionality)
  • Improvement (non-breaking change which improves existing functionality)
  • New feature (non-breaking change which adds functionality)
  • Breaking change (fix or feature that will cause existing functionality to change)
  • Cosmetic change (non-breaking change that doesn't touch code)
  • None of the above (please explain below)

Checklist:

  • I have read the Contributing document
  • My code follows the Code Guidelines of this project
  • My change requires a change to the Wiki documentation
  • I have updated the documentation accordingly

@kodiai

kodiai Bot commented Jul 24, 2026

Copy link
Copy Markdown
Review Details
  • Review plan: ready hash=66537c4530ba route=standard task=review.full files=11 lines=279(local-diff) budget=na/790s gates=3/3 publish=canonical-visible-surface graph=skipped candidates=preferred doctrine=disabled/0/0/0 reasons=disabled

  • Review reducer: ready input=1 kept=1 suppressed=0 rewritten=0 deprioritized=0 lowConfidence=0 auditEvents=0 severityDemoted=0 graphValidated=0 graphUncertain=0 doctrine=disabled/0/0/0 reasons=disabled

  • Review candidates: shadow recorded=1 rejected=0 errors=0 artifact=present repo=xbmc-inputstream.adaptive pr=2093 key=kodiai-review-output:v1:inst-109141824:xbmc-inputstream.adaptive:pr-2093:action- delivery=4cf55130-87b2-11f1-86ff-330021fd0f7c

  • Review candidate publication: mode=moved-to-details approved=1 rewritten=0 publishable=0 nonPublishable=1 fixBlocked=1 published=0 directFallback=0 reasons=candidate-moved-to-details,fix-eligibility-blocked movedToDetails=1 detailsOmitted=0 buckets=blocked:1:fix-eligibility-blocked+missing-replacement,moved-to-details:1:candidate-moved-to-details+missing-replacement

  • Moved review candidates preserved in details:

    • [major/correctness] Dangling reference risk in ensureSegment wait loop (src/common/AdaptiveStream.cpp:806, reason=missing-replacement) — [MAJOR] The frontBuffer reference is obtained at line 797 and held across the wait loop (lines 800-806). During each wait_for(lckrw, pollInterval) call, th…
  • M072 candidate publication bridge: status=denied; bridgeVersion=candidate-publication-bridge.v1; bridgeId=candidate-publication-record:d1cdbbd69388f4576efb6ab23712c1e4; recordKey=candidate-publication-record:d1cdbbd69388f4576efb6ab23712c1e4; correlationKey=candidate-publication-bridge:7a4cec75f8ad0d4fdd363b6d08cce641; source=review-handler-publication; candidateRef=candidate-publication-summary-47f1f4d3; verification=none; counts=candidateCount:0,evidenceCount:0,verifiedCount:0,partiallyVerifiedCount:0,unverifiedCount:0,disprovenCount:0,publicationEligibleCount:0,malformedRecordCount:0,unsafeInputFieldCount:0; reasons=no-evidence,publication-ineligible; malformed=none; presence=deliveryId:y,reviewOutputKey:y,upstreamCorrelationKey:y,policyCorrelationKey:y; handoffOwner=available; redaction=privateOnly:y,rawPayloads:n,publicationFields:n,evidencePayloads:n,githubCommentBody:n,reducerRawPayload:n,discardedRawPayload:n,discardedPublicationFields:n,discardedEvidencePayloads:n

  • Review finding lifecycle: status=normalized; counts=input:1,recorded:1,rejected:0,unsafeInputFields:0; correlation=repo:y,pull:y,reviewOutputKey:y,deliveryId:y,commit:y; statuses=detected:1,open:1,suggested:0,validated:0,revalidated:0,resolved:0,blocked:0,degraded:0; severity=critical:0,major:1,medium:0,minor:0; actionability=actionable:0,needs-human-review:1,needs-reproduction:0,blocked:0,not-actionable:0; reasons=automatic-detected,automatic-open,automatic-review; rejected=none; redaction=privateOnly:y,rawPrompts:n,rawModelOutput:n,candidateBodies:n,toolPayloads:n,secretLike:n,diffs:n,unboundedArrays:n,unsafeFields:0

  • Review validation truth: status=normalized; counts=detected:1,suggested:0,validated:0,revalidated:0,resolved:0,blocked:0,degraded:0,open:1,uncertain:0,inputFindings:1,unsafeInputFields:0; evidence=fresh:0,stale:0,missingValidation:1,missingRevalidation:1; reasons=validation-missing:1; refs=rfl-94e8d4e0c0b41a3c:open:validation-missing:fix:n:validation:n:revalidation:n; correlation=reviewOutputKey:y,deliveryId:y; redaction=privateOnly:y,rawPrompts:n,rawModelOutput:n,candidateBodies:n,replacementText:n,toolPayloads:n,secretLike:n,diffs:n,unboundedArrays:n,unsafeFields:0

  • Files reviewed: 11

  • Findings: 0 critical, 0 major, 0 medium, 0 minor

  • Lines changed: +260 -19

  • Profile: balanced (auto, lines changed: 279)

  • Contributor experience: coarse-fallback (using coarse fallback signals only)

  • Shadow specialist: lane=docs-config-truth status=skipped reason=no-operator-truth-paths candidateCount=0 decisionCount=0 decisionCounts=candidate:0,duplicate:0,disagreement:0,dismissed:0,unclassifiable:0 duplicateCount=0 disagreementCount=0 dismissedCount=0 unclassifiableCount=0 truncatedCandidateCount=0 metricAvailability=token:n,cost:n,latency:n visiblePublicationDenied=true approvalPublicationDenied=true privateOnly=true shadowOnly=true redacted=raw:n,publication:n,approval:n,unsafe:0 correlationKey=2e37302cadd00c96 deliveryId=4cf55130-87b2-11f1-86ff-330021f… reviewOutputKey=kodiai-review-output:v1:inst-10…

  • Review completed: 2026-07-24T23:02:43.832Z

  • Total wall-clock: 10m 33s

  • Phase timings:

    • queue wait: 0ms
    • workspace preparation: 1.0s
    • retrieval/context assembly: 3.5s
    • executor handoff: 41s
    • remote runtime: 9m 45s
    • publication: 116ms (degraded: captured before publication completed)
  • Tokens: 160 in / 27,254 out | 0.7850

  • Keyword parsing: No keywords detected

  • Budget behavior: scoped (prompt-budget-limited).

  • Prompt budget: 5 sections, 1 trimmed, 0 bypassed, 2413 trimmed tokens.

  • Cache behavior: 2 observations, 1 hits, 1 misses, 0 degraded, 0 bypassed.

  • Continuation behavior: 0 observations, 0 compacted, 0 fallback, 0 degraded, 0 bypassed.

@kodiai

kodiai Bot commented Jul 24, 2026

Copy link
Copy Markdown

Decision: NOT APPROVED

Issues:

  • MAJOR src/common/AdaptiveStream.cpp:806 — Dangling reference risk in ensureSegment wait loop
    [MAJOR] The frontBuffer reference is obtained at line 797 and held across the wait loop (lines 800-806). During each wait_for(lckrw, pollInterval) call, the mutex is atomically released, creating a window where other threads could modi…

The findings need attention even though Kodiai could not produce safe automatic patches for them.

Review Details
  • Review plan: ready hash=66537c4530ba route=standard task=review.full files=11 lines=279(local-diff) budget=na/790s gates=3/3 publish=canonical-visible-surface graph=skipped candidates=preferred doctrine=disabled/0/0/0 reasons=disabled

  • Review reducer: ready input=1 kept=1 suppressed=0 rewritten=0 deprioritized=0 lowConfidence=0 auditEvents=0 severityDemoted=0 graphValidated=0 graphUncertain=0 doctrine=disabled/0/0/0 reasons=disabled

  • Review candidates: shadow recorded=1 rejected=0 errors=0 artifact=present repo=xbmc-inputstream.adaptive pr=2093 key=kodiai-review-output:v1:inst-109141824:xbmc-inputstream.adaptive:pr-2093:action- delivery=4cf55130-87b2-11f1-86ff-330021fd0f7c

  • Review candidate publication: mode=moved-to-details approved=1 rewritten=0 publishable=0 nonPublishable=1 fixBlocked=1 published=0 directFallback=0 reasons=candidate-moved-to-details,fix-eligibility-blocked movedToDetails=1 detailsOmitted=0 buckets=blocked:1:fix-eligibility-blocked+missing-replacement,moved-to-details:1:candidate-moved-to-details+missing-replacement

  • Moved review candidates preserved in details:

    • [major/correctness] Dangling reference risk in ensureSegment wait loop (src/common/AdaptiveStream.cpp:806, reason=missing-replacement) — [MAJOR] The frontBuffer reference is obtained at line 797 and held across the wait loop (lines 800-806). During each wait_for(lckrw, pollInterval) call, th…
  • M072 candidate publication bridge: status=denied; bridgeVersion=candidate-publication-bridge.v1; bridgeId=candidate-publication-record:d1cdbbd69388f4576efb6ab23712c1e4; recordKey=candidate-publication-record:d1cdbbd69388f4576efb6ab23712c1e4; correlationKey=candidate-publication-bridge:7a4cec75f8ad0d4fdd363b6d08cce641; source=review-handler-publication; candidateRef=candidate-publication-summary-47f1f4d3; verification=none; counts=candidateCount:0,evidenceCount:0,verifiedCount:0,partiallyVerifiedCount:0,unverifiedCount:0,disprovenCount:0,publicationEligibleCount:0,malformedRecordCount:0,unsafeInputFieldCount:0; reasons=no-evidence,publication-ineligible; malformed=none; presence=deliveryId:y,reviewOutputKey:y,upstreamCorrelationKey:y,policyCorrelationKey:y; handoffOwner=available; redaction=privateOnly:y,rawPayloads:n,publicationFields:n,evidencePayloads:n,githubCommentBody:n,reducerRawPayload:n,discardedRawPayload:n,discardedPublicationFields:n,discardedEvidencePayloads:n

  • Review finding lifecycle: status=normalized; counts=input:1,recorded:1,rejected:0,unsafeInputFields:0; correlation=repo:y,pull:y,reviewOutputKey:y,deliveryId:y,commit:y; statuses=detected:1,open:1,suggested:0,validated:0,revalidated:0,resolved:0,blocked:0,degraded:0; severity=critical:0,major:1,medium:0,minor:0; actionability=actionable:0,needs-human-review:1,needs-reproduction:0,blocked:0,not-actionable:0; reasons=automatic-detected,automatic-open,automatic-review; rejected=none; redaction=privateOnly:y,rawPrompts:n,rawModelOutput:n,candidateBodies:n,toolPayloads:n,secretLike:n,diffs:n,unboundedArrays:n,unsafeFields:0

  • Review validation truth: status=normalized; counts=detected:1,suggested:0,validated:0,revalidated:0,resolved:0,blocked:0,degraded:0,open:1,uncertain:0,inputFindings:1,unsafeInputFields:0; evidence=fresh:0,stale:0,missingValidation:1,missingRevalidation:1; reasons=validation-missing:1; refs=rfl-94e8d4e0c0b41a3c:open:validation-missing:fix:n:validation:n:revalidation:n; correlation=reviewOutputKey:y,deliveryId:y; redaction=privateOnly:y,rawPrompts:n,rawModelOutput:n,candidateBodies:n,replacementText:n,toolPayloads:n,secretLike:n,diffs:n,unboundedArrays:n,unsafeFields:0

  • Files reviewed: 11

  • Findings: 0 critical, 0 major, 0 medium, 0 minor

  • Lines changed: +260 -19

  • Profile: balanced (auto, lines changed: 279)

  • Contributor experience: coarse-fallback (using coarse fallback signals only)

  • Shadow specialist: lane=docs-config-truth status=skipped reason=no-operator-truth-paths candidateCount=0 decisionCount=0 decisionCounts=candidate:0,duplicate:0,disagreement:0,dismissed:0,unclassifiable:0 duplicateCount=0 disagreementCount=0 dismissedCount=0 unclassifiableCount=0 truncatedCandidateCount=0 metricAvailability=token:n,cost:n,latency:n visiblePublicationDenied=true approvalPublicationDenied=true privateOnly=true shadowOnly=true redacted=raw:n,publication:n,approval:n,unsafe:0 correlationKey=2e37302cadd00c96 deliveryId=4cf55130-87b2-11f1-86ff-330021f… reviewOutputKey=kodiai-review-output:v1:inst-10…

  • Review completed: 2026-07-24T23:02:43.238Z

  • Total wall-clock: 10m 33s

  • Phase timings:

    • queue wait: 0ms
    • workspace preparation: 1.0s
    • retrieval/context assembly: 3.5s
    • executor handoff: 41s
    • remote runtime: 9m 45s
    • publication: 116ms (degraded: captured before publication completed)
  • Tokens: 160 in / 27,254 out | 0.7850

  • Keyword parsing: No keywords detected

  • Budget behavior: scoped (prompt-budget-limited).

  • Prompt budget: 5 sections, 1 trimmed, 0 bypassed, 2413 trimmed tokens.

  • Cache behavior: 2 observations, 1 hits, 1 misses, 0 degraded, 0 bypassed.

  • Continuation behavior: 0 observations, 0 compacted, 0 fallback, 0 degraded, 0 bypassed.

@larena1

larena1 commented Jul 24, 2026

Copy link
Copy Markdown
Author

I looked into the dangling-reference concern on the ensureSegment wait loop and I don't think it can occur under the actual threading model. Reasoning:

1. The container is a std::deque (CSegmentBuffers::m_buffers). push_back never invalidates references to existing elements, and pop_front only invalidates the reference to the erased front. So frontBuffer can only dangle if another thread erases the front (PopFront) or clears the deque (Reset) during the wait.

2. The only genuinely concurrent thread — the download worker (worker()) — never modifies the deque structurally. It only calls GetNextDownload/NotifyDownloadCompleted (which touch m_downloadIndex, not the structure) and ChangeState/size updates on existing elements. No PopFront, Reset, or Push. Mutating fields of the referenced element does not invalidate the reference — that is exactly the benign, racy state/size update already documented in the comment above the loop.

3. Every structural modifier runs on the read/demux thread itself, or during teardown:

  • AlignBufferToSegment (PopFront/Reset) is on the seek path — same thread as DemuxReadensureSegment, since Kodi serializes seek and read; it also pauses/stops downloads first.
  • ensureSegment's own PopFront runs later in the same call, not during the wait.
  • Dispose's Reset deletes thread_data_ immediately afterwards, so it only runs once the threads are stopped (otherwise the mutexRW/cvRW use in the loop would already be UB).

Because the thread executing the loop is itself blocked in it, none of these can pop/reset concurrently with the wait.

4. This mirrors the pre-existing seek() method, which caches m_segBuffers.Front() across a cvRW.wait() on the same mutex. The invariant ("structural changes to m_segBuffers happen only on the read/demux thread") is established code, not something this change introduces.

I'm happy to add a short comment on the loop documenting that invariant so this is easier to verify in future reviews. Let me know if you'd prefer that, or if I've missed a path where PopFront/Reset can be reached off the read thread.

larena1 added 6 commits July 25, 2026 02:01
…ment tail

read() advanced segment_read_pos_ and absolute_position_ by the number of bytes
available, but only copied them out and reported them when they happened to satisfy
the full requested amount. Whenever a read straddled the end of a segment buffer -
which happens at every segment boundary - the remaining bytes were skipped over
without ever being delivered, and the caller was told the read failed.

For the TS demuxer that error turns into AVCONTEXT_IO_ERROR, and TSReader::ReadPacket
recovers from it by calling Reset(), whose Tell() runs read(0, 0) and therefore
ensureSegment(), advancing to the next segment. The parser re-anchors there and
everything it had not yet emitted from the current segment is lost - a hole of
several seconds in the delivered video, at segment boundaries during plain playback
as well as after a seek.

Copy and report what is available. ReadPartial is a partial read by contract and
AP4_ByteStream::Read loops for the remainder, so a request spanning a segment
boundary is now satisfied across both segments instead of failing.

Also guard the unsigned subtraction that computes the available count: a read
position past the downloaded end would wrap to a huge value and read beyond the
buffer. Equality is legitimate - nothing is available yet and the wait below may
still deliver data - so only a position strictly beyond it is rejected.

Assisted-by: Claude Opus 5 <noreply@anthropic.com>
…with

ensureSegment() treats "read position has reached BufferSize()" as "segment fully
read". BufferSize() is however the amount downloaded so far, not the size of the
segment. When the reader catches up with an ongoing download - at startup, and after
every seek, where the download has no head start - the read position reaches that end
long before the segment is complete, and the segment is popped with everything that
had not yet arrived.

Nothing fails visibly at that point: ResetSegment() sets segment_read_pos_ to 0 and
leaves absolute_position_ alone for TS, so the absolute position maps cleanly onto the
following segment and the demuxer simply reads on there. The result is a hole of
several seconds in the delivered media with no read error, no failed seek and no IO
error anywhere - which starves Kodi's video player into a stillframe and a decoder
reset while audio keeps playing.

The existing lock_guard on mutexWorker was aimed at this case but only waits for the
mutex, not for data; read() has the correct wait but runs after this decision has
already been made.

Wait on the same condition variable read() uses until the download delivers more data
or leaves the QUEUED/DOWNLOADING state, then re-check before popping.

The wait is polled and bounded rather than indefinite: the download thread changes the
buffer state and notifies cvRW without holding mutexRW, so a notification issued
between the predicate check and the wait is lost and the waiter would never wake, and
downloads can also be paused, in which case no notification is coming at all. This was
observed on a stream with small, quickly downloaded segments, where the segment reached
DOWNLOADED one millisecond after the reader caught up and the demuxer thread blocked -
which also made the player impossible to stop. Re-evaluating on a timeout covers both
cases, and on expiry the code falls through to the previous behaviour, so this can
degrade but never hang.

Verified with instrumentation on the affected stream: the condition fires reliably at
every download chunk boundary (segment_read_pos_ 1540096, 3080192, ... = multiples of
8192 TS packets), and with the wait in place seven consecutive seeks produced no gap
in the packets delivered to Kodi, where every previous build produced one within
seconds of the seek and at playback start.

Assisted-by: Claude Opus 5 <noreply@anthropic.com>
…stead of wrapping

Positions passed to seek() are absolute over the whole stream while only the current
segment is buffered. A position before that segment underflowed the unsigned
subtraction that maps it into the segment buffer, producing a huge offset that the
following clamp turned into "end of the current segment" - and the method then
returned false having already moved the read position.

TSReader::ReadAV in turn discarded the result of Seek() and read regardless. So the
parser was handed valid-looking data from an entirely different point in the timeline
while being told the read succeeded, then continued in the *next* segment, silently
dropping everything in between.

Reject the out-of-range position up front so the failure is explicit and the read
position stays untouched, and propagate it in ReadAV so the demuxer sees an IO error
instead of wrong data.

Assisted-by: Claude Opus 5 <noreply@anthropic.com>
Two problems on MPEG-TS seeks:

1. Latency: the seek scanned forward for a keyframe at/after the target.
   The MPEG-TS parser reads ahead, so on long-GOP content the next
   recognised keyframe was at the following segment boundary - the scan
   downloaded the whole current segment (seconds of latency) and overshot
   the requested time.

2. A/V desync: because of the same read-ahead the reported PTS did not
   match the frame actually delivered, so CSession::SeekTime aligned the
   audio streams to the wrong PTS and audio started ahead of the picture.

Stop at the first recovery point (keyframe) instead, which is the one that starts the
segment AdaptiveStream::seek_time already selected as containing the requested time.
This content carries a single keyframe per segment, at its start (verified on a sample
segment: one random_access_indicator, at the first video packet, followed by a 250
frame / 10 second GOP), so the previous scan could not land inside the current segment
at all. The scan is still bounded by timeInTs, so a stream that never flags a recovery
point degrades to the previous behaviour instead of scanning to EOS.

Do not reposition to the recovery position afterwards. The packet we want is already
read and CTSSampleReader::TimeSeek hands this m_pkt to Kodi as the first sample, while
the packets that follow it are queued in the elementary stream buffers and are drained
in order. Seeking the AVContext back to GetRecoveryPos() instead loses them: the parser
read-ahead puts that position *behind* the packet just delivered, and reading resumed a
full GOP later - the video stream got a hole of seconds right after every seek while
audio kept feeding, which starves Kodi's video player into a stillframe and a decoder
reset.

The reported PTS now matches what is delivered (A/V stays aligned), and no extra
segment is downloaded. For scrubber (accurate) seeks Kodi drops the decoded frames up
to the requested time, landing exactly; skip seeks land on the segment-start keyframe.

Audio-only TS keeps the forward scan (no keyframes to snap to).

Assisted-by: Claude Opus 5 <noreply@anthropic.com>
CSegContainer::FindByPTSOrNext treated m_endPts as inclusive, but it is the
exclusive end of a segment - for a contiguous timeline it equals the start PTS
of the next segment. A pts landing exactly on a boundary therefore matched the
segment that *ends* there and the search returned the previous segment.

This is hit on every seek: CSession::SeekTime replaces the requested time with
the PTS of the video sample actually found and aligns the audio streams to it.
Since the video seek lands on a segment-start keyframe, that PTS is exactly a
segment boundary, so the audio stream selected the preceding segment and
started up to a full segment ahead of the picture.

Use the half-open range [startPTS_, m_endPts). A pts at the very end of the
last segment still resolves to that segment, so seeking to the stream end is
unchanged.

Assisted-by: Claude Opus 5 <noreply@anthropic.com>
After a seek the video lands on its segment-start sync sample, but each audio
representation was still positioned through its own manifest timing plus the
frozen per-stream PTS diff (CSession::SeekTime -> ISampleReader::TimeSeek).
Deep into a recording the audio and video timelines drift apart by a fixed
offset, so the audio reader emitted a PTS ~1.8s away from the video sample.
Kodi's VideoPlayer synchronises on the emitted PTS, not on the addon's internal
elapsed time, so the picture started seconds before the sound. This is hit on
every skip seek and, identically, on resume-from-position (Kodi issues a seek
to the resume point right at startup). Observed on fMP4 (DASH/Smooth) and TS.

Audio and video are delivered from the same source PTS clock. Once the video
sample actually delivered is known, align the audio reader straight to that
reader PTS instead of routing it through the manifest offset:

- ISampleReader::TimeSeekReaderPts(pts): seek to an absolute reader PTS (the
  domain PTS() returns), i.e. without the TimeSeek() m_ptsDiff compensation.
  Implemented once on the interface by removing that compensation before
  delegating to TimeSeek(), which every reader already applies.
- CSession::SeekTime remembers the video reader PTS and co-times the audio
  streams that own a segment buffer to it. SeekAdStream has already reset the
  audio segment to its start, so the seek lands on the target whether or not the
  reader was running yet - this also covers the resume seek that happens before
  the first DemuxRead starts the readers. Segment selection is unchanged (it
  already uses the common elapsed time); only the in-segment reader landing is
  corrected. fMP4 audio muxed into the video stream (no own segment buffer,
  hasAdStream == false) keeps its existing behaviour.

A LOGINFO/LOGWARNING line reports the residual A/V delta after alignment, so a
bad landing (target outside the selected audio segment) is visible in the log
rather than only audible.

Assisted-by: Claude Opus 5 <noreply@anthropic.com>
@larena1
larena1 force-pushed the fix/seek-av-desync branch from e18d2f2 to 4f6ed61 Compare July 25, 2026 00:10
@CastagnaIT

Copy link
Copy Markdown
Collaborator

today i dont have time to review nor to test nothing,
so i write here some note as reminder

  • in the AdaptiveStream::ensureSegment method, this method has the purpose to ensure "future" segments for download, so it should not have things like "wait for data" as done
  • the changes under CSession::SeekTime method should be taken with a grain of salt, it's very easy to break some manifest use case (VOD or Live with/without multiple-periods) it's not clear here what manifest type has been tested, i'm concerned about the removal of GetAbsolutePTSOffset use, needed to verify carefully differences before/after

@larena1

larena1 commented Jul 25, 2026

Copy link
Copy Markdown
Author

These two logs are what the series started from: a seek on HLS that takes ~5 seconds, and audio that starts seconds before the picture on both HLS and DASH. Both were recorded before the patches.

HLS — seek latency and the video hole afterwards

2026-07-25 00:56:51.609 T:19400   debug <general>: demuxer seek to: 1275387.000000
2026-07-25 00:56:51.609 T:19400    info <inputstream.adaptive>: PosTime (1275387)
2026-07-25 00:56:51.623 T:19414   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00128.ts>
2026-07-25 00:56:51.671 T:19451   debug <general>: CDVDAudio::Pause - pausing audio stream
2026-07-25 00:56:52.029 T:19177   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:56:52.717 T:19414   debug <inputstream.adaptive>: Skipped 3 duplicate messages..
2026-07-25 00:56:52.716 T:19414   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00128.ts (downloaded 10302024 byte, speed 9428415.00 byte/s)
2026-07-25 00:56:52.718 T:19414   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00129.ts>
2026-07-25 00:56:52.751 T:19462   debug <CWebserver[8080]>: request received for /jsonrpc?Application.GetProperties
2026-07-25 00:56:52.758 T:19388   debug <CWebserver[8080]>: Skipped 2 duplicate messages..
2026-07-25 00:56:52.758 T:19388   debug <CWebserver[8080]>: request received for /jsonrpc?Player.GetActivePlayers
2026-07-25 00:56:52.769 T:19388   debug <CWebserver[8080]>: Skipped 2 duplicate messages..
2026-07-25 00:56:52.769 T:19388   debug <CWebserver[8080]>: request received for /jsonrpc?Base
2026-07-25 00:56:53.761 T:19177   debug <CWebserver[8080]>: Skipped 2 duplicate messages..
2026-07-25 00:56:53.761 T:19177   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:56:53.768 T:19414   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00129.ts (downloaded 9282688 byte, speed 8838424.00 byte/s)
2026-07-25 00:56:53.769 T:19414   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00130.ts>
2026-07-25 00:56:53.777 T:19177   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:56:54.042 T:19736   debug <general>: Skipped 2 duplicate messages..
2026-07-25 00:56:54.042 T:19736   debug <general>: TEMP: [framecount] video=7920 ctrls=4283 subs=0 skip-gui=2568 skip-any=6192
2026-07-25 00:56:54.874 T:19414   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00130.ts (downloaded 9513364 byte, speed 8613994.00 byte/s)
2026-07-25 00:56:54.876 T:19414   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00131.ts>
2026-07-25 00:56:55.385 T:19177   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:56:55.977 T:19414   debug <inputstream.adaptive>: Skipped 3 duplicate messages..
2026-07-25 00:56:55.977 T:19414   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00131.ts (downloaded 9122700 byte, speed 8287652.00 byte/s)
2026-07-25 00:56:55.982 T:19414   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00132.ts>
2026-07-25 00:56:55.986 T:19400    info <inputstream.adaptive>: Seek time 1275.4 for stream: 1001 continues at 1280.0 (PTS: 1282080000)
2026-07-25 00:56:55.987 T:19400    info <inputstream.adaptive>: Corrected seek time PTS from 1275387060 to 1280000000
2026-07-25 00:56:55.988 T:19450   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00128.aac>
2026-07-25 00:56:56.162 T:19450   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00128.aac (downloaded 160262 byte, speed 926080.00 byte/s)
2026-07-25 00:56:56.163 T:19450   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00129.aac>
2026-07-25 00:56:56.228 T:19400    info <inputstream.adaptive>: Seek time 1280.0 for stream: 1002 continues at 1280.0 (PTS: 1282089333)
2026-07-25 00:56:56.229 T:19400   debug <general>: demuxer seek to: 1275387.000000, success
2026-07-25 00:56:56.229 T:19400   debug <general>: CVideoPlayer::FlushBuffers - flushing buffers
2026-07-25 00:56:56.231 T:19446   debug <general>: CDVDVideoCodecAndroidMediaCodec::Reset Current state (3)
2026-07-25 00:56:56.248 T:19446   debug <general>: void CDVDVideoCodecAndroidMediaCodec::InjectExtraData(CJNIMediaFormat &): call
2026-07-25 00:56:56.262 T:19736   error <general>: CMediaCodecVideoBuffer::ReleaseOutputBuffer error in render(false)
2026-07-25 00:56:56.274 T:19450   error <inputstream.adaptive>: Skipped 2 duplicate messages..
2026-07-25 00:56:56.274 T:19450   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00129.aac (downloaded 160169 byte, speed 1461116.00 byte/s)
2026-07-25 00:56:56.275 T:19450   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00130.aac>
2026-07-25 00:56:56.278 T:19451   debug <general>: CDVDAudio::Flush - flush audio stream
2026-07-25 00:56:56.279 T:19451   debug <general>: CDVDAudio::Pause - pausing audio stream
2026-07-25 00:56:56.279 T:19451   debug <general>: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
2026-07-25 00:56:56.292 T:19446   debug <general>: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
2026-07-25 00:56:56.293 T:19446   debug <general>: CVideoPlayerVideo - Stillframe left, switching to normal playback
2026-07-25 00:56:56.293 T:19446   debug <general>: CDVDVideoCodecAndroidMediaCodec::AddData current state (2)
2026-07-25 00:56:56.344 T:19400   debug <general>: Skipped 1 duplicate messages..
2026-07-25 00:56:56.343 T:19400   debug <general>: CVideoPlayer::HandleMessages - player started 1
2026-07-25 00:56:56.344 T:20194   debug <general>: virtual void CApplicationPlayerCallback::OnAVChange(): call
2026-07-25 00:56:56.383 T:19400   debug <general>: CVideoPlayer::HandleMessages - player started 2
2026-07-25 00:56:56.383 T:19400   debug <general>: CVideoPlayer::SetCaching - caching state 3
2026-07-25 00:56:56.384 T:19400   debug <general>: CDVDClock::SetSpeedAdjust - adjusted:0.000000
2026-07-25 00:56:56.384 T:19400   debug <general>: CVideoPlayer::SetCaching - caching state 0
2026-07-25 00:56:56.384 T:19400   debug <general>: CDVDClock::SetSpeedAdjust - adjusted:0.000000
2026-07-25 00:56:56.384 T:19400   debug <general>: VideoPlayer::Sync - Audio - pts: 1282388000.000000, cache: 618860.146431, totalcache: 792375.028133
2026-07-25 00:56:56.384 T:19400   debug <general>: VideoPlayer::Sync - Video - pts: 1282080000.000000, cache: 50000.000000, totalcache: 100000.000000
2026-07-25 00:56:56.385 T:19451   debug <general>: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(1281769139.853569), level: 81, cache: 577453.685431
2026-07-25 00:56:56.385 T:19451   debug <general>: CDVDAudio::Resume - resume audio stream
2026-07-25 00:56:56.385 T:19753   debug <general>: ActiveAE - start sync of audio stream
2026-07-25 00:56:56.385 T:19446   debug <general>: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(1281769139.853569)
2026-07-25 00:56:56.556 T:19753   debug <general>: ActiveAE::SyncStream - average error of -11.167120, start adjusting
2026-07-25 00:56:56.557 T:19753   debug <general>: ActiveAE::SyncStream - average error -0.000453 below threshold of 30.000000
2026-07-25 00:56:56.740 T:19450   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00130.aac (downloaded 160327 byte, speed 345509.00 byte/s)
2026-07-25 00:56:56.741 T:19450   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00131.aac>
2026-07-25 00:56:56.944 T:19446 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:56:57.157 T:19414   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00132.ts (downloaded 8951808 byte, speed 7621654.00 byte/s)
2026-07-25 00:56:57.343 T:19177   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:56:57.381 T:19450   debug <inputstream.adaptive>: Skipped 3 duplicate messages..
2026-07-25 00:56:57.381 T:19450   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00131.aac (downloaded 159808 byte, speed 250114.00 byte/s)
2026-07-25 00:56:57.382 T:19450   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00132.aac>
2026-07-25 00:56:57.460 T:19446 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:56:57.521 T:19450   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_audio_2_00132.aac (downloaded 160298 byte, speed 1159227.00 byte/s)
2026-07-25 00:56:57.977 T:19446 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:56:58.042 T:19736   debug <general>: TEMP: [framecount] video=8160 ctrls=4523 subs=0 skip-gui=2639 skip-any=6263
2026-07-25 00:56:58.494 T:19446 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:56:58.955 T:19177   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:56:59.011 T:19446   debug <general>: Skipped 3 duplicate messages..
2026-07-25 00:56:59.011 T:19446 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:56:59.599 T:19736   debug <general>: ------ Window Deinit (DialogSeekBar.xml) ------
2026-07-25 00:56:59.599 T:19736   debug <general>: ------ Window Deinit (Custom_1109_TopBarOverlay.xml) ------
2026-07-25 00:56:59.998 T:19177   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:57:02.042 T:19736   debug <general>: Skipped 4 duplicate messages..
2026-07-25 00:57:02.042 T:19736   debug <general>: TEMP: [framecount] video=8400 ctrls=4763 subs=0 skip-gui=2835 skip-any=6459
2026-07-25 00:57:02.206 T:19414   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxxx/hls/DCB887260007100310001_1080_00133.ts>

What the timestamps say:

  • The seek is issued at 00:56:51.609 and the video reader reports its landing at 00:56:55.9864.38 s, with demuxer seek ... success at 00:56:56.229, so 4.62 s end to end.
  • In that window four full video segments are downloaded (0012800131, ~38 MB) although the requested position, 1275.4, lies inside the first of them. That is the forward keyframe scan in CTSSampleReader::TimeSeek: it looks for a recovery point at or after the target, and because of the MPEG-TS parser read-ahead the next one it recognises is a segment boundary away. The stream carries a single keyframe per 10 s segment, at its start, so the scan could never land inside the current segment — it had to walk forward. It also explains the overshoot: 1275.4 requested, continues at 1280.0, i.e. 4.6 s past the requested time.
  • Walking through four segments rather than one is the second bug showing through: while the scan reads faster than the download delivers, ensureSegment() sees the read position at BufferSize() and pops each segment while it is still downloading, so the scan is carried past the keyframe it was looking for.
  • Corrected seek time PTS from 1275387060 to 1280000000 is CSession::SeekTime replacing the request with the PTS the video reader reported. The audio is then aligned to that value — but with the read-ahead the reported PTS is not the frame that was actually handed to Kodi, so the alignment reference is wrong to begin with. At the player, VideoPlayer::Sync starts audio at pts 1282388000 against video 1282080000, 308 ms apart, with 619 ms of audio cache against 50 ms of video.
  • Afterwards the video pipeline runs dry: OutputPicture - timeout waiting for buffer from 00:56:56.944 to 00:57:00.194 (~3.3 s), around a MediaCodec Reset and a ReleaseOutputBuffer error, while audio keeps being fed and pre-buffers four segments in a second. That is the signature of media that was silently dropped rather than delivered — no read error, no failed seek, just a hole.

Covered by:

  • [TSReader] Land TS seeks on the segment-start keyframe — stop at the first recovery point instead of scanning forward, and do not reposition the AVContext to GetRecoveryPos() afterwards (that position sits behind the packet already read, which lost a full GOP after every seek). No extra segment is downloaded, and the reported PTS is the one actually delivered, so the audio alignment has a correct reference. Skip seeks land on the segment-start keyframe; for accurate seeks Kodi drops the decoded frames up to the requested time.
  • [AdaptiveStream] Do not drop a segment the reader has only caught up withBufferSize() is what has been downloaded so far, not the segment size. Wait on the same condition variable read() uses (bounded and polled, so it can degrade but never hang) and re-check before popping.
  • [AdaptiveStream] Deliver a partial read instead of discarding the segment tailread() advanced the positions by the available bytes but only reported them when the full request could be satisfied, so every read straddling a segment boundary threw away the tail and returned an error; for the TS demuxer that error turns into AVCONTEXT_IO_ERROR and a Reset() that re-anchors in the next segment.
  • [AdaptiveStream][TSReader] Fail a seek before the buffered segment instead of wrapping — a position before the buffered segment underflowed the unsigned subtraction and was clamped to "end of current segment", and ReadAV discarded the Seek() result and read on, so the parser was fed data from a different point in the timeline and told it succeeded.

DASH — audio lands a full segment ahead of the picture

2026-07-25 00:03:52.647 T:22344   debug <general>: demuxer seek to: 1093689.000000
2026-07-25 00:03:52.647 T:22344    info <inputstream.adaptive>: PosTime (1093689)
2026-07-25 00:03:52.667 T:22358   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000110.mp4>
2026-07-25 00:03:52.695 T:22376   debug <general>: CDVDAudio::Pause - pausing audio stream
2026-07-25 00:03:52.839 T:22344    info <inputstream.adaptive>: Seek time 1093.7 for stream: 1001 continues at 1090.0 (PTS: 1090080000)
2026-07-25 00:03:52.839 T:22344    info <inputstream.adaptive>: Corrected seek time PTS from 1093689051 to 1090000000
2026-07-25 00:03:52.840 T:22375   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000109.mp4>
2026-07-25 00:03:53.066 T:22344    info <inputstream.adaptive>: Seek time 1090.0 for stream: 1002 continues at 1082.0 (PTS: 1082026666)
2026-07-25 00:03:53.066 T:22344   debug <general>: demuxer seek to: 1093689.000000, success
2026-07-25 00:03:53.067 T:22344   debug <general>: CVideoPlayer::FlushBuffers - flushing buffers
2026-07-25 00:03:53.068 T:22371   debug <general>: CDVDVideoCodecAndroidMediaCodec::Reset Current state (3)
2026-07-25 00:03:53.080 T:22376   debug <general>: CDVDAudio::Flush - flush audio stream
2026-07-25 00:03:53.080 T:22376   debug <general>: CDVDAudio::Pause - pausing audio stream
2026-07-25 00:03:53.081 T:22371   debug <general>: void CDVDVideoCodecAndroidMediaCodec::InjectExtraData(CJNIMediaFormat &): call
2026-07-25 00:03:53.084 T:22371   debug <general>: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
2026-07-25 00:03:53.084 T:22376   debug <general>: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
2026-07-25 00:03:53.088 T:21931   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:03:53.093 T:22344   debug <general>: CVideoPlayer::HandleMessages - player started 1
2026-07-25 00:03:53.093 T:22650   debug <general>: Thread JobWorker start, auto delete: true
2026-07-25 00:03:53.094 T:22344   debug <general>: VideoPlayer::Sync - Audio - pts: 1082325333.000000, cache: 320000.022650, totalcache: 792375.028133
2026-07-25 00:03:53.094 T:22344   debug <general>: CVideoPlayer::SetCaching - caching state 0
2026-07-25 00:03:53.094 T:22371   debug <general>: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(1082005332.977350)
2026-07-25 00:03:53.094 T:22344   debug <general>: CDVDClock::SetSpeedAdjust - adjusted:0.000000
2026-07-25 00:03:53.094 T:22650   debug <general>: [threads] name: 'JobWorker' priority: '1'
2026-07-25 00:03:53.108 T:22650   debug <general>: virtual void CApplicationPlayerCallback::OnAVChange(): call
2026-07-25 00:03:53.106 T:21931   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:03:53.095 T:22376   debug <general>: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(1082005332.977350), level: 90, cache: 320000.022650
2026-07-25 00:03:53.108 T:19736   error <general>: CMediaCodecVideoBuffer::ReleaseOutputBuffer error in render(false)
2026-07-25 00:03:53.109 T:19753   debug <general>: ActiveAE - start sync of audio stream
2026-07-25 00:03:53.110 T:19736   error <general>: CMediaCodecVideoBuffer::ReleaseOutputBuffer error in render(false)
2026-07-25 00:03:53.110 T:22376   debug <general>: CDVDAudio::Resume - resume audio stream
2026-07-25 00:03:53.111 T:19736   error <general>: CMediaCodecVideoBuffer::ReleaseOutputBuffer error in render(false)
2026-07-25 00:03:53.119 T:21931   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:03:53.232 T:19753   debug <general>: Skipped 1 duplicate messages..
2026-07-25 00:03:53.232 T:19753   debug <general>: ActiveAE::SyncStream - average error of -354.336050, start adjusting
2026-07-25 00:03:53.232 T:19753   debug <general>: ActiveAE::SyncStream - average error -17.752717 below threshold of 30.000000
2026-07-25 00:03:53.277 T:22375   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000109.mp4 (downloaded 166210 byte, speed 381120.00 byte/s)
2026-07-25 00:03:53.278 T:22375   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000110.mp4>
2026-07-25 00:03:53.730 T:22375   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000110.mp4 (downloaded 166484 byte, speed 660208.00 byte/s)
2026-07-25 00:03:53.732 T:22375   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000111.mp4>
2026-07-25 00:03:53.858 T:21975   debug <CWebserver[8080]>: request received for /jsonrpc?Application.GetProperties
2026-07-25 00:03:53.893 T:21972   debug <CWebserver[8080]>: Skipped 2 duplicate messages..
2026-07-25 00:03:53.893 T:21972   debug <CWebserver[8080]>: request received for /jsonrpc?Player.GetActivePlayers
2026-07-25 00:03:53.907 T:21975   debug <CWebserver[8080]>: Skipped 2 duplicate messages..
2026-07-25 00:03:53.907 T:21975   debug <CWebserver[8080]>: request received for /jsonrpc?Base
2026-07-25 00:03:54.024 T:22358   debug <inputstream.adaptive>: Skipped 2 duplicate messages..
2026-07-25 00:03:54.024 T:22358   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000110.mp4 (downloaded 10046665 byte, speed 7406931.00 byte/s)
2026-07-25 00:03:54.026 T:22358   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000111.mp4>
2026-07-25 00:03:54.256 T:22376   debug <general>: CDVDClock::ErrorAdjust - CVideoPlayerAudio::OutputPacket - error:-58813.217730, adjusted:-58813.217730
2026-07-25 00:03:54.358 T:22375   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000111.mp4 (downloaded 165918 byte, speed 389289.00 byte/s)
2026-07-25 00:03:54.359 T:22375   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000112.mp4>
2026-07-25 00:03:54.503 T:22375   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000112.mp4 (downloaded 166419 byte, speed 1165325.00 byte/s)
2026-07-25 00:03:54.834 T:21931   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:03:55.132 T:22358   debug <inputstream.adaptive>: Skipped 3 duplicate messages..
2026-07-25 00:03:55.131 T:22358   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000111.mp4 (downloaded 8919043 byte, speed 8068837.00 byte/s)
2026-07-25 00:03:55.133 T:22358   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000112.mp4>
2026-07-25 00:03:55.675 T:19736   debug <general>: TEMP: [framecount] video=3600 ctrls=3600 subs=0 skip-gui=2348 skip-any=2348
2026-07-25 00:03:56.051 T:22358   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000112.mp4 (downloaded 8062476 byte, speed 8790572.00 byte/s)
2026-07-25 00:03:56.052 T:22358   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000113.mp4>
2026-07-25 00:03:56.307 T:22371   debug <general>: CVideoPlayerVideo - Stillframe left, switching to normal playback
2026-07-25 00:03:56.307 T:22371   debug <general>: CDVDVideoCodecAndroidMediaCodec::AddData current state (2)
2026-07-25 00:03:56.331 T:22375   debug <general>: CurlFile::Open - <https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000113.mp4>
2026-07-25 00:03:56.402 T:19736   debug <general>: ------ Window Deinit (DialogSeekBar.xml) ------
2026-07-25 00:03:56.403 T:19736   debug <general>: ------ Window Deinit (Custom_1109_TopBarOverlay.xml) ------
2026-07-25 00:03:56.573 T:21931   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:03:56.725 T:22375   debug <inputstream.adaptive>: Skipped 3 duplicate messages..
2026-07-25 00:03:56.725 T:22375   debug <inputstream.adaptive>: [AS-1] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_audio_1_000000113.mp4 (downloaded 166289 byte, speed 423737.00 byte/s)
2026-07-25 00:03:57.111 T:22371 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:03:57.601 T:22358   debug <inputstream.adaptive>: [AS-0] Download finished: https://streaming.aurora.enhanced.live/xxxx/DCB892660010100310001/dash/DCB892660010100310001_1080_000000113.mp4 (downloaded 10040321 byte, speed 6484826.00 byte/s)
2026-07-25 00:03:57.613 T:22371 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:03:58.221 T:21931 warning <CWebserver[8080]>: Skipped 1 duplicate messages..
2026-07-25 00:03:58.221 T:21931   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:03:58.343 T:19771   debug <general>: Skipped 3 duplicate messages..
2026-07-25 00:03:58.343 T:19771   debug <general>: [plugin.video.youtube] service_runner:138(run) - Clear property 'plugin_sleeping'
2026-07-25 00:03:58.360 T:19771   debug <general>: [plugin.video.youtube] service_runner:244(run) - Set property 'plugin_sleeping': 'true'
2026-07-25 00:03:58.643 T:22371 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:03:59.675 T:19736 warning <general>: Skipped 1 duplicate messages..
2026-07-25 00:03:59.675 T:19736   debug <general>: TEMP: [framecount] video=3840 ctrls=3840 subs=0 skip-gui=2472 skip-any=2472
2026-07-25 00:03:59.677 T:22371 warning <general>: OutputPicture - timeout waiting for buffer
2026-07-25 00:03:59.825 T:21931   debug <CWebserver[8080]>: request received for /jsonrpc
2026-07-25 00:04:00.194 T:22371   debug <general>: Skipped 3 duplicate messages..
2026-07-25 00:04:00.194 T:22371 warning <general>: OutputPicture - timeout waiting for buffer

Here the seek itself is quick — 419 ms, fMP4 has a sync sample table and needs no scan — and the desync is visible as plain arithmetic:

  • Video: requested 1093.689, continues at 1090.0 (PTS: 1090080000), segment _1080_000000110 — correct, the segment-start sync sample.
  • Audio: asked for the corrected 1090.0, continues at 1082.0 (PTS: 1082026666), segment _audio_1_000000109. Video PTS minus audio PTS is 8 053 334 µs ≈ 8.05 s, exactly one audio segment: the audio segment preceding the one that starts at 1090.0 was selected.
  • That is CSegContainer::FindByPTSOrNext treating m_endPts as inclusive. m_endPts is the exclusive end and equals the next segment's start on a contiguous timeline, so a PTS landing exactly on a boundary matched the segment that ends there. Every seek hits this, because SeekTime replaces the request with the PTS of the video sample found — and that one is a segment boundary by construction.
  • The consequence at the player is right below: VideoPlayer::Sync - Audio - pts: 1082325333 and GENERAL_RESYNC(1082005332) anchor the clock to the audio timeline, ~8 s behind the video being delivered. ActiveAE::SyncStream - average error of -354.336050 (against −11.2 in the HLS log) and CDVDClock::ErrorAdjust - error:-58813 follow, the picture stays a stillframe until 00:03:56.307, and OutputPicture - timeout waiting for buffer repeats from 00:03:57.111 past 00:04:00.194: the video frames sit several seconds in the future of the clock, so no output buffer is ever recycled.

Covered by:

  • [Segment] Select the segment starting at an exact PTS boundary — use the half-open range [startPTS_, m_endPts). A PTS at the very end of the last segment still resolves to that segment, so seeking to the stream end is unchanged.
  • [Seek] Co-time audio to the delivered video PTS — the audio representations were positioned through their own manifest timing plus the frozen per-stream PTS diff, so deep into a recording they drift from the video by a fixed offset. ISampleReader::TimeSeekReaderPts() seeks to an absolute reader PTS, and CSession::SeekTime aligns every audio stream that owns a segment buffer to the video PTS actually delivered. This also covers resume-from-position, where Kodi issues a seek right at startup before the readers are running. fMP4 audio muxed into the video stream keeps its existing behaviour. The residual A/V delta after alignment is logged, so a bad landing is visible rather than only audible.

Why they surfaced in this order

The HLS seek latency masked the rest: once seeking dropped below a second, the segment that ensureSegment() popped while it was still downloading started to matter, because after a seek the download has no head start and the reader catches up with it immediately. Hence

Do not drop a segment the reader has only caught up with: wait for the ongoing
download to deliver more data (or leave the QUEUED/DOWNLOADING state) before
popping it.

on top of the seek fixes.

With all of this in, seeking and general playback are much better. I have tested DASH VoD, live and live timeshift as well as HLS and did not run into regressions — I would have fixed those too. Still, I would appreciate some thorough testing from your side when you find the time. Thanks!

@matthuisman

Copy link
Copy Markdown
Contributor

just a suggestion - might be easier for users to test and for reviewers if this was broken up into multiple PRs :)
One PR for each problem it fixes :)

@larena1

larena1 commented Jul 27, 2026

Copy link
Copy Markdown
Author

Fair point, and I did consider it. The reason they're together is that they're not independent fixes — they were all found while chasing the same symptom, and they sit on one causal chain. Split up, none of them is really testable on its own: a build with only one of them still stalls, because the remaining ones produce the same visible symptom. That would mostly generate "doesn't work" reports that don't actually tell you anything.

The granularity is still there though — every fix is its own self-contained commit with its own explanation, so it reviews (and reverts, if needed) commit by commit just like separate PRs would.

@larena1
larena1 force-pushed the fix/seek-av-desync branch from 4f6ed61 to a16fa1a Compare August 1, 2026 19:21
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants