PlaybackController.getBufferLevel() continually returns 0 due to inactive text track.

[riksagar]

Environment

• The MPD passes the DASH-IF Conformance Tool on https://conformance.dashif.org/
• The stream has correct Access-Control-Allow-Origin headers (CORS)
• There are no network errors such as 404s in the browser console when trying to play the stream
• The issue observed is not mentioned on https://github.com/Dash-Industry-Forum/dash.js/wiki/FAQ
• The issue occurs in the latest reference client on http://reference.dashif.org/dash.js/ and not just on my page

• Link to playable MPD file: n/a (Our MPD URLs expire)
• Dash.js version: 4.1.0
• Browser name/version: Tizen (but I don't think this affects the issue)
• OS name/version: Tizen (but I don't think this affects the issue)

Steps to reproduce

Configure DASH-JS player with text.defaultEnabled = false setting via MediaPlayer.updateSettings() API, similar to the following:

player.updateSettings({
                debug: {
                    ...
                },
                streaming: {
                    abr,
                    buffer: {
                        initialBufferLevel: 5,
                        ...

                    },
                    text: {
                        defaultEnabled: false
                    }
                }
            });

Provide player an MPD which contains an AdaptationSet for a text track.

Start player with autoplay

        player.initialize(playerEl, url + (startTime ? `#t=${startTime}` : ""), true /*autoplay*/);

Observed behavior

Playback does not start, as the PlaybackController.getBufferLevel() function returns zero due to the text track.

Playback has to be started by calling play() on the video element.

Console output

  13:11:53:156 [INFO]: [712][DashParser] Parsing complete: ( xml2json: 380ms, objectiron: 1.75ms, total: 0.382s) 
  13:11:53:169 [INFO]: [726][StreamController] Manifest updated... updating data system wide. 
  13:11:53:186 [INFO]: [742][ManifestUpdater] Manifest has been refreshed at Thu Jan 06 2022 13:11:53 GMT-0800 (Pacific Standard Time)[1641503513.167]  
  13:11:53:217 [INFO]: [774][StreamController] Start time from URI parameters: 1 
  13:11:53:224 [DEBUG]: [780][GapController] Starting the gap controller 
  13:11:53:231 [INFO]: [788][StreamController] Switch to stream 1. Seektime is 1, current playback time is null. Seamless period switch is set to false 
  13:11:53:243 [DEBUG]: [800][StreamController] MediaSource attached to element.  Waiting on open... 
  13:11:53:314 [feature] event: loadstart seeking: false seekable:0 paused: true played: 0 currentTime: 0 buffered:  duration: NaN
  13:11:53:315 video-player-lb-dashjs4: feature - unhandled event loadstart
  13:11:53:330 [DEBUG]: [887][StreamController] MediaSource is open! 
  13:11:53:332 [INFO]: [889][MediaSourceController] Set MediaSource duration:2506.504 
  13:11:53:374 [DEBUG]: [931][DOMStorage] Last saved bitrate for video was 17858.083 
  13:11:53:401 [INFO]: [958][Stream] No muxed data. 
  13:11:53:405 [INFO]: [962][Stream] No image data. 
  13:11:53:418 [DEBUG]: [975][SourceBufferSink][video] Updated append window for video. Set start to 0 and end to 2506.514 
  13:11:53:430 [DEBUG]: [986][SourceBufferSink][audio] Updated append window for audio. Set start to 0 and end to 2506.514 
  13:11:53:444 [DEBUG]: [1001][SourceBufferSink][text] Set MSE timestamp offset to 0 
  13:11:53:452 [INFO]: [1009][AbrController] Stream ID: 1 [video] switch from 0 to 2/5 (buffer: 0) . 
  13:11:53:456 [DEBUG]: [1013][StreamProcessor][video] Preparing quality switch for type video 
  13:11:53:463 [DEBUG]: [1020][FragmentModel][video] abort requests 
  13:11:53:501 [INFO]: [1058][PlaybackController] Requesting seek to time: 1 (internal) 
  13:11:53:508 [feature] event: durationchange seeking: false seekable:1 paused: true played: 0 currentTime: 0 buffered:  duration: 2506.504
  13:11:53:558 [DEBUG]: [1115][ScheduleController][video] Quality has changed, get init request for representationid = 3 
  13:11:53:589 [DEBUG]: [1146][ScheduleController][audio] Quality has changed, get init request for representationid = 9 
  13:11:53:670 player rendered
  13:11:53:717 [DEBUG]: [1274][BufferController][video] Append Init fragment video  with representationId: 3  and quality: 2 , data size: 1508 
  13:11:53:723 [INFO]: [1280][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_4_0_init.mp4  
  13:11:53:732 [DEBUG]: [1288][BufferController][audio] Append Init fragment audio  with representationId: 9  and quality: 0 , data size: 638 
  13:11:53:736 [INFO]: [1293][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_init.mp4  
  13:11:53:790 [DEBUG]: [1347][ProtectionController] DRM: onNeedKey 
  13:11:53:793 [DEBUG]: [1350][ProtectionController] DRM: initData: ���zpssh...����
  13:11:53:802 systemString: com.widevine.alpha
dash.all.debug.js?ebf6:55180 It is recommended that a robustness level be specified. Not specifying the robustness level could result in unexpected behavior. ...
  13:11:53:815 [INFO]: [1372][ProtectionController] DRM: KeySystem Access Granted (com.widevine.alpha)!  Selecting key system... 
  13:11:53:831 [DEBUG]: [1388][ScheduleController][video] Appended bytes for video and stream id 1 
  13:11:53:833 [INFO]: [1390][ScheduleController][video] [video] lastInitializedRepresentationInfo changed to 2 
  13:11:53:839 [DEBUG]: [1396][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:11:53:842 [INFO]: [1399][ScheduleController][audio] [audio] lastInitializedRepresentationInfo changed to 0 
  13:11:53:853 [INFO]: [1410][ScheduleController][video] Top quality video index has changed from NaN to 5 
  13:11:53:856 [DEBUG]: [1413][ScheduleController][video] Media segment needed for video and stream id 1 
  13:11:53:864 [DEBUG]: [1421][DashHandler][video] Index for time 1 is 0 
  13:11:53:870 [DEBUG]: [1427][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_4_0_1.mp4 
  13:11:53:879 [INFO]: [1436][ScheduleController][audio] Top quality audio index has changed from NaN to 0 
  13:11:53:881 [DEBUG]: [1438][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:11:53:895 [DEBUG]: [1451][DashHandler][audio] Index for time 1 is 0 
  13:11:53:900 [DEBUG]: [1456][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_1.mp4 
  13:11:54:767 [DEBUG]: [2324][ProtectionModel_21Jan2015] DRM: Session created.  SessionID = ksidFFB2EB4B 
  13:11:54:781 [INFO]: [2338][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_1.mp4  
  13:11:54:808 [INFO]: [2365][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_4_0_1.mp4  
  13:11:54:822 [feature] event: durationchange seeking: false seekable:1 paused: true played: 0 currentTime: 0 buffered:  duration: 2506.504
  13:11:54:823 [feature] event: resize seeking: false seekable:1 paused: true played: 0 currentTime: 0 buffered:  duration: 2506.504
  13:11:54:825 video-player-lb-dashjs4: feature - unhandled event resize
  13:11:54:827 [feature] event: loadedmetadata seeking: false seekable:1 paused: true played: 0 currentTime: 0 buffered:  duration: 2506.504
  13:11:54:828 video-player-lb-dashjs4: feature - unhandled event loadedmetadata
  13:11:54:829 [INFO]: [2386][PlaybackController] Native video element event: loadedmetadata 
  13:11:54:840 [DEBUG]: [2397][ProtectionController] DRM: onKeyMessage 
  13:11:54:867 [feature] event: seeking seeking: true seekable:1 paused: true played: 0 currentTime: 1 buffered: [0.036, 1.204] duration: 2506.504
  13:11:54:870 Feature state: seeking (sent to parent)
  13:11:54:877 player rendered
  13:11:54:906 [DEBUG]: [2463][BufferController][audio] Got enough buffer to start 
  13:11:54:912 [DEBUG]: [2469][BufferController][audio] Buffered range: 0 - 2.043, currentTime =  1 
  13:11:54:917 [DEBUG]: [2474][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:11:54:958 [DEBUG]: [2515][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:11:54:965 [DEBUG]: [2522][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_2.mp4 
  13:11:54:975 [DEBUG]: [2532][ProtectionController] DRM: onNeedKey 
  13:11:54:978 [DEBUG]: [2534][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:11:54:982 [DEBUG]: [2539][BufferController][video] Got enough buffer to start 
  13:11:54:987 [DEBUG]: [2544][BufferController][video] Buffered range: 0.036 - 2.038, currentTime =  1 
  13:11:54:991 [DEBUG]: [2548][ScheduleController][video] Appended bytes for video and stream id 1 
  13:11:55:054 [DEBUG]: [2611][ScheduleController][video] Media segment needed for video and stream id 1 
  13:11:55:059 [DEBUG]: [2616][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_4_0_2.mp4 
  13:11:55:085 [INFO]: [2642][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_2.mp4  
  13:11:59:002 [feature] event: stalled seeking: true seekable:1 paused: true played: 0 currentTime: 1 buffered: [0.036, 2.038] duration: 2506.504
  13:11:59:004 Feature state: stalled (sent to parent)
  13:11:59:041 [DEBUG]: [6598][BufferController][audio] Buffered range: 0 - 4.04, currentTime =  1 
  13:11:59:059 [DEBUG]: [6616][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:11:59:066 [DEBUG]: [6623][ProtectionController] DRM: key status = usable 
  13:11:59:116 [INFO]: [6673][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_4_0_2.mp4  
  13:11:59:130 [DEBUG]: [6687][ProtectionController] DRM: onNeedKey 
  13:11:59:131 [DEBUG]: [6688][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:11:59:133 [DEBUG]: [6690][BufferController][video] Buffered range: 0.036 - 4.04, currentTime =  1 
  13:11:59:137 [DEBUG]: [6694][ScheduleController][video] Appended bytes for video and stream id 1 
  13:11:59:171 [INFO]: [6728][AbrController] Stream ID: 1 [video] switch from 2 to 0/5 (buffer: 3.04) {"throughput":5183.1,"latency":1974} 
  13:11:59:179 [DEBUG]: [6736][StreamProcessor][video] Preparing quality switch for type video 
  13:11:59:188 [DEBUG]: [6745][FragmentModel][video] abort requests 
  13:11:59:231 [DEBUG]: [6787][ScheduleController][video] Quality has changed, get init request for representationid = 1 
  13:11:59:542 [DEBUG]: [7099][BufferController][video] Append Init fragment video  with representationId: 1  and quality: 0 , data size: 1505 
  13:11:59:555 [INFO]: [7112][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_1_0_init.mp4  
  13:11:59:565 [DEBUG]: [7122][ScheduleController][video] Appended bytes for video and stream id 1 
  13:11:59:578 [INFO]: [7135][ScheduleController][video] [video] lastInitializedRepresentationInfo changed to 0 
  13:11:59:596 [DEBUG]: [7153][ProtectionController] DRM: onNeedKey 
  13:11:59:598 [DEBUG]: [7155][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:11:59:600 [DEBUG]: [7157][ScheduleController][video] Media segment needed for video and stream id 1 
  13:11:59:608 [DEBUG]: [7165][DashHandler][video] Index for time 4.04 is 1 
  13:11:59:622 [DEBUG]: [7179][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_1_0_2.mp4 
  13:11:59:662 [DEBUG]: [7219][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:11:59:672 [DEBUG]: [7229][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_3.mp4 
  13:12:00:387 [INFO]: [7944][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_1_0_2.mp4  
  13:12:00:405 [DEBUG]: [7962][BufferController][video] Buffered range: 0.036 - 4.04, currentTime =  1 
  13:12:00:414 [DEBUG]: [7971][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:00:425 [DEBUG]: [7982][ProtectionController] DRM: onNeedKey 
  13:12:00:427 [DEBUG]: [7984][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:00:442 [INFO]: [7999][AbrController] Stream ID: 1 [video] switch from 0 to 1/5 (buffer: 3.04) "InsufficientBufferRule: being conservative to avoid immediate rebuffering" 
  13:12:00:453 [DEBUG]: [8010][StreamProcessor][video] Preparing quality switch for type video 
  13:12:00:462 [DEBUG]: [8019][FragmentModel][video] abort requests 
  13:12:00:515 [DEBUG]: [8072][ScheduleController][video] Quality has changed, get init request for representationid = 2 
  13:12:00:542 [INFO]: [8099][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_3.mp4  
  13:12:00:558 [DEBUG]: [8115][BufferController][video] Append Init fragment video  with representationId: 2  and quality: 1 , data size: 1507 
  13:12:00:569 [INFO]: [8126][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_3_0_init.mp4  
  13:12:00:583 [DEBUG]: [8140][BufferController][audio] Buffered range: 0 - 6.06, currentTime =  1 
  13:12:00:590 [DEBUG]: [8147][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:00:601 [DEBUG]: [8158][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:00:613 [INFO]: [8169][ScheduleController][video] [video] lastInitializedRepresentationInfo changed to 1 
  13:12:00:623 [DEBUG]: [8180][ProtectionController] DRM: onNeedKey 
  13:12:00:624 [DEBUG]: [8181][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:00:641 [DEBUG]: [8198][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:00:652 [DEBUG]: [8209][DashHandler][video] Index for time 4.04 is 1 
  13:12:00:663 [DEBUG]: [8220][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_3_0_2.mp4 
  13:12:00:970 [INFO]: [8527][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_3_0_2.mp4  
  13:12:01:009 [DEBUG]: [8566][BufferController][video] Buffered range: 0.036 - 4.04, currentTime =  1 
  13:12:01:021 [DEBUG]: [8578][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:01:032 [DEBUG]: [8588][ProtectionController] DRM: onNeedKey 
  13:12:01:033 [DEBUG]: [8590][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:01:062 [DEBUG]: [8619][SwitchHistoryRule] Switch history rule index: 1 samples: 6 drops: 1 
  13:12:01:072 [DEBUG]: [8629][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:01:086 [DEBUG]: [8643][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_3_0_3.mp4 
  13:12:01:376 [INFO]: [8933][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_3_0_3.mp4  
  13:12:01:393 [DEBUG]: [8950][ProtectionController] DRM: onNeedKey 
  13:12:01:394 [DEBUG]: [8951][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:01:397 [DEBUG]: [8954][BufferController][video] Buffered range: 0.036 - 6.042, currentTime =  1 
  13:12:01:411 [DEBUG]: [8967][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:01:451 [DEBUG]: [9008][SwitchHistoryRule] Switch history rule index: 1 samples: 7 drops: 1 
  13:12:01:469 [DEBUG]: [9026][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:01:481 [DEBUG]: [9038][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_3_0_4.mp4 
  13:12:01:650 [DEBUG]: [9207][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:01:656 [DEBUG]: [9213][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_4.mp4 
  13:12:01:686 [INFO]: [9243][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_3_0_4.mp4  
  13:12:01:723 [DEBUG]: [9280][BufferController][video] Buffered range: 0.036 - 8.044, currentTime =  1 
  13:12:01:739 [DEBUG]: [9296][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:01:766 [DEBUG]: [9322][ProtectionController] DRM: onNeedKey 
  13:12:01:768 [DEBUG]: [9325][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:01:780 [INFO]: [9337][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_4.mp4  
  13:12:01:821 [DEBUG]: [9378][SwitchHistoryRule] Switch history rule index: 1 samples: 8 drops: 1 
  13:12:01:837 [DEBUG]: [9394][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:01:852 [DEBUG]: [9409][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_3_0_5.mp4 
  13:12:01:892 [DEBUG]: [9449][BufferController][audio] Buffered range: 0 - 8.057, currentTime =  1 
  13:12:01:900 [DEBUG]: [9457][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:01:921 [DEBUG]: [9478][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:01:934 [DEBUG]: [9491][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_5.mp4 
  13:12:02:026 [INFO]: [9583][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_3_0_5.mp4  
  13:12:02:061 [INFO]: [9618][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_5.mp4  
  13:12:02:076 [DEBUG]: [9633][BufferController][video] Buffered range: 0.036 - 10.046, currentTime =  1 
  13:12:02:088 [DEBUG]: [9645][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:02:109 [DEBUG]: [9666][ProtectionController] DRM: onNeedKey 
  13:12:02:113 [DEBUG]: [9669][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:02:117 [DEBUG]: [9674][BufferController][audio] Buffered range: 0 - 10.054, currentTime =  1 
  13:12:02:128 [DEBUG]: [9685][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:02:146 [DEBUG]: [9702][SwitchHistoryRule] Switch history rule index: 1 samples: 8 drops: 1 
  13:12:02:163 [DEBUG]: [9720][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:02:179 [DEBUG]: [9736][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_3_0_6.mp4 
  13:12:02:226 [DEBUG]: [9783][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:02:236 [DEBUG]: [9793][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_6.mp4 
  13:12:02:338 [INFO]: [9895][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_3_0_6.mp4  
  13:12:02:367 [INFO]: [9924][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_6.mp4  
  13:12:02:381 [DEBUG]: [9938][BufferController][video] Buffered range: 0.036 - 12.048, currentTime =  1 
  13:12:02:403 [DEBUG]: [9959][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:02:421 [DEBUG]: [9978][ProtectionController] DRM: onNeedKey 
  13:12:02:422 [DEBUG]: [9979][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:02:427 [DEBUG]: [9984][BufferController][audio] Buffered range: 0 - 12.051, currentTime =  1 
  13:12:02:441 [DEBUG]: [9998][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:02:471 [DEBUG]: [10028][SwitchHistoryRule] Switch history rule index: 1 samples: 8 drops: 1 
  13:12:02:484 [DEBUG]: [10041][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:02:500 [DEBUG]: [10057][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_3_0_7.mp4 
  13:12:02:567 [DEBUG]: [10124][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:02:577 [DEBUG]: [10134][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_7.mp4 
  13:12:02:650 [INFO]: [10207][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_3_0_7.mp4  
  13:12:02:679 [INFO]: [10236][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_7.mp4  
  13:12:02:694 [DEBUG]: [10251][BufferController][video] Buffered range: 0.036 - 14.05, currentTime =  1 
  13:12:02:708 [DEBUG]: [10265][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:02:725 [DEBUG]: [10282][ProtectionController] DRM: onNeedKey 
  13:12:02:727 [DEBUG]: [10284][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:02:730 [DEBUG]: [10287][BufferController][audio] Buffered range: 0 - 14.071, currentTime =  1 
  13:12:02:740 [DEBUG]: [10297][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:02:788 [INFO]: [10345][AbrController] Stream ID: 1 [video] switch from 1 to 5/5 (buffer: 13.05) {"throughput":8666.1,"latency":90.25} 
  13:12:02:801 [DEBUG]: [10358][StreamProcessor][video] Preparing quality switch for type video 
  13:12:02:816 [DEBUG]: [10373][FragmentModel][video] abort requests 
  13:12:02:866 [DEBUG]: [10422][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:02:877 [DEBUG]: [10434][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_8.mp4 
  13:12:02:939 [DEBUG]: [10495][ScheduleController][video] Quality has changed, get init request for representationid = 6 
  13:12:02:978 [INFO]: [10535][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_8.mp4  
  13:12:03:015 [DEBUG]: [10572][BufferController][video] Append Init fragment video  with representationId: 6  and quality: 5 , data size: 1509 
  13:12:03:031 [INFO]: [10587][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_init.mp4  
  13:12:03:056 [DEBUG]: [10613][BufferController][audio] Buffered range: 0 - 16.068, currentTime =  1 
  13:12:03:069 [DEBUG]: [10626][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:03:091 [DEBUG]: [10648][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:03:106 [INFO]: [10662][ScheduleController][video] [video] lastInitializedRepresentationInfo changed to 5 
  13:12:03:122 [DEBUG]: [10679][ProtectionController] DRM: onNeedKey 
  13:12:03:124 [DEBUG]: [10681][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:03:126 [DEBUG]: [10683][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:03:141 [DEBUG]: [10698][DashHandler][video] Index for time 14.05 is 6 
  13:12:03:154 [DEBUG]: [10711][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_7.mp4 
  13:12:03:530 [INFO]: [11087][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_7.mp4  
  13:12:03:553 [DEBUG]: [11110][ProtectionController] DRM: onNeedKey 
  13:12:03:555 [DEBUG]: [11112][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:03:569 [DEBUG]: [11126][BufferController][video] Buffered range: 0.036 - 14.05, currentTime =  1 
  13:12:03:585 [DEBUG]: [11142][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:03:620 [DEBUG]: [11177][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:03:636 [DEBUG]: [11193][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_8.mp4 
  13:12:03:949 [INFO]: [11506][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_8.mp4  
  13:12:03:980 [DEBUG]: [11537][ProtectionController] DRM: onNeedKey 
  13:12:03:982 [DEBUG]: [11539][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:04:004 [DEBUG]: [11561][BufferController][video] Buffered range: 0.036 - 16.052, currentTime =  1 
  13:12:04:017 [DEBUG]: [11574][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:04:065 [DEBUG]: [11622][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:04:078 [DEBUG]: [11635][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_9.mp4 
  13:12:04:205 [DEBUG]: [11762][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:04:232 [DEBUG]: [11788][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_9.mp4 
  13:12:04:357 [INFO]: [11914][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_9.mp4  
  13:12:04:392 [DEBUG]: [11949][BufferController][audio] Buffered range: 0 - 18.065, currentTime =  1 
  13:12:04:408 [DEBUG]: [11964][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:04:468 [INFO]: [12025][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_9.mp4  
  13:12:04:492 [DEBUG]: [12049][ProtectionController] DRM: onNeedKey 
  13:12:04:494 [DEBUG]: [12051][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:04:507 [DEBUG]: [12064][BufferController][video] Buffered range: 0.036 - 18.054, currentTime =  1 
  13:12:04:521 [DEBUG]: [12078][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:04:536 [feature] event: suspend seeking: true seekable:1 paused: true played: 0 currentTime: 1 buffered: [0.036, 18.054] duration: 2506.504
  13:12:04:537 video-player-lb-dashjs4: feature - unhandled event suspend
  13:12:04:562 [DEBUG]: [12118][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:04:576 [DEBUG]: [12133][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_10.mp4 
  13:12:04:647 [DEBUG]: [12204][ScheduleController][audio] Quality change rendered for streamId 1 and type audio 
  13:12:04:654 [feature] event: seeked seeking: false seekable:1 paused: true played: 0 currentTime: 0.036 buffered: [0.036, 18.054] duration: 2506.504
  13:12:04:656 Feature state: seeked (sent to parent)
  13:12:04:921 player rendered
  13:12:04:944 [INFO]: [12501][PlaybackController] Native video element event: seeked 
  13:12:04:947 [feature] event: loadeddata seeking: false seekable:1 paused: true played: 0 currentTime: 0.036 buffered: [0.036, 18.054] duration: 2506.504
  13:12:04:948 video-player-lb-dashjs4: feature - unhandled event loadeddata
  13:12:04:949 [INFO]: [12506][PlaybackController] Native video element event: loadeddata 
  13:12:04:951 [feature] event: canplay seeking: false seekable:1 paused: true played: 0 currentTime: 0.036 buffered: [0.036, 18.054] duration: 2506.504
  13:12:04:952 Feature state: can play
  13:12:04:959 [feature] event: canplaythrough seeking: false seekable:1 paused: true played: 0 currentTime: 0.036 buffered: [0.036, 18.054] duration: 2506.504
  13:12:04:960 video-player-lb-dashjs4: feature - unhandled event canplaythrough
  13:12:05:019 [DEBUG]: [12576][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:05:033 [DEBUG]: [12590][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_10.mp4 
  13:12:05:074 [webapi.js] cbArr length: 1, then remove Callback!
  13:12:05:116 [INFO]: [12673][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_10.mp4  
  13:12:05:134 [DEBUG]: [12691][BufferController][audio] Buffered range: 0 - 20.062, currentTime =  0.036 
  13:12:05:148 [DEBUG]: [12705][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:05:202 [INFO]: [12758][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_10.mp4  
  13:12:05:238 [DEBUG]: [12795][ProtectionController] DRM: onNeedKey 
  13:12:05:239 [DEBUG]: [12796][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:05:252 [DEBUG]: [12809][BufferController][video] Buffered range: 0.036 - 20.056, currentTime =  0.036 
  13:12:05:273 [DEBUG]: [12830][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:05:359 [DEBUG]: [12916][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:05:374 [DEBUG]: [12930][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_11.mp4 
  13:12:05:555 [INFO]: [13112][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_11.mp4  
  13:12:05:576 [DEBUG]: [13133][ProtectionController] DRM: onNeedKey 
  13:12:05:578 [DEBUG]: [13135][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:05:588 [DEBUG]: [13145][BufferController][video] Buffered range: 0.036 - 22.058, currentTime =  0.036 
  13:12:05:606 [DEBUG]: [13163][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:05:673 [DEBUG]: [13230][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:05:685 [DEBUG]: [13242][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_12.mp4 
  13:12:05:753 [DEBUG]: [13310][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:05:766 [DEBUG]: [13323][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_11.mp4 
  13:12:05:905 [INFO]: [13458][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_12.mp4  
  13:12:05:929 [INFO]: [13486][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_11.mp4  
  13:12:06:023 [DEBUG]: [13580][BufferController][audio] Buffered range: 0 - 22.058, currentTime =  0.036 
  13:12:06:036 [DEBUG]: [13593][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:06:065 [DEBUG]: [13622][ProtectionController] DRM: onNeedKey 
  13:12:06:066 [DEBUG]: [13623][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:06:099 [DEBUG]: [13656][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:06:112 [DEBUG]: [13669][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_12.mp4 
  13:12:06:157 [DEBUG]: [13714][BufferController][video] Buffered range: 0.036 - 24.06, currentTime =  0.036 
  13:12:06:174 [DEBUG]: [13731][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:06:199 [INFO]: [13756][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_12.mp4  
  13:12:06:246 [DEBUG]: [13803][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:06:259 [DEBUG]: [13816][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_13.mp4 
  13:12:06:322 [DEBUG]: [13879][BufferController][audio] Buffered range: 0 - 24.079, currentTime =  0.036 
  13:12:06:337 [DEBUG]: [13893][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:06:389 [DEBUG]: [13946][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:06:412 [DEBUG]: [13969][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_13.mp4 
  13:12:06:559 [INFO]: [14116][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_13.mp4  
  13:12:06:592 [DEBUG]: [14149][BufferController][audio] Buffered range: 0 - 26.076, currentTime =  0.036 
  13:12:06:608 [DEBUG]: [14165][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:06:696 [INFO]: [14253][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_13.mp4  
  13:12:06:720 [DEBUG]: [14277][ProtectionController] DRM: onNeedKey 
  13:12:06:722 [DEBUG]: [14279][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:06:734 [DEBUG]: [14291][BufferController][video] Buffered range: 0.036 - 26.062, currentTime =  0.036 
  13:12:06:748 [DEBUG]: [14305][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:06:796 [DEBUG]: [14353][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:06:811 [DEBUG]: [14367][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_14.mp4 
  13:12:07:113 [INFO]: [14670][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_14.mp4  
  13:12:07:131 [DEBUG]: [14688][ProtectionController] DRM: onNeedKey 
  13:12:07:133 [DEBUG]: [14690][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:07:170 [DEBUG]: [14727][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:07:184 [DEBUG]: [14741][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_14.mp4 
  13:12:07:214 [DEBUG]: [14771][BufferController][video] Buffered range: 0.036 - 28.064, currentTime =  0.036 
  13:12:07:229 [DEBUG]: [14786][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:07:259 [DEBUG]: [14816][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:07:273 [DEBUG]: [14830][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_15.mp4 
  13:12:07:310 [INFO]: [14867][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_14.mp4  
  13:12:07:364 [DEBUG]: [14921][BufferController][audio] Buffered range: 0 - 28.072, currentTime =  0.036 
  13:12:07:379 [DEBUG]: [14936][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:07:432 [DEBUG]: [14988][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:07:446 [DEBUG]: [15003][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_15.mp4 
  13:12:07:513 [INFO]: [15070][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_15.mp4  
  13:12:07:535 [INFO]: [15092][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_15.mp4  
  13:12:07:554 [DEBUG]: [15110][ProtectionController] DRM: onNeedKey 
  13:12:07:555 [DEBUG]: [15112][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:07:558 [INFO]: [15115][AbrController] [audio] switching from throughput to buffer occupancy ABR rule (buffer: 30.033). 
  13:12:07:571 [DEBUG]: [15128][BufferController][audio] Buffered range: 0 - 30.069, currentTime =  0.036 
  13:12:07:582 [DEBUG]: [15139][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:07:601 [INFO]: [15158][AbrController] [video] switching from throughput to buffer occupancy ABR rule (buffer: 30.030). 
  13:12:07:616 [DEBUG]: [15172][BufferController][video] Buffered range: 0.036 - 30.066, currentTime =  0.036 
  13:12:07:629 [DEBUG]: [15186][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:07:679 [DEBUG]: [15236][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:07:693 [DEBUG]: [15250][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_16.mp4 
  13:12:07:865 [INFO]: [15422][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_16.mp4  
  13:12:07:885 [DEBUG]: [15442][ProtectionController] DRM: onNeedKey 
  13:12:07:887 [DEBUG]: [15444][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:07:895 [DEBUG]: [15452][BufferController][video] Buffered range: 0.036 - 32.068, currentTime =  0.036 
  13:12:07:908 [DEBUG]: [15465][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:07:956 [DEBUG]: [15513][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:07:969 [DEBUG]: [15526][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_17.mp4 
  13:12:08:122 [DEBUG]: [15678][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:08:135 [DEBUG]: [15691][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_16.mp4 
  13:12:08:200 [INFO]: [15757][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_17.mp4  
  13:12:08:224 [INFO]: [15781][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_16.mp4  
  13:12:08:245 [DEBUG]: [15802][BufferController][audio] Buffered range: 0 - 32.089, currentTime =  0.036 
  13:12:08:262 [DEBUG]: [15819][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:08:278 [DEBUG]: [15835][ProtectionController] DRM: onNeedKey 
  13:12:08:279 [DEBUG]: [15836][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:08:334 [DEBUG]: [15891][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:08:347 [DEBUG]: [15904][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_17.mp4 
  13:12:08:400 [DEBUG]: [15957][BufferController][video] Buffered range: 0.036 - 34.07, currentTime =  0.036 
  13:12:08:417 [DEBUG]: [15974][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:08:443 [INFO]: [16000][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_17.mp4  
  13:12:08:493 [DEBUG]: [16050][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:08:507 [DEBUG]: [16064][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_18.mp4 
  13:12:08:545 [DEBUG]: [16102][BufferController][audio] Buffered range: 0 - 34.086, currentTime =  0.036 
  13:12:08:561 [DEBUG]: [16118][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:08:607 [DEBUG]: [16163][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:08:619 [DEBUG]: [16176][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_18.mp4 
  13:12:08:712 [INFO]: [16269][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_18.mp4  
  13:12:08:742 [INFO]: [16299][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_18.mp4  
  13:12:08:767 [DEBUG]: [16324][BufferController][audio] Buffered range: 0 - 36.083, currentTime =  0.036 
  13:12:08:782 [DEBUG]: [16339][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:08:802 [DEBUG]: [16359][ProtectionController] DRM: onNeedKey 
  13:12:08:804 [DEBUG]: [16361][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:08:817 [DEBUG]: [16374][BufferController][video] Buffered range: 0.036 - 36.072, currentTime =  0.036 
  13:12:08:832 [DEBUG]: [16389][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:08:863 [DEBUG]: [16420][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:08:878 [DEBUG]: [16435][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_19.mp4 
  13:12:09:043 [INFO]: [16600][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_19.mp4  
  13:12:09:064 [DEBUG]: [16621][ProtectionController] DRM: onNeedKey 
  13:12:09:066 [DEBUG]: [16623][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:09:074 [DEBUG]: [16631][BufferController][video] Buffered range: 0.036 - 38.074, currentTime =  0.036 
  13:12:09:087 [DEBUG]: [16644][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:09:129 [DEBUG]: [16686][ScheduleController][video] Media segment needed for video and stream id 1 
  13:12:09:144 [DEBUG]: [16701][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://.../index_video_7_0_20.mp4 
  13:12:09:378 [DEBUG]: [16935][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:09:392 [DEBUG]: [16949][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_19.mp4 
  13:12:09:476 [INFO]: [17033][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://.../index_video_7_0_20.mp4  
  13:12:09:500 [INFO]: [17057][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_19.mp4  
  13:12:09:521 [DEBUG]: [17078][BufferController][audio] Buffered range: 0 - 38.08, currentTime =  0.036 
  13:12:09:534 [DEBUG]: [17091][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:09:548 [DEBUG]: [17105][ProtectionController] DRM: onNeedKey 
  13:12:09:550 [DEBUG]: [17106][ProtectionController] DRM: Ignoring initData because we have already seen it! 
  13:12:09:589 [DEBUG]: [17146][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:09:603 [DEBUG]: [17160][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_20.mp4 
  13:12:09:658 [DEBUG]: [17215][BufferController][video] Buffered range: 0.036 - 40.076, currentTime =  0.036 
  13:12:09:673 [DEBUG]: [17230][ScheduleController][video] Appended bytes for video and stream id 1 
  13:12:09:710 [INFO]: [17267][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_20.mp4  
  13:12:09:732 [DEBUG]: [17289][BufferController][audio] Buffered range: 0 - 40.077, currentTime =  0.036 
  13:12:09:745 [DEBUG]: [17302][ScheduleController][audio] Appended bytes for audio and stream id 1 
  13:12:09:767 [DEBUG]: [17323][ScheduleController][audio] Media segment needed for audio and stream id 1 
  13:12:09:781 [DEBUG]: [17338][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://.../index_audio_2_0_21.mp4 
  13:12:09:852 [INFO]: [17409][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://.../index_audio_2_0_21.mp4  
  13:12:09:869 [DEBUG]: [17426][BufferController][audio] Buffered range: 0 - 42.097, currentTime =  0.036 
  

Expected behavior

Playback should start once the buffer level of the active VIDEO and AUDIO tracks reaches the value in initialBufferLevel.

[riksagar]

Can be reproduced with:

• https://reference.dashif.org/dash.js/v4.2.1/samples/captioning/caption_vtt.html

Add the following to caption_vtt.html before the call to player.initialize(...) - can be done by setting breakpoint and executing via debug console:

player.updateSettings({

    streaming: {
        buffer: {
            bufferToKeep: 45,
            bufferTimeAtTopQuality:45 ,
            bufferTimeAtTopQualityLongForm: 45,
            fastSwitchEnabled: false,
            initialBufferLevel: 5,
            setStallState: true,
            stableBufferTime: 30,
        },
        text: {
            defaultEnabled: false
        }
    }
});

Using a breakpoint on line 42912 of dash.all.debug.js you can observe that playbackController.play() is not called when text tracks are disabled.

[dsilhavy]

Thanks for reporting. #3857 excludes the text StreamProcessor when comparing the initialBufferLevel against the current buffer level. @riksagar Can you confirm that #3857 solves your issue?

[riksagar]

HI Daniel,

Thanks for looking at this. I'll give it a try in the next few days. Your fix looks similar to the change I applied locally, so I think it'll be good.

FYI: What I concluded was it required both a text track in the MPD and initialBufferLevel to be non-zero to trigger this issue. Which is probably why it hadn't been seen before.

Regards,
Rik.

[dsilhavy]

Thanks, I will merge this for now and close this ticket. Please comment if you encounter any problems.