shaka-project / shaka-player-embedded

Shaka Player in a C++ Framework
Apache License 2.0
238 stars 63 forks source link

Audio stops playing after seek #97

Closed jgongo closed 4 years ago

jgongo commented 4 years ago

After successfully running the sample app in the simulator I browsed some of the sample assets and noticed that from time to time, after seeking backward or forward, audio would randomly stop playing (not always, but easily reproducible if you move the slider a few times).

TheModMaker commented 4 years ago

I cannot reproduce this. Can you post some logs from when it happens? Does the video still play and is the app still responsive? Does the issue resolve after another seek? Does the issue happen with any asset, which asset did you test with? Does the issue still persist with ABR disabled?

jgongo commented 4 years ago

I have moved my tests to a device (iPhone X) and the problem seems to persist. After seeking the audio stopped playing, and it was noticeable just a moment just before the video ended.

I didn't try to seek again, as I was using my own test app, I still have no controls implemented, and the seek was fired programatically with a timer.

The issue happens at least with the provided sample asset Angel One (URL included in code).

How do I disable ABR?

Here you have the code:

import UIKit
import ShakaPlayerEmbedded

class ViewController: UIViewController, ShakaPlayerClient {
    private var player: ShakaPlayerView!

    override func viewWillAppear(_ animated: Bool) {
        super.viewWillAppear(animated)

        // Make a Shaka Player view.
        player = ShakaPlayerView()
        player.setClient(self)
        player.logLevel = .V1
        player.frame = self.view.bounds
        self.view.addSubview(player)

        // Load and play an asset.
        let assetURL = "https://storage.googleapis.com/shaka-demo-assets/angel-one/dash.mpd"

        player.load(assetURL, withStartTime: 0) { error in
            if let error = error {
                NSLog("Error loading resource: \(String(describing: error.message))")
            } else {
                NSLog("Resource correctly loaded")
            }
            self.player.play()
        }
        // SEEK
        DispatchQueue.main.asyncAfter(deadline: .now() + 15) {
            self.player.currentTime = 1
        }
    }

    func onPlayerError(_ error: ShakaPlayerError!) {
        NSLog("Error while playing: %@", error.message)
    }

    func onPlayerBufferingChange(_ is_buffering: Bool) {
        NSLog("Buffering changed: \(is_buffering)")
    }

    func onPlayerPlayingEvent() {
        NSLog("Player is playing, duration: \(player.duration)")
        NSLog("Seek range: \(player.seekRange.start) -> \(player.seekRange.end)")

    }

    func onPlayerPauseEvent() {
        NSLog("Player is paused")
    }

    func onPlayerEndedEvent() {
        NSLog("Player ended")
    }

    func onPlayerSeekingEvent() {
        NSLog("Player seeking started")
    }

