EventStream events gets dispatched multiple times

[bwallberg]

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: https://demo.unified-streaming.com/k8s/live/scte35.isml/.mpd
• Dash.js version: 4.4.0
• Browser name/version: Chrome 103
• OS name/version: macOS 12.3.1

Steps to reproduce

1. Open https://reference.dashif.org/dash.js/latest/samples/dash-if-reference-player/index.html?mpd=https%3A%2F%2Fdemo.unified-streaming.com%2Fk8s%2Flive%2Fscte35.isml%2F.mpd+&debug.logLevel=5&streaming.delay.liveDelayFragmentCount=NaN&streaming.delay.liveDelay=NaN&streaming.buffer.initialBufferLevel=NaN&streaming.liveCatchup.maxDrift=NaN&streaming.liveCatchup.playbackRate=NaN
2. Load the asset and filter For Received event

Observed behavior

For every mpd refresh the Received event event is triggered ( this is also true for Starting event )

Console output

Received event logs

Debug.js:169 [269518][TimeSyncController] Completed UTC sync. Setting client - server offset to -553.5 
Debug.js:169 [269518][EventController] Added inline event with id 43578 
Debug.js:169 [269518][EventController] Received event 43578 
Debug.js:169 [269518][EventController] Added inline event with id 43579 
Debug.js:169 [269518][EventController] Received event 43579 
Debug.js:169 [269518][EventController] Added inline event with id 43580 
Debug.js:169 [269518][EventController] Received event 43580 
Debug.js:169 [269518][EventController] Added inline event with id 43581 
Debug.js:169 [269518][EventController] Received event 43581 
Debug.js:169 [269518][EventController] Added inline event with id 43582 
Debug.js:169 [269518][EventController] Received event 43582 
Debug.js:169 [269518][EventController] Updated inline event with id 43583 
Debug.js:169 [269523][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [269523][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-video=1000000-993951472896.dash 
Debug.js:169 [269567][EventController] Deleting event 43578 as it is expired or invalid 
Debug.js:169 [269568][EventController] Deleting event 43579 as it is expired or invalid 
Debug.js:169 [269568][EventController] Deleting event 43580 as it is expired or invalid 
Debug.js:169 [269568][EventController] Deleting event 43581 as it is expired or invalid 
Debug.js:169 [269568][EventController] Deleting event 43582 as it is expired or invalid 
Debug.js:169 [269649][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-video=1000000-993951472896.dash  
Debug.js:169 [269650][BufferController][video] Buffered range: 1656585765.12 - 1656585790.08, currentTime =  1656585785.848331 
Debug.js:169 [269650][ScheduleController][video] Appended bytes for video and stream id 1 
Debug.js:169 [269652][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [269652][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-video=1000000-993951474048.dash 
Debug.js:169 [269703][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-video=1000000-993951474048.dash  
Debug.js:169 [269703][BufferController][video] Buffered range: 1656585765.12 - 1656585792, currentTime =  1656585785.902389 
Debug.js:169 [269704][ScheduleController][video] Appended bytes for video and stream id 1 
Debug.js:169 [269705][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [269705][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [269907][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [269907][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-audio_eng=128000-79516117831680.dash 
Debug.js:169 [269957][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-audio_eng=128000-79516117831680.dash  
Debug.js:169 [269958][BufferController][audio] Buffered range: 1656585763.413333 - 1656585790.079999, currentTime =  1656585786.15723 
Debug.js:169 [269958][ScheduleController][audio] Appended bytes for audio and stream id 1 
Debug.js:169 [269959][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [269960][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-audio_eng=128000-79516117923840.dash 
Debug.js:169 [270000][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-audio_eng=128000-79516117923840.dash  
Debug.js:169 [270001][BufferController][audio] Buffered range: 1656585763.413333 - 1656585791.999999, currentTime =  1656585786.199263 
Debug.js:169 [270001][ScheduleController][audio] Appended bytes for audio and stream id 1 
Debug.js:169 [270002][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [270002][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [270206][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [270206][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [270511][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [270512][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [270707][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [270707][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [271013][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [271013][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [271207][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [271207][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [271513][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [271513][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [271546][DashParser] Parsing complete: ( xml2json: 1.20ms, objectiron: 0.100ms, total: 0.00130s) 
Debug.js:169 [271546][StreamController] Manifest updated... updating data system wide. 
Debug.js:169 [271546][StreamController] Matching default timing source protocol to manifest protocol:  https://time.akamai.com/?iso&ms 
Debug.js:169 [271547][ManifestUpdater] Manifest has been refreshed at Thu Jun 30 2022 12:43:16 GMT+0200 (Central European Summer Time)[1656585796.585]  
Debug.js:169 [271547][ManifestUpdater] Refresh manifest in 2000 milliseconds. 
Debug.js:169 [271547][EventController] Added inline event with id 43578 
Debug.js:169 [271547][EventController] Received event 43578 
Debug.js:169 [271547][EventController] Added inline event with id 43579 
Debug.js:169 [271547][EventController] Received event 43579 
Debug.js:169 [271547][EventController] Added inline event with id 43580 
Debug.js:169 [271547][EventController] Received event 43580 
Debug.js:169 [271548][EventController] Added inline event with id 43581 
Debug.js:169 [271548][EventController] Received event 43581 
Debug.js:169 [271548][EventController] Added inline event with id 43582 
Debug.js:169 [271548][EventController] Received event 43582 
Debug.js:169 [271548][EventController] Updated inline event with id 43583 
Debug.js:169 [271668][EventController] Deleting event 43578 as it is expired or invalid 
Debug.js:169 [271668][EventController] Deleting event 43579 as it is expired or invalid 
Debug.js:169 [271668][EventController] Deleting event 43580 as it is expired or invalid 
Debug.js:169 [271668][EventController] Deleting event 43581 as it is expired or invalid 
Debug.js:169 [271668][EventController] Deleting event 43582 as it is expired or invalid 
Debug.js:169 [271710][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [271710][StreamProcessor][video] Next fragment request url for stream id 1 and media type video is https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-video=1000000-993951475200.dash 
Debug.js:169 [271838][StreamProcessor][video] OnFragmentLoadingCompleted for stream id 1 and media type video - Url: https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-video=1000000-993951475200.dash  
Debug.js:169 [271839][BufferController][video] Buffered range: 1656585765.12 - 1656585793.92, currentTime =  1656585788.037702 
Debug.js:169 [271839][ScheduleController][video] Appended bytes for video and stream id 1 
Debug.js:169 [271841][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [271841][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [271968][EventController] Starting event 43583 at 1656585788.166745 
Debug.js:169 [272017][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [272017][StreamProcessor][audio] Next fragment request url for stream id 1 and media type audio is https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-audio_eng=128000-79516118016000.dash 
Debug.js:169 [272065][StreamProcessor][audio] OnFragmentLoadingCompleted for stream id 1 and media type audio - Url: https://demo.unified-streaming.com/k8s/live/scte35.isml/dash/scte35-audio_eng=128000-79516118016000.dash  
Debug.js:169 [272066][BufferController][audio] Buffered range: 1656585763.413333 - 1656585793.919999, currentTime =  1656585788.264287 
Debug.js:169 [272066][ScheduleController][audio] Appended bytes for audio and stream id 1 
Debug.js:169 [272067][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [272067][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [272342][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [272342][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [272569][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [272569][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [272844][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [272845][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [273070][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [273070][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [273347][ScheduleController][video] Media segment needed for video and stream id 1 
Debug.js:169 [273348][DashHandler][video] video No segment found at index: 157. Wait for next loop 
Debug.js:169 [273572][ScheduleController][audio] Media segment needed for audio and stream id 1 
Debug.js:169 [273572][DashHandler][audio] audio No segment found at index: 157. Wait for next loop 
Debug.js:169 [273587][DashParser] Parsing complete: ( xml2json: 2.10ms, objectiron: 0.00ms, total: 0.00210s) 
Debug.js:169 [273587][StreamController] Manifest updated... updating data system wide. 
Debug.js:169 [273587][StreamController] Matching default timing source protocol to manifest protocol:  https://time.akamai.com/?iso&ms 
Debug.js:169 [273588][ManifestUpdater] Manifest has been refreshed at Thu Jun 30 2022 12:43:18 GMT+0200 (Central European Summer Time)[1656585798.626]  
Debug.js:169 [273588][ManifestUpdater] Refresh manifest in 2000 milliseconds. 
Debug.js:169 [273594][TimeSyncController] Increasing timeBetweenSyncAttempts to 8 
Debug.js:169 [273594][TimeSyncController] Completed UTC sync. Setting client - server offset to -630 
Debug.js:169 [273594][EventController] Added inline event with id 43578 
Debug.js:169 [273594][EventController] Received event 43578 
Debug.js:169 [273594][EventController] Added inline event with id 43579 
Debug.js:169 [273594][EventController] Received event 43579 
Debug.js:169 [273594][EventController] Added inline event with id 43580 
Debug.js:169 [273594][EventController] Received event 43580 
Debug.js:169 [273594][EventController] Added inline event with id 43581 
Debug.js:169 [273595][EventController] Received event 43581 
Debug.js:169 [273595][EventController] Added inline event with id 43582 
Debug.js:169 [273595][EventController] Received event 43582 
Debug.js:169 [273595][EventController] Added inline event with id 43583 
Debug.js:169 [273595][EventController] Received event 43583 
Debug.js:169 [273622][EventController] Deleting event 43578 as it is expired or invalid 
Debug.js:169 [273622][EventController] Deleting event 43579 as it is expired or invalid 
Debug.js:169 [273622][EventController] Deleting event 43580 as it is expired or invalid 
Debug.js:169 [273622][EventController] Deleting event 43581 as it is expired or invalid 
Debug.js:169 [273622][EventController] Deleting event 43582 as it is expired or invalid 
Debug.js:169 [273622][EventController] Starting event 43583 at 1656585789.821055 

Expected behavior

For each unique Event there should be one receive and start event.

[dsilhavy]

@bwallberg Thanks for pointing this out. Can you please check and confirm that #3980 solves this issue

[bwallberg]

I can confirm that the issue seems resolved :)