Schedule is stalling when request is abandoned by AbandonRequestsRule

Created by: chrisss404

Environment

The MPD passes the DASH-IF Conformance Tool on http://dashif.org/conformance.html
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 -> not tested

Dash.js version: 2.6.7
Browser name/version: Firefox 52

Steps to reproduce

Start a stream and let it run for some time
Provoke AbandonRequestsRule to abandon current (in progress) request
ScheduleController's onFragmentLoadingAbandoned is not invoked, therefore the schedule of the stream is not resumed

Observed behaviour

ScheduleController's schedule is not resumed after AbandonRequestsRule abandons the current (in progress) request.
FragmentLoader is not triggering the LOADING_ABANDONED event, because xhr request was already in progress, therefore xhr status was 200 instead of 0.

XMLHttpRequest status reference: https://developer.mozilla.org/en-US/docs/Web/API/XMLHttpRequest/status

var xhr = new XMLHttpRequest();
console.log('UNSENT', xhr.status);

xhr.open('GET', '/server', true);
console.log('OPENED', xhr.status);

xhr.onprogress = function () {
  console.log('LOADING', xhr.status);
};

xhr.onload = function () {
  console.log('DONE', xhr.status);
};

xhr.send(null);

/**
 * Outputs the following:
 *
 * UNSENT 0
 * OPENED 0
 * LOADING 200
 * DONE 200
 */

Console output

Note: I added an additional debug line to xhrLoader's abort function within FragmentLoader around line 118:

            abort: function (request, status) {
                if (request) {
                    if (status === 0) {
                        eventBus.trigger(Events.LOADING_ABANDONED, {request: request, mediaType: request.mediaType, sender: instance});
                    } else {
                        console.log("[FragmentLoader][", request.mediaType, "] - event LOADING_ABANDONED was not triggered, xhr status: " + status);
                    }
                }
            }