    func onPlayerSeekedEvent() {
        NSLog("Player seeking ended")
    }
}
Here you have the resulting log: ``` [Info]: "Starting attach..." [Info]: "Starting load of https://storage.googleapis.com/shaka-demo-assets/angel-one/dash.mpd..." WARNING: Logging before InitGoogleLogging() is written to STDERR E0127 12:27:55.496978 1866018816 hardware_support.cc:232] Unable to query support for codec: vp09.00.20.08.00.02.02.02.00 [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.20.08.00.02.02.02.00 bandwidth=333746 frameRate=25 width=320 height=240" E0127 12:27:55.497673 1866018816 hardware_support.cc:232] Unable to query support for codec: vp09.00.30.08.00.02.02.02.00 [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=1100994 frameRate=25 width=768 height=576" E0127 12:27:55.497956 1866018816 hardware_support.cc:232] Unable to query support for codec: vp09.00.10.08.00.02.02.02.00 [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.10.08.00.02.02.02.00 bandwidth=114126 frameRate=25 width=192 height=144" E0127 12:27:55.498248 1866018816 hardware_support.cc:232] Unable to query support for codec: vp09.00.21.08.00.02.02.02.00 [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.21.08.00.02.02.02.00 bandwidth=612642 frameRate=25 width=480 height=360" E0127 12:27:55.498525 1866018816 hardware_support.cc:232] Unable to query support for codec: vp09.00.30.08.00.02.02.02.00 [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=829676 frameRate=25 width=640 height=480" E0127 12:27:55.498705 1866018816 hardware_support.cc:232] Unable to query support for codec: opus [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=97374 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=152000 channelsCount=2" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.20.08.00.02.02.02.00 bandwidth=333746 frameRate=25 width=320 height=240" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=1100994 frameRate=25 width=768 height=576" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.10.08.00.02.02.02.00 bandwidth=114126 frameRate=25 width=192 height=144" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.21.08.00.02.02.02.00 bandwidth=612642 frameRate=25 width=480 height=360" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=829676 frameRate=25 width=640 height=480" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.20.08.00.02.02.02.00 bandwidth=333746 frameRate=25 width=320 height=240" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=1100994 frameRate=25 width=768 height=576" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.10.08.00.02.02.02.00 bandwidth=114126 frameRate=25 width=192 height=144" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.21.08.00.02.02.02.00 bandwidth=612642 frameRate=25 width=480 height=360" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=829676 frameRate=25 width=640 height=480" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.20.08.00.02.02.02.00 bandwidth=333746 frameRate=25 width=320 height=240" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=1100994 frameRate=25 width=768 height=576" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.10.08.00.02.02.02.00 bandwidth=114126 frameRate=25 width=192 height=144" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.21.08.00.02.02.02.00 bandwidth=612642 frameRate=25 width=480 height=360" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=829676 frameRate=25 width=640 height=480" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.20.08.00.02.02.02.00 bandwidth=333746 frameRate=25 width=320 height=240" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=1100994 frameRate=25 width=768 height=576" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.10.08.00.02.02.02.00 bandwidth=114126 frameRate=25 width=192 height=144" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.21.08.00.02.02.02.00 bandwidth=612642 frameRate=25 width=480 height=360" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=829676 frameRate=25 width=640 height=480" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=148953 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=434667 channelsCount=6" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.20.08.00.02.02.02.00 bandwidth=333746 frameRate=25 width=320 height=240" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=1100994 frameRate=25 width=768 height=576" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.10.08.00.02.02.02.00 bandwidth=114126 frameRate=25 width=192 height=144" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.21.08.00.02.02.02.00 bandwidth=612642 frameRate=25 width=480 height=360" [Log]: "Dropping variant - video not compatible with platform" "type=video codecs=vp09.00.30.08.00.02.02.02.00 bandwidth=829676 frameRate=25 width=640 height=480" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Log]: "Dropping variant - audio not compatible with platform" "type=audio codecs=opus bandwidth=151620 channelsCount=2" [Debug]: "notifyNewSegmentDuration:" "maxSegmentDuration=1" [Log]: "Found variant with audio and video content, so filtering out audio-only content in all periods." 2020-01-27 12:27:55.533645+0100 ShakaPlayer[43235:9791105] Buffering changed: true [Log]: "codecs" "avc1-mp4a" "avg bandwidth" 3978617.2 [Log]: "onChooseStreams_" {startTime:0, textStreams:[...], variants:[...]} [Log]: "Choosing new streams after period changed" [Debug]: "(all) setting up Stream 14" [Debug]: "(all) setting up Stream 7" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "(all) setup Stream 14" [Debug]: "(all) setup Stream 7" [Log]: "init: completed initial Stream setup" 2020-01-27 12:27:55.786504+0100 ShakaPlayer[43235:9791105] Resource correctly loaded [Debug]: "(audio:14)" "next position unknown: nothing buffered" [Log]: "(audio:14)" "looking up segment:" "presentationTime=0" "currentPeriod.startTime=0" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=0" "currentPeriod.startTime=0" "reference.position=0" "reference.startTime=0" "reference.endTime=4.010666666666666" [Debug]: "(audio:14)" "setting timestamp offset to 0" [Debug]: "(audio:14)" "setting append window start to 0" [Debug]: "(audio:14)" "setting append window end to 60" [Debug]: "(audio:14)" "fetching init segment" [Debug]: "(video:7)" "next position unknown: nothing buffered" [Log]: "(video:7)" "looking up segment:" "presentationTime=0" "currentPeriod.startTime=0" [Debug]: "(video:7)" "fetchAndAppend_:" "presentationTime=0" "currentPeriod.startTime=0" "reference.position=0" "reference.startTime=0" "reference.endTime=4" [Debug]: "(video:7)" "setting timestamp offset to 0" [Debug]: "(video:7)" "setting append window start to 0" [Debug]: "(video:7)" "setting append window end to 60" [Debug]: "(video:7)" "fetching init segment" [Debug]: "(audio:14)" "appending init segment" I0127 12:27:55.973618 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:7)" "appending init segment" I0127 12:27:56.025997 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "appending media segment" [mov,mp4,m4a,3gp,3g2,mj2 @ 0x13a82c400] Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol I0127 12:27:56.042203 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=0" "currentPeriod.startTime=0" "reference.position=1" "reference.startTime=4.010666666666666" "reference.endTime=8" I0127 12:27:56.065570 1868886016 ffmpeg_decoder.cc:140] Reconfiguring decoder I0127 12:27:56.065641 1868886016 ffmpeg_decoder.cc:257] No hardware-accelerators available, using decoder: aac_at [Debug]: "(video:7)" "appending media segment" [mov,mp4,m4a,3gp,3g2,mj2 @ 0x13a82a400] Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol [Debug]: "(audio:14)" "appending media segment" I0127 12:27:56.270018 1866018816 source_buffer.cc:207] Finish appending media segment: success [Log]: "(video:7)" "startup complete" [Log]: "(all) setting up Period 0" [Log]: "(all) Stream 7 is being or has been set up" [Debug]: "(all) setting up Stream 5" 2020-01-27 12:27:56.274066+0100 ShakaPlayer[43235:9791105] Player is playing, duration: 60.0 [Debug]: "(all) setting up Stream 8" [Debug]: "(all) setting up Stream 9" I0127 12:27:56.276465 1868312576 ffmpeg_decoder.cc:140] Reconfiguring decoder I0127 12:27:56.276579 1868312576 ffmpeg_decoder.cc:263] Using decoder: h264, with hardware accelerator: videotoolbox [Debug]: "(all) setting up Stream 10" [Debug]: "(all) setting up Stream 11" [Debug]: "(all) setting up Stream 13" [Log]: "(all) Stream 14 is being or has been set up" [Debug]: "(all) setting up Stream 15" [Debug]: "(all) setting up Stream 16" [Debug]: "(all) setting up Stream 25" [Debug]: "(all) setting up Stream 1" [Debug]: "(all) setting up Stream 2" [Debug]: "(all) setting up Stream 3" [Debug]: "(all) setting up Stream 4" [Log]: "(all) Period 0 is being or has been set up" [Debug]: "(video:7)" "finished fetch and append" I0127 12:27:56.300227 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:7)" "fetchAndAppend_:" "presentationTime=0" "currentPeriod.startTime=0" "reference.position=1" "reference.startTime=4" "reference.endTime=8" 2020-01-27 12:27:56.311345+0100 ShakaPlayer[43235:9791105] Seek range: 0.0 -> 60.0 2020-01-27 12:27:56.314811+0100 ShakaPlayer[43235:9791105] Buffering changed: false [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=0.001" "currentPeriod.startTime=0" "reference.position=2" "reference.startTime=8" "reference.endTime=12.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "notifySegments:" "maxSegmentDuration=4.010666666666667" [Debug]: "(all) setup Stream 5" [Debug]: "(all) setup Stream 8" [Debug]: "(all) setup Stream 9" [Debug]: "(all) setup Stream 10" [Debug]: "(all) setup Stream 11" [Debug]: "(all) setup Stream 13" [Debug]: "(all) setup Stream 15" [Debug]: "(all) setup Stream 16" [Debug]: "(all) setup Stream 25" [Debug]: "(all) setup Stream 1" [Debug]: "(all) setup Stream 2" [Debug]: "(all) setup Stream 3" [Debug]: "(all) setup Stream 4" [Debug]: "(video:7)" "calling onCanSwitch()..." [Log]: "canSwitch_" [Debug]: "(all) setup Period 0" [Log]: "Calling switch_(), bandwidth=5258 kbps" [Log]: "switch_" [Log]: "switch: switching to Stream (video:11)" [Debug]: "(video:11)" "next position unknown: another Stream buffered" [Log]: "(video:11)" "looking up segment:" "presentationTime=4" "currentPeriod.startTime=0" [Info]: "Aborting current segment request to switch." [Log]: "switch: Stream (audio:14) already active" [Debug]: "(video:11)" "next position unknown: another Stream buffered" [Log]: "(video:11)" "looking up segment:" "presentationTime=4" "currentPeriod.startTime=0" [Debug]: "(video:11)" "fetchAndAppend_:" "presentationTime=0.24700000000000008" "currentPeriod.startTime=0" "reference.position=1" "reference.startTime=4" "reference.endTime=8" [Debug]: "(video:11)" "setting timestamp offset to 0" [Debug]: "(video:11)" "setting append window start to 0" [Debug]: "(video:11)" "setting append window end to 60" [Debug]: "(video:11)" "fetching init segment" [Debug]: "(audio:14)" "appending media segment" I0127 12:27:56.589624 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:11)" "appending init segment" [mov,mp4,m4a,3gp,3g2,mj2 @ 0x13a82a400] Found duplicated MOOV Atom. Stopping. I0127 12:27:56.741262 1874620416 ffmpeg_demuxer.cc:247] Reinitializing demuxer I0127 12:27:56.742231 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:11)" "appending media segment" [mov,mp4,m4a,3gp,3g2,mj2 @ 0x13a006000] Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol I0127 12:27:56.977247 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:11)" "finished fetch and append" [Debug]: "(video:11)" "fetchAndAppend_:" "presentationTime=0.6690000000000004" "currentPeriod.startTime=0" "reference.position=2" "reference.startTime=8" "reference.endTime=12" [Debug]: "(video:11)" "appending media segment" I0127 12:27:57.336117 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:11)" "finished fetch and append" [Debug]: "(video:11)" "fetchAndAppend_:" "presentationTime=2.036999999999995" "currentPeriod.startTime=0" "reference.position=3" "reference.startTime=12" "reference.endTime=16" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=2.294999999999994" "currentPeriod.startTime=0" "reference.position=3" "reference.startTime=12.010666666666667" "reference.endTime=16" [Debug]: "(video:11)" "appending media segment" I0127 12:27:58.651232 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:11)" "finished fetch and append" [Debug]: "(audio:14)" "appending media segment" I0127 12:27:58.857165 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" I0127 12:27:59.095813 1868312576 ffmpeg_decoder.cc:140] Reconfiguring decoder I0127 12:27:59.097635 1868312576 ffmpeg_decoder.cc:263] Using decoder: h264, with hardware accelerator: videotoolbox [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=6.085999999999977" "currentPeriod.startTime=0" "reference.position=4" "reference.startTime=16" "reference.endTime=20.010666666666665" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:02.620852 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:11)" "fetchAndAppend_:" "presentationTime=6.387999999999972" "currentPeriod.startTime=0" "reference.position=4" "reference.startTime=16" "reference.endTime=20" [Debug]: "(video:11)" "appending media segment" I0127 12:28:02.903017 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:11)" "finished fetch and append" [Debug]: "(video:11)" "fetchAndAppend_:" "presentationTime=10.13999999999993" "currentPeriod.startTime=0" "reference.position=5" "reference.startTime=20" "reference.endTime=24" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=10.355999999999923" "currentPeriod.startTime=0" "reference.position=5" "reference.startTime=20.010666666666665" "reference.endTime=24" [Log]: "Calling switch_(), bandwidth=11200 kbps" [Log]: "switch_" [Log]: "switch: switching to Stream (video:9)" [Debug]: "(video:9)" "next position unknown: another Stream buffered" [Log]: "(video:9)" "looking up segment:" "presentationTime=20" "currentPeriod.startTime=0" [Info]: "Aborting current segment request to switch." [Log]: "switch: Stream (audio:14) already active" [Debug]: "(video:9)" "next position unknown: another Stream buffered" [Log]: "(video:9)" "looking up segment:" "presentationTime=20" "currentPeriod.startTime=0" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=10.379999999999923" "currentPeriod.startTime=0" "reference.position=5" "reference.startTime=20" "reference.endTime=24" [Debug]: "(video:9)" "setting timestamp offset to 0" [Debug]: "(video:9)" "setting append window start to 0" [Debug]: "(video:9)" "setting append window end to 60" [Debug]: "(video:9)" "fetching init segment" [Debug]: "(video:9)" "appending init segment" [mov,mp4,m4a,3gp,3g2,mj2 @ 0x13a006000] Found duplicated MOOV Atom. Stopping. I0127 12:28:06.902441 1874620416 ffmpeg_demuxer.cc:247] Reinitializing demuxer [Debug]: "(audio:14)" "appending media segment" I0127 12:28:06.904119 1866018816 source_buffer.cc:207] Finish appending media segment: success I0127 12:28:06.912199 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "appending media segment" [mov,mp4,m4a,3gp,3g2,mj2 @ 0x13c802000] Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol I0127 12:28:07.078052 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" 2020-01-27 12:28:09.776958+0100 ShakaPlayer[43235:9791105] Player seeking started [Debug]: "Playhead in safe region or in buffered region." [Debug]: "Seek to 1" 2020-01-27 12:28:09.779608+0100 ShakaPlayer[43235:9791105] Player is playing, duration: 60.0 [Log]: "(all): seeked: buffered seek: presentationTime=1.001" 2020-01-27 12:28:09.787630+0100 ShakaPlayer[43235:9791105] Seek range: 0.0 -> 60.0 2020-01-27 12:28:09.787801+0100 ShakaPlayer[43235:9791105] Player seeking ended I0127 12:28:09.813237 1868312576 ffmpeg_decoder.cc:140] Reconfiguring decoder I0127 12:28:09.813370 1868312576 ffmpeg_decoder.cc:263] Using decoder: h264, with hardware accelerator: videotoolbox I0127 12:28:11.550084 1868312576 ffmpeg_decoder.cc:140] Reconfiguring decoder I0127 12:28:11.552124 1868312576 ffmpeg_decoder.cc:263] Using decoder: h264, with hardware accelerator: videotoolbox [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=14.330999999999872" "currentPeriod.startTime=0" "reference.position=6" "reference.startTime=24" "reference.endTime=28.010666666666665" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=14.502999999999869" "currentPeriod.startTime=0" "reference.position=6" "reference.startTime=24" "reference.endTime=28" [Log]: "Calling switch_(), bandwidth=9657 kbps" [Log]: "switch_" [Log]: "switch: Stream (video:9) already active" [Log]: "switch: Stream (audio:14) already active" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:23.345474 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "appending media segment" I0127 12:28:23.657430 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" I0127 12:28:24.690344 1866018816 js_engine.cc:33] Begin GC run I0127 12:28:24.727952 1866018816 object_tracker.cc:143] Deleted 2659 object(s). I0127 12:28:24.731751 1866018816 js_engine.cc:44] End GC run [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=18.10999999999993" "currentPeriod.startTime=0" "reference.position=7" "reference.startTime=28.010666666666665" "reference.endTime=32" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:27.122766 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=18.427999999999937" "currentPeriod.startTime=0" "reference.position=7" "reference.startTime=28" "reference.endTime=32" I0127 12:28:27.553524 1868312576 ffmpeg_decoder.cc:140] Reconfiguring decoder I0127 12:28:27.554138 1868312576 ffmpeg_decoder.cc:263] Using decoder: h264, with hardware accelerator: videotoolbox [Debug]: "(video:9)" "appending media segment" I0127 12:28:27.729815 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=22.39200000000003" "currentPeriod.startTime=0" "reference.position=8" "reference.startTime=32" "reference.endTime=36.010666666666665" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=22.496000000000038" "currentPeriod.startTime=0" "reference.position=8" "reference.startTime=32" "reference.endTime=36" [Log]: "Calling switch_(), bandwidth=12814 kbps" [Log]: "switch_" [Log]: "switch: Stream (video:9) already active" [Log]: "switch: Stream (audio:14) already active" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:31.390147 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "appending media segment" I0127 12:28:31.640466 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=26.153000000000095" "currentPeriod.startTime=0" "reference.position=9" "reference.startTime=36.010666666666665" "reference.endTime=40" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=26.407000000000103" "currentPeriod.startTime=0" "reference.position=9" "reference.startTime=36" "reference.endTime=40" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:35.306813 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "appending media segment" I0127 12:28:35.751665 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=30.01200000000016" "currentPeriod.startTime=0" "reference.position=10" "reference.startTime=40" "reference.endTime=44" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=30.07400000000016" "currentPeriod.startTime=0" "reference.position=10" "reference.startTime=40" "reference.endTime=44.010666666666665" [Log]: "Calling switch_(), bandwidth=15164 kbps" [Log]: "switch_" [Log]: "switch: Stream (video:9) already active" [Log]: "switch: Stream (audio:14) already active" [Debug]: "(audio:14)" "buffer behind too large:" "presentationTime=30.07400000000016" "bufferedBehind=30.07400000000016" "bufferBehind=30" "overflow=0.07400000000016149" [Debug]: "(audio:14)" "evicted 0.07400000000016149 seconds" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:39.596241 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "buffer behind too large:" "presentationTime=30.01200000000016" "bufferedBehind=30.01200000000016" "bufferBehind=30" "overflow=0.012000000000160327" [Debug]: "(video:9)" "evicted 0.012000000000160327 seconds" [Debug]: "(video:9)" "appending media segment" I0127 12:28:39.670994 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=34.36200000000046" "currentPeriod.startTime=0" "reference.position=11" "reference.startTime=44.010666666666665" "reference.endTime=48" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=34.43800000000046" "currentPeriod.startTime=0" "reference.position=11" "reference.startTime=44" "reference.endTime=48" [Debug]: "(audio:14)" "buffer behind too large:" "presentationTime=34.36200000000046" "bufferedBehind=34.276666666667126" "bufferBehind=30" "overflow=4.276666666667126" [Debug]: "(audio:14)" "evicted 4.276666666667126 seconds" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:43.451557 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "buffer behind too large:" "presentationTime=34.43800000000046" "bufferedBehind=30.438000000000457" "bufferBehind=30" "overflow=0.43800000000045713" [Debug]: "(video:9)" "evicted 0.43800000000045713 seconds" [Debug]: "(video:9)" "appending media segment" I0127 12:28:43.578786 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=38.21700000000086" "currentPeriod.startTime=0" "reference.position=12" "reference.startTime=48" "reference.endTime=52.010666666666665" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=38.345000000000844" "currentPeriod.startTime=0" "reference.position=12" "reference.startTime=48" "reference.endTime=52" [Debug]: "(audio:14)" "buffer behind too large:" "presentationTime=38.21700000000086" "bufferedBehind=33.843666666667524" "bufferBehind=30" "overflow=3.8436666666675237" [Debug]: "(audio:14)" "evicted 3.8436666666675237 seconds" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:47.534425 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Log]: "Calling switch_(), bandwidth=16105 kbps" [Log]: "switch_" [Log]: "switch: Stream (video:9) already active" [Log]: "switch: Stream (audio:14) already active" [Debug]: "(video:9)" "buffer behind too large:" "presentationTime=38.345000000000844" "bufferedBehind=30.345000000000844" "bufferBehind=30" "overflow=0.3450000000008444" [Debug]: "(video:9)" "evicted 0.3450000000008444 seconds" [Debug]: "(video:9)" "appending media segment" I0127 12:28:47.552449 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=42.31100000000112" "currentPeriod.startTime=0" "reference.position=13" "reference.startTime=52.010666666666665" "reference.endTime=56" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=42.32700000000113" "currentPeriod.startTime=0" "reference.position=13" "reference.startTime=52" "reference.endTime=56" [Debug]: "(audio:14)" "buffer behind too large:" "presentationTime=42.31100000000112" "bufferedBehind=34.07633333333446" "bufferBehind=30" "overflow=4.0763333333344605" [Debug]: "(audio:14)" "evicted 4.0763333333344605 seconds" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:51.364902 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Debug]: "(video:9)" "buffer behind too large:" "presentationTime=42.32700000000113" "bufferedBehind=30.327000000001128" "bufferBehind=30" "overflow=0.32700000000112794" [Debug]: "(video:9)" "evicted 0.32700000000112794 seconds" [Debug]: "(video:9)" "appending media segment" I0127 12:28:51.718995 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" I0127 12:28:54.690865 1866018816 js_engine.cc:33] Begin GC run I0127 12:28:54.725683 1866018816 object_tracker.cc:143] Deleted 1828 object(s). I0127 12:28:54.731643 1866018816 js_engine.cc:44] End GC run [Debug]: "(audio:14)" "fetchAndAppend_:" "presentationTime=46.125000000001336" "currentPeriod.startTime=0" "reference.position=14" "reference.startTime=56" "reference.endTime=60" [Debug]: "(audio:14)" "buffer behind too large:" "presentationTime=46.125000000001336" "bufferedBehind=33.79433333333467" "bufferBehind=30" "overflow=3.79433333333467" [Debug]: "(audio:14)" "evicted 3.79433333333467 seconds" [Debug]: "(audio:14)" "appending media segment" I0127 12:28:55.186106 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(audio:14)" "finished fetch and append" [Log]: "(audio:14)" "buffered to end of presentation" [Debug]: "(video:9)" "fetchAndAppend_:" "presentationTime=46.48000000000134" "currentPeriod.startTime=0" "reference.position=14" "reference.startTime=56" "reference.endTime=60" [Log]: "Calling switch_(), bandwidth=14875 kbps" [Log]: "switch_" [Log]: "switch: Stream (video:9) already active" [Log]: "switch: Stream (audio:14) already active" [Debug]: "(video:9)" "buffer behind too large:" "presentationTime=46.48000000000134" "bufferedBehind=30.48000000000134" "bufferBehind=30" "overflow=0.4800000000013398" [Debug]: "(video:9)" "evicted 0.4800000000013398 seconds" [Debug]: "(video:9)" "appending media segment" I0127 12:28:55.897656 1866018816 source_buffer.cc:207] Finish appending media segment: success [Debug]: "(video:9)" "finished fetch and append" [Log]: "(video:9)" "buffered to end of presentation" [Debug]: "(video:9)" "calling endOfStream()..." I0127 12:29:08.769968 1868886016 ffmpeg_decoder.cc:140] Reconfiguring decoder I0127 12:29:08.770174 1868886016 ffmpeg_decoder.cc:257] No hardware-accelerators available, using decoder: aac_at 2020-01-27 12:29:08.783728+0100 ShakaPlayer[43235:9791105] Player ended I0127 12:29:24.690508 1866018816 js_engine.cc:33] Begin GC run I0127 12:29:24.702275 1866018816 object_tracker.cc:143] Deleted 993 object(s). I0127 12:29:24.706583 1866018816 js_engine.cc:44] End GC run ```
jgongo commented 4 years ago

Ok, I seem to have found a pattern using the sample app:

This seems to happen quite consistently with Angel One, although some times seeking again fixes it.

I've also found it to happen consistently with Sintel 4k (multi codec) or Tears of Steel (multicodec, TTML) with the following behavior:

TheModMaker commented 4 years ago

Ok, so it seems to be a problem with stream switching.

You can disable ABR the same was as with the JavaScript Shaka Player (google/shaka-player). See their tutorial and the argument documentation. You can only use the string form of configure. You would do it with:

player.configure("abr.enabled", withBool: false);
TheModMaker commented 4 years ago

I just pushed a change that fixes sometimes when the audio doesn't play. Please try again with the latest master.

jgongo commented 4 years ago

This seems to be working now. Thanks!!