1151760 - [RTSP] Playback jumps to the end-of-stream after playing 34 seconds

Status: RESOLVED FIXED

(Firefox OS Graveyard :: RIL, defect)

Description

[Ethan Tseng [:ethan]]

This bug is found while debugging bug 1146251.

Reproduction Steps:
1. Open this web page in browser app.
   http://60.12.220.48/test/test.html
2. Click the clip "long_1.mp4".
3. Wait for 34~35 seconds, the playback suddenly jumps to the end and stops.

Expected Result:
The player can play the video as normal as other clips.

Additional Comment:
1. Codec Information
   Video Codec: H264 - MPEG-4 AVC (part 10) (h264)
   Video Resolution: 512x288
   Video Frame Rate: 15
   Video Decoded format: Planar 4:2:0 YUV
   Audio Codec: MPEG AAC Audio (mp4a)
   Audio Sample rate: 44100 Hz
   Audio AAC extension: SBR

2. VLC player desktop and Android phone both can play this RTSP clip normally.
   Benjamin guesses our RTSP stack encounters some kind of decode error
   while dealing with this clip.

3. VLC player shows there are totally four tracks in this RTSP clip.
   Two video tracks and two audio tracks.

Comment 1

[Ethan Tseng [:ethan]]

Jonathan, please help to investigate this bug.

Comment 2

[Ethan Tseng [:ethan]]

Attachment: Codec information

Comment 3

[Jonathan Hao (inactive) [:jhao]]

Currently, we check whether there are any new access units received every 2 seconds.
Maybe it's the server's problem; this stream lags for a couple of seconds at the 34 second point.
This lagging can also be observed on Android or VLC desktop.
No access units are received in these seconds and cause the player to jump to end-of-stream.

That check was originally done every 10 seconds, and was used to check network connection.
When it was used as end-of-stream criteria, the timeout was reduced to 2 seconds.
Benjamin, Ethan and I think we should separate this check from the end-of-stream criteria.

We can write another timer with 2-second timeout, and only initiates it when the stream is closed to the end of duration.

Comment 4

[Jonathan Hao (inactive) [:jhao]]

If we look at the timestamps of received access units, we would find there's always about 1.5 seconds missing at around 34 seconds.

Comment 5

[Jonathan Hao (inactive) [:jhao]]

Attachment: Separate timer of access unit timeout and end-of-stream detection.

This patch add a timer for end-of-stream detection, and increase original timer to 10 seconds to avoid false timeout.

I cannot test some use cases because of bug 1145052. I'll do more tests after that bug is fixed, and then I'll ask for Ethan's review.

Comment 6

[Ethan Tseng [:ethan]]

Comment on attachment 8591582 [details] [diff] [review]
Separate timer of access unit timeout and end-of-stream detection.

Review of attachment 8591582 [details] [diff] [review]:
-----------------------------------------------------------------

It's a good thing to separate these two timers.
Thanks for your patch! I'll review it thoroughly when you're ready. :)

::: netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h
@@ +51,5 @@
> +static int64_t kAccessUnitTimeoutUs = 10000000ll;
> +
> +// If no access units are received within the final 2 secs of duration,
> +// assume that the rtp stream has ended and signal end of stream.
> +static int64_t kEndOfStreamUs = 2000000ll;

s/kEndOfStreamUs/kEndOfStreamTimeoutUs/

Comment 7

[Jonathan Hao (inactive) [:jhao]]

Attachment: Separate timer of access unit timeout and end-of-stream detection.

Hi Ethan, this patch is ready.
I've tested "seeking to near the end" based on bug 1145052's patch and there are no problems.

Comment 8

[Ethan Tseng [:ethan]]

Comment on attachment 8595836 [details] [diff] [review]
Separate timer of access unit timeout and end-of-stream detection.

Review of attachment 8595836 [details] [diff] [review]:
-----------------------------------------------------------------

The patch looks good overall.
But I have a question and a minor suggestion. Feedback+.

::: netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h
@@ +965,5 @@
> +                    // This is an outdated message. Ignore.
> +                    break;
> +                }
> +
> +                if (mNumAccessUnitsReceived == 0) {

Is there a reason to remove this code fragment?

/* missing code fragment */
if (gIOService->IsOffline()) {	
    sp<AMessage> reply = new AMessage(kWhatDisconnected, id());	
    reply->setInt32("result", ERROR_CONNECTION_LOST);	
    mConn->disconnect(reply);	
    break;	
}
/* end of missing code */

@@ +1082,5 @@
>                  }
>  
>                  onAccessUnitComplete(trackIndex, accessUnit);
> +
> +                // put this code here because now accessUnit has timestamp

nit: Capitalize the first letter.

@@ +1087,5 @@
> +                track->mNumAccessUnitsReceiveds++;
> +                int64_t duration, timeUs;
> +                mSessionDesc->getDurationUs(&duration);
> +                accessUnit->meta()->findInt64("timeUs", &timeUs);
> +                // we only check end-of-stream in the last 10 seconds.

nit: Capitalize the first letter.

@@ +1090,5 @@
> +                accessUnit->meta()->findInt64("timeUs", &timeUs);
> +                // we only check end-of-stream in the last 10 seconds.
> +                if (timeUs >= duration - 10) {
> +                    postEndOfStreamCheck(trackIndex);
> +                }

Also name a constant for this.
Do not use magic number.

Comment 9

[Jonathan Hao (inactive) [:jhao]]

Attachment: Separate timer of access unit timeout and end-of-stream detection.

Hi Ethan, please review again. Thanks.

Comment 10

[Jonathan Hao (inactive) [:jhao]]

(In reply to Ethan Tseng [:ethan] from comment #8)
> Is there a reason to remove this code fragment?
> 
> /* missing code fragment */
> if (gIOService->IsOffline()) {	
>     sp<AMessage> reply = new AMessage(kWhatDisconnected, id());	
>     reply->setInt32("result", ERROR_CONNECTION_LOST);	
>     mConn->disconnect(reply);	
>     break;	
> }
> /* end of missing code */

I thought we had the mechanism to detect network disconnection, so we didn't need that code.
But now, on second thoughts, I think it's still useful because the network may disconnect right in the last 2 second range.
In the new patch, I keep that code but use disconnect() instead, because it will go to kWhatAbort and do the cleanup and send TEARDOWN.

I also revised the comment, and change the constant to 2 seconds. I think mistreating disconnection as end-of-stream in the last 2 seconds wouldn't harm user experience too much.

Comment 11

[Ethan Tseng [:ethan]]

Comment on attachment 8596495 [details] [diff] [review]
Separate timer of access unit timeout and end-of-stream detection.

Review of attachment 8596495 [details] [diff] [review]:
-----------------------------------------------------------------

Thanks for the patch! Looks good to me.
I just have a minor suggestion on naming, but you could choose to apply it or not on your own. :)

::: netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h
@@ +50,5 @@
> +// stream has ended and abort.
> +static int64_t kAccessUnitTimeoutUs = 10000000ll;
> +
> +// We start the end-of-stream timer in the last 2 seconds.
> +static int64_t kPrepareForEndOfStreamUs = 2000000ll;

My suggested naming:
static int64_t kActivateEndOfStreamTimerUs = 2000000ll;

@@ +1095,5 @@
> +                mSessionDesc->getDurationUs(&duration);
> +                accessUnit->meta()->findInt64("timeUs", &timeUs);
> +
> +                // Start a timer to detect end-of-stream if close to the end.
> +                if (timeUs >= duration - kPrepareForEndOfStreamUs) {

if (timeUs >= duration - kActivateEndOfStreamTimerUs)

Comment 12

[Jonathan Hao (inactive) [:jhao]]

Attachment: Separate timer of access unit timeout and end-of-stream detection.

I agree with your naming choice.

Waiting for try server results:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=2c63b5ecbaf6

Comment 13

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/b2g-inbound/rev/6b935b2fd11c

Comment 14

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/6b935b2fd11c

Comment 16

[Kai-Zhen Li [:seinlin][:kli]]

https://hg.mozilla.org/releases/mozilla-b2g32_v2_0m/rev/02e1958c6086