[477700] Getting the request for audio time : 495
[477700] Index for audio time 495 is 98
[477700] SegmentTemplate: 490 / 730.5
[477700] Getting the next request at index: 99, type: audio
[477700] SegmentTemplate: 495 / 730.5
[477700] ScheduleController - audio - getNextFragment - request is https://example.com/audio/en/mp4a/9/seg-100.m4s
[478400] AbrController (video) stay on 5/6 (buffer: 19.6)
[478400] Getting the request for video time : 495
[478400] Index for video time 495 is 98
[478400] SegmentTemplate: 490 / 730.5
[478400] Getting the next request at index: 99, type: video
[478400] SegmentTemplate: 495 / 730.5
[478400] ScheduleController - video - getNextFragment - request is https://example.com/video/avc1/6/seg-100.m4s
[478500] [ScheduleController][ audio ] - onFragmentLoadingCompleted
[478500] Buffered Range for type: audio : 449.700861  -  499.948843  currentTime =  475.7
[478500] [BufferController][ audio ] onAppended chunk type =  MediaSegment  and index =  99
[482500] getClearRanges for video - Remove buffer out of  459.7  -  559.7
[482500] Removing video buffer from: 0 to 459.7
[482500] getClearRanges for audio - Remove buffer out of  459.7  -  559.7
[482500] Removing audio buffer from: 0 to 459.7
[482500] [BufferController][ video ] onRemoved buffer from: 0 to 459.7
[482500] Buffered Range for type: video : 460  -  495  currentTime =  479.7
[482500] onRemoved : call updateBufferLevel
[482500] [BufferController][ audio ] onRemoved buffer from: 0 to 459.7
[482500] Buffered Range for type: audio : 459.708662  -  499.948843  currentTime =  479.7
[482500] onRemoved : call updateBufferLevel
[483000] [ScheduleController][ video ] - onFragmentLoadingCompleted
[483000] Buffered Range for type: video : 460  -  500  currentTime =  480.1
[483000] [BufferController][ video ] onAppended chunk type =  MediaSegment  and index =  99
[483000] AbrController (video) stay on 5/6 (buffer: 19.9)
[483000] Getting the request for video time : 500
[483000] Index for video time 500 is 99
[483000] SegmentTemplate: 495 / 730.5
[483000] Getting the next request at index: 100, type: video
[483000] SegmentTemplate: 500 / 730.5
[483000] ScheduleController - video - getNextFragment - request is https://example.com/video/avc1/6/seg-101.m4s
[483000] AbrController (audio) stay on 8/8 (buffer: 19.749)
[483000] Getting the request for audio time : 500
[483000] Index for audio time 500 is 99
[483000] SegmentTemplate: 495 / 730.5
[483000] Getting the next request at index: 100, type: audio
[483000] SegmentTemplate: 500 / 730.5
[483000] ScheduleController - audio - getNextFragment - request is https://example.com/audio/en/mp4a/9/seg-101.m4s
[484000] [ScheduleController][ audio ] - onFragmentLoadingCompleted
[484000] Buffered Range for type: audio : 459.708662  -  504.964353  currentTime =  481.1
[484000] [BufferController][ audio ] onAppended chunk type =  MediaSegment  and index =  100
[487700] [ScheduleController][ video ] - onFragmentLoadingCompleted
[487700] Buffered Range for type: video : 460  -  505  currentTime =  484.8
[487700] [BufferController][ video ] onAppended chunk type =  MediaSegment  and index =  100
[488000] AbrController (audio) stay on 8/8 (buffer: 19.964)
[488000] Getting the request for audio time : 505
[488000] Index for audio time 505 is 100
[488000] SegmentTemplate: 500 / 730.5
[488000] Getting the next request at index: 101, type: audio
[488000] isMediaFinished - no segment found
[488000] ScheduleController - audio - getNextFragment - request is https://example.com/audio/en/mp4a/9/seg-102.m4s
[488200] AbrController (video) stay on 5/6 (buffer: 19.7)
[488200] Getting the request for video time : 505
[488200] Index for video time 505 is 100
[488200] SegmentTemplate: 500 / 730.5
[488200] Getting the next request at index: 101, type: video
[488200] isMediaFinished - no segment found
[488200] ScheduleController - video - getNextFragment - request is https://example.com/video/avc1/6/seg-102.m4s
[489100] [ScheduleController][ audio ] - onFragmentLoadingCompleted
[489100] Buffered Range for type: audio : 459.708662  -  509.956643  currentTime =  486.3
[489100] [BufferController][ audio ] onAppended chunk type =  MediaSegment  and index =  101
[492500] getClearRanges for video - Remove buffer out of  469.7  -  569.7
[492500] Removing video buffer from: 0 to 469.7
[492500] getClearRanges for audio - Remove buffer out of  469.7  -  569.7
[492500] Removing audio buffer from: 0 to 469.7
[492500] [BufferController][ video ] onRemoved buffer from: 0 to 469.7
[492500] Buffered Range for type: video : 470  -  505  currentTime =  489.7
[492500] onRemoved : call updateBufferLevel
[492600] [BufferController][ audio ] onRemoved buffer from: 0 to 469.7
[492600] Buffered Range for type: audio : 469.716462  -  509.956643  currentTime =  489.7
[492600] onRemoved : call updateBufferLevel
[493700] [ScheduleController][ video ] - onFragmentLoadingCompleted
[493700] Buffered Range for type: video : 470  -  510  currentTime =  490.9
[493700] [BufferController][ video ] onAppended chunk type =  MediaSegment  and index =  101
[493800] AbrController (video) stay on 5/6 (buffer: 19.1)
[493800] Getting the request for video time : 510
[493800] Index for video time 510 is 101
[493800] SegmentTemplate: 505 / 730.5
[493800] Getting the next request at index: 102, type: video
[493800] SegmentTemplate: 510 / 730.5
[493800] ScheduleController - video - getNextFragment - request is https://example.com/video/avc1/6/seg-103.m4s
[494100] AbrController (audio) stay on 8/8 (buffer: 18.657)
[494200] Getting the request for audio time : 510
[494200] Index for audio time 510 is 101
[494200] SegmentTemplate: 505 / 730.5
[494200] Getting the next request at index: 102, type: audio
[494200] SegmentTemplate: 510 / 730.5
[494200] ScheduleController - audio - getNextFragment - request is https://example.com/audio/en/mp4a/9/seg-103.m4s
[495600] [ScheduleController][ audio ] - onFragmentLoadingCompleted
[495600] Buffered Range for type: audio : 469.716462  -  514.948934  currentTime =  492.8
[495600] [BufferController][ audio ] onAppended chunk type =  MediaSegment  and index =  102
[498900] AbandonRequestsRule (  video frag id 102 ) is asking to abandon and switch to quality to  4  measured bandwidth was 1382
[FragmentLoader][ video ] - event LOADING_ABANDONED was not triggered, xhr status: 200
[499000] AbrController (video) switch from 5 to 4/6 (buffer: 14.2) .
[502500] getClearRanges for video - Remove buffer out of  479.7  -  579.7
[502500] Removing video buffer from: 0 to 479.7
[502500] getClearRanges for audio - Remove buffer out of  479.7  -  579.7
[502500] Removing audio buffer from: 0 to 479.7
[502500] [BufferController][ video ] onRemoved buffer from: 0 to 479.7
[502500] Buffered Range for type: video : 480  -  510  currentTime =  499.7
[502500] onRemoved : call updateBufferLevel
[502500] [BufferController][ audio ] onRemoved buffer from: 0 to 479.7
[502500] Buffered Range for type: audio : 479.701043  -  514.948934  currentTime =  499.7
[502500] onRemoved : call updateBufferLevel
[502900] AbrController (video) switching from buffer occupancy to throughput ABR rule (buffer: 9.900).
[508000] AbrController (audio) switching from buffer occupancy to throughput ABR rule (buffer: 9.749).
[512500] getClearRanges for video - Remove buffer out of  489.7  -  589.7
[512500] Removing video buffer from: 0 to 489.7
[512500] getClearRanges for audio - Remove buffer out of  489.7  -  589.7
[512500] Removing audio buffer from: 0 to 489.7
[512500] [BufferController][ video ] onRemoved buffer from: 0 to 489.7
[512500] Buffered Range for type: video : 490  -  510  currentTime =  509.7
[512500] onRemoved : call updateBufferLevel
[512500] [ScheduleController][ video ] - Buffer is empty! Stalling!
[512500] Waiting for more buffer before starting playback for video
[512500] [BufferController][ audio ] onRemoved buffer from: 0 to 489.7
[512500] Buffered Range for type: audio : 489.708843  -  514.948934  currentTime =  509.7
[512500] onRemoved : call updateBufferLevel
[512600] Native video element event: ratechange:  0
[522500] getClearRanges for video - Remove buffer out of  489.7  -  589.7
[522500] getClearRanges for audio - Remove buffer out of  489.7  -  589.7
[532500] getClearRanges for video - Remove buffer out of  489.7  -  589.7
[532500] getClearRanges for audio - Remove buffer out of  489.7  -  589.7
[542500] getClearRanges for video - Remove buffer out of  489.7  -  589.7
[542500] getClearRanges for audio - Remove buffer out of  489.7  -  589.7

Admin message

Schedule is stalling when request is abandoned by AbandonRequestsRule

Environment

Steps to reproduce

Observed behaviour

Console output