dash.js icon indicating copy to clipboard operation
dash.js copied to clipboard

DashJS does not play very short audio files (around 50ms or less)

Open kthyer opened this issue 2 years ago • 6 comments

Environment
  • [x] The MPD passes the DASH-IF Conformance Tool on https://conformance.dashif.org/
  • [x] The stream has correct Access-Control-Allow-Origin headers (CORS)
  • [x] There are no network errors such as 404s in the browser console when trying to play the stream
  • [x] The issue observed is not mentioned on https://github.com/Dash-Industry-Forum/dash.js/wiki/FAQ
  • [N/A] 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: VeryShortAudio.mpd.zip
  • Dash.js version: 4.4.0
  • Browser name/version: Firefox 98.0.2 and Chrome 100.0.4896.75 64-bit
  • OS name/version: Ubuntu 20.0.04
Steps to reproduce
  • Make a very short .mpd file (50ms or less normally will do it)
  • Make a DashJS MediaPlayer and initialize it with the short .mpd file
  • Try to play the audio
Observed behavior
  • When I hit play on a very short audio clip (about 50ms or less), I do not hear the audio clip.
  • I do not get playback time updated or playback ended events
  • When I hit play with a native html audio element it plays no sound and stays in the playing state but the audio progress does not move at all.
Console output
web:components:ChannelPlayer DashJS Logger: +0ms
Object { message: "[29781][mediaplayer] Streaming Initialized ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +10ms
Object { message: "[29793][eventcontroller] Start Event Controller ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +6ms
Object { message: "[29798][mediaplayer] Playback Initialized ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +215ms
Object { message: "[30014][dashparser] Parsing complete: ( xml2json: 4.00ms, objectiron: 0.00ms, total: 0.00400s) ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30015][streamcontroller] Manifest updated... updating data system wide. ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +4ms
Object { message: "[30019][manifestupdater] Manifest has been refreshed at Mon May 23 2022 03:41:32 GMT-0400 (Eastern Daylight Time)[1653291692.115] ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +8ms
Object { message: "[30027][streamcontroller] Start time from URI parameters: 0 ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30028][gapcontroller] Starting the gap controller ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +2ms
Object { message: "[30030][streamcontroller] Switch to stream defaultId_0. Seektime is 0, current playback time is null. Seamless period switch is set to false ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30031][streamcontroller] MediaSource attached to element. Waiting on open... ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +5ms
Object { message: "[30036][streamcontroller] MediaSource is open! ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30037][mediasourcecontroller] Set MediaSource duration:0.092 ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +9ms
Object { message: "[30046][stream] No text data. ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +0ms
Object { message: "[30046][stream] No muxed data. ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30047][stream] No image data. ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +2ms
Object { message: "[30049][sourcebuffersink][audio] Updated append window for audio. Set start to 0 and end to 0.102 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30050][sourcebuffersink][audio] Set MSE timestamp offset to -0.09578231292517007 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30051][abrcontroller] Stream ID: defaultId_0 [audio] switch from 0 to 1/1 (buffer: 0) . ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +0ms
Object { message: "[30051][streamprocessor][audio] Preparing quality switch for type audio ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +2ms
Object { message: "[30053][fragmentmodel][audio] abort requests ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +8ms
Object { message: "[30061][schedulecontroller][audio] Quality has changed, get init request for representationid = 1 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +152ms
Object { message: "[30213][buffercontroller][audio] Append Init fragment audio with representationId: 1 and quality: 1 , data size: 740 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30214][streamprocessor][audio] OnFragmentLoadingCompleted for stream id defaultId_0 and media type audio - Url: https://localhost:3000/portal/audio/6287f2458419ea4cd2dfab31/audio_dash_rep1.mp4 ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +3ms
Object { message: "[30217][playbackcontroller] Native video element event: loadedmetadata ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +6ms
Object { message: "[30223][schedulecontroller][audio] Appended bytes for audio and stream id defaultId_0 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +2ms
Object { message: "[30225][schedulecontroller][audio] [audio] lastInitializedRepresentationInfo changed to 1 ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30226][schedulecontroller][audio] Top quality audio index has changed from NaN to 1 ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30227][schedulecontroller][audio] Media segment needed for audio and stream id defaultId_0 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30228][dashhandler][audio] Index for time 0 is 0 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30229][streamprocessor][audio] Next fragment request url for stream id defaultId_0 and media type audio is https://localhost:3000/portal/audio/6287f2458419ea4cd2dfab31/audio_dash1_rep1.m4s ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +128ms
Object { message: "[30357][streamprocessor][audio] OnFragmentLoadingCompleted for stream id defaultId_0 and media type audio - Url: https://localhost:3000/portal/audio/6287f2458419ea4cd2dfab31/audio_dash1_rep1.m4s ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +2ms
Object { message: "[30359][schedulecontroller][audio] Appended bytes for audio and stream id defaultId_0 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30360][schedulecontroller][audio] Media segment needed for audio and stream id defaultId_0 ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +2ms
Object { message: "[30361][streamprocessor][audio] Segment requesting for stream defaultId_0 has finished ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +0ms
Object { message: "[30362][stream] onBufferingCompleted - trigger STREAM_BUFFERING_COMPLETED ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30363][streamcontroller] Stream with id defaultId_0 finished buffering ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +0ms
Object { message: "[30363][streamcontroller] [onStreamBufferingCompleted] calls signalEndOfStream of mediaSourceController. ", level: 4, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +1ms
Object { message: "[30364][buffercontroller][audio] checkIfBufferingCompleted trigger BUFFERING_COMPLETED for stream id defaultId_0 and type audio ", level: 5, type: "log" }
common.js:113
web:components:ChannelPlayer DashJS Logger: +369ms
Object { message: "[30733][buffercontroller][audio] Got enough buffer to start ", level: 5, type: "log" }
common.js:113
XHRPOSThttps://localhost:3000/
Expected behavior

I expect:

  • To hear the audio clip
  • To get playback time updated and playback ended events

kthyer avatar May 23 '22 07:05 kthyer

The SourceBuffers of the MSE require a certain amount of data in the buffer before playback can be triggered. That might cause a problem here. Can you please check if your stream plays in Shaka or Bitmovin player for means of comparison.

dsilhavy avatar May 24 '22 12:05 dsilhavy

@dsilhavy I just tried Shaka and I am unable to hear the playback of the sound. For more info, the original sound is a .mp3 file that is converted into a .mpd file. I can hear the .mp3 version of the file fine so I know sound does exist.

Is there a way to lower the data threshold needed in the buffer before playback can be triggered?

kthyer avatar May 25 '22 05:05 kthyer

The minimum buffer is platform/browser specific. Although 50ms sounds like it should be enough imo. Can you provide a hosted version of the MPD + content?

Please also check if there is data in the buffer:

var vid = document.querySelector('video')
vid.buffered.start(0)
vid.buffered.end(0)

Should output something like this:

var vid = document.querySelector('video')
undefined
vid.buffered
TimeRanges {length: 1}
vid.buffered.start(0)
0
vid.buffered.end(0)
63.999999

dsilhavy avatar May 26 '22 11:05 dsilhavy

The block length of mp3 is ~26 ms @44.1 kHz, so this is only two frames of mp3 at best. Once you take the overlap-add into account, there would be only 26 ms of usable data in these two frames. If the system tries any kind of delay compensation by, e.g., dropping samples in the beginning, you are left with nothing. I can't say this is happening for sure, but 50 ms are awfully short.

wschidol avatar May 27 '22 08:05 wschidol

@dsilhavy This is an audio only element but I think your steps should still apply.

When I did

var audio = document.querySelector('audio');
audio.buffered.start(0);
audio.buffered.end(0);

I get

TimeRanges { length: 0 }

with errors for the start function: `Uncaught DOMException: Failed to execute 'start' on 'TimeRanges': The index provided (0) is greater than or equal to the maximum bound (0).

For other longer audio clips I do get output similar to yours. For example.

TimeRanges { length: 1 }
0
2.020136

I am using Firefox 98.0.2 and Chrome 100.0.4896.75 on Ubuntu 20.04.4.

Does my output indicate it as completely unusable in this case?

Thanks for your time and help on this

kthyer avatar May 30 '22 22:05 kthyer

Ok then there is no usable audio data in the SourceBuffer. That explains why the playback does not start. I can see that your MPD has a presentationTimeOffset. You might want to check the media timestamp of your first audio sample to see if it matches the presentationTimeOffset. For an initial test try to set the presentationTimeOffset in your MPD to 0 and check if it changes anything.

dsilhavy avatar Jun 01 '22 13:06 dsilhavy

This issue has been automatically marked as stale because it has not had recent activity. However, it might still be relevant so please leave a short comment if it should remain open. Otherwise the issue will be closed automatically after two weeks. Thank you for your contributions.

stale[bot] avatar Oct 29 '22 15:10 stale[bot]

This issue has been automatically closed because no further activity occurred. If you think this issue is still relevant please reopen it or contact @dsilhavy. Thank you for your contributions.

stale[bot] avatar Nov 12 '22 17:11 stale[bot]