Closed Bug 951278 Opened 11 years ago Closed 11 years ago

[RTSP][V1.3] The RTSP streaming always stops at the last 1st or 2nd second

Categories

(Firefox OS Graveyard :: RTSP, defect)

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(blocking-b2g:2.0+, b2g-v2.0 fixed)

VERIFIED FIXED
2.0 S2 (23may)
blocking-b2g 2.0+
Tracking Status
b2g-v2.0 --- fixed

People

(Reporter: whsu, Assigned: vchang)

References

Details

Attachments

(3 files, 5 obsolete files)

Attached video WP_20131217_002.mp4
* Description: This problem happened on v1.3 build. If a RTSP streaming has 200 seconds, the video app always stops at the 198th or 199th second. Attaching the demo video (WP_20131217_002.mp4). * Reproduction steps: 1. Launch the following web page via browser - http://goo.gl/lE2eE3 2. Tap the "Video test page" 3. Seek the RTSP streaming to the 1:50. 4. Wait for the end of the streaming * Expected result: Video app can play whole RTSP streaming * Actual result: The RTSP streaming always stops at the last 1st or 2nd second * Reproduction build: V1.3 (Buri) - Gaia: 37142f72c422120401dbc90e1f5e8f689576bb8e - Gecko: http://hg.mozilla.org/releases/mozilla-aurora/rev/cc2ab73484b2 - BuildID 20131215004003 - Version 28.0a2
blocking-b2g: --- → 1.3?
Assignee: nobody → vchang
NI Sri for confirming blocking decision (per some recent email from Sri/Chris - video streaming is not a blocker for 1.3)
Flags: needinfo?(skasetti)
Seems that in the streaming case, we don't have a way to know "end of stream". In mpeg4extractor.cpp , there is a sample table and return false for "end of stream".
RTSP video support is not a blocker for 1.3
blocking-b2g: 1.3? → -
Flags: needinfo?(skasetti)
Blocks: b2g-RTSP-1.3
Whiteboard: [FT:RIL]
Discussed offline - we can't ship audio RTSP support without video RTSP support in 1.3 (i.e. hard dependency). We also can't lower the quality bar on video RTSP support as well, given that users only know that a RTSP URL is video only after the media content is loaded. Therefore, any feature blockers for shipping video RTSP support needs to be treated as a blocker for the release.
blocking-b2g: - → 1.3?
I am still working on this bug, but don't have a solution right now. I found that media decoder state machine thread is in DECODER_STATE_DECODING state, and trying to rend video data from mReader->VideoQueue(). But the size of VideoQueue is alway zero while at the same time Video end time (mVideoFrameEndTime) and Audio end time (mAudioEndTime) are less than total duration. Not sure if decoder loop has consumed all the data received from the RTSP server. Still take time to find the root cause.
1.3+ for data loss
blocking-b2g: 1.3? → 1.3+
(In reply to Preeti Raghunath(:Preeti) from comment #8) > 1.3+ for data loss We discussed this later in triage when product joined the call - the proposal going forward is to throw an error when video is detected given the fact that quality of video with RTSP is poor. This would be a blocker for shipping video support for RTSP, so moving this to 1.4?
blocking-b2g: 1.3+ → 1.4?
Blocks: b2g-RTSP-2.0
No longer blocks: b2g-RTSP-1.3
Finally figure out the root cause here, we have to return end of stream error to prevent from blocking binder thread in RtspTrackBuffer::ReadBuffer() function. http://dxr.mozilla.org/mozilla-central/source/content/media/RtspMediaResource.cpp?from=RtspMediaResource.cpp#148 The decoder thread will be blocked in read() function if we are unable to handle end of stream event in http://dxr.mozilla.org/mozilla-central/source/content/media/omx/OmxDecoder.cpp?from=OmxDecoder.cpp#793 Along with RTP protocol, RTCP protocol defines BYE message and we can use it to indicate that we are going to leave the participation of current session. We have implemented end of stream using RTCP bye message right now. However, this mechanism is highly depending on the implementation of RTSP server. In my observation, the RTSP server sends the RTCP bye message after more than 10 seconds it sends the last RTP packet. It means that we need to find a better method to detect end of stream.
It blocks 1.4 feature.
blocking-b2g: 1.4? → 1.4+
Attached patch WIP: endofstream.v1.0.patch (obsolete) — Splinter Review
There are two ways to indicate end of stream from Rtsp server. They are 1. Rtsp server send tear down to Rtsp client. 2. Rtsp client receive Rtcp bye message. But both ways depend on how server is implemented. We propose a method to detect end of stream in Rtsp client by checking if Rtsp client receives Rtp packet is certain period of time. The reason we need this patch is because that we need to notify Android binder thread to prevent it suspends in ReadBuffer() function. http://dxr.mozilla.org/mozilla-central/source/content/media/RtspMediaResource.cpp?from=RtspMediaResource.cpp#203 So the decoder state machine thread can swith to DECODER_STATE_COMPLETED and read the remaining audio data completely. http://dxr.mozilla.org/mozilla-central/source/content/media/MediaDecoderStateMachine.cpp?from=mediadecoderstatemachine.cpp#2352 This is marked as a WIP because I found that GENLOCK_IOC_LOCK error message after this patch is applied. E/libgenlock( 1973): perform_lock_unlock_operation: GENLOCK_IOC_LOCK failed (lockType0x2, err=Connection timed out fd=134) E/Adreno200-EGLSUB( 1973): LockImage() genlock_lock_buffer GENLOCK_READ_LOCK failed
Attachment #8376828 - Flags: feedback?(sworkman)
(In reply to Vincent Chang[:vchang] from comment #12) > Created attachment 8376828 [details] [diff] [review] > WIP: endofstream.v1.0.patch > > There are two ways to indicate end of stream from Rtsp server. They are > 1. Rtsp server send tear down to Rtsp client. > 2. Rtsp client receive Rtcp bye message. In general the patch seems fine, but I'm not 100% clear how the 'tear down' is received, or where the 'bye' message is mentioned in this patch. What I do see is an end of stream frame type being written to the track buffer, and this seems good to me. It should stop the decoder state machine from waiting indefinitely. If you can give me some details on where 1. and 2. above are at in the code, that would be great. > But both ways depend on how server is implemented. We propose a method to > detect end of stream in Rtsp client by checking if Rtsp client receives Rtp > packet is certain period of time. > The reason we need this patch is because that we need to notify Android > binder thread to prevent it suspends in ReadBuffer() function. > http://dxr.mozilla.org/mozilla-central/source/content/media/ > RtspMediaResource.cpp?from=RtspMediaResource.cpp#203 > So the decoder state machine thread can swith to DECODER_STATE_COMPLETED and > read the remaining audio data completely. > http://dxr.mozilla.org/mozilla-central/source/content/media/ > MediaDecoderStateMachine.cpp?from=mediadecoderstatemachine.cpp#2352 > > This is marked as a WIP because I found that GENLOCK_IOC_LOCK error message > after this patch is applied. > E/libgenlock( 1973): perform_lock_unlock_operation: GENLOCK_IOC_LOCK failed > (lockType0x2, err=Connection timed out fd=134) > E/Adreno200-EGLSUB( 1973): LockImage() genlock_lock_buffer GENLOCK_READ_LOCK > failed
For the TEARDOWN message, it is sent from the Rtsp client to the Rtsp server and the server stops the stream delivery for the given URI and release all the resources bind on this session. So the server doesn't send TEARDOWN message to the client. It's my typo, sorry. There are serveral timings that the client sends TEARDOWN message to the server, 1. Timeout receiving rtp/rtcp packets from the server after the client recieves 200 OK ACK for PLAY message. The timeout is set to 10 seconds now. 2. access unit time out after received first RTP and RTCP packets. The default value is set to 10 seconds so far, but my patch decrease the timeout value to 2 seconds and send the end of stream in this case. The end of stream event is per track basis. 3. RTSPsource::stop() is called from RtspController. For the Rtcp bye message, It is defined in http://www.ietf.org/rfc/rfc3550.txt (6.3.4 Receiving an RTCP BYE Packet) We parse this message in http://dxr.mozilla.org/mozilla-central/source/netwerk/protocol/rtsp/rtsp/ARTPConnection.cpp#560 and set 'eos' in access unit in http://dxr.mozilla.org/mozilla-central/source/netwerk/protocol/rtsp/rtsp/AMPEG4ElementaryAssembler.cpp?from=AMPEG4ElementaryAssembler.cpp&case=true#402 The access unit with 'eos' message is handled here http://dxr.mozilla.org/mozilla-central/source/netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h?from=rtspconnectionhandler.h&case=true#936 Right now, it just output the debug message and do nothing. This 'eos' message is useless because it's too late to receive that rtcp bye message and it's depending on how server implement it. The message flow is something like (you can check the captured packeted in attached file) 61.175s Rtsp server (final rtp) -----> desktop vlc client 71.681s Rtsp server <----- (rtsp TearDown) desktop vlc client 71.681s Rtsp server <----- (rtcp bye) desktop vlc client 71.972 Rtsp server (rtcp bye, icmp err)--> desktop vlc client I think we should send end of stream right after we receive the final rtp packet from Rtsp server, except to reduce access unit timeout, I don't have good approach to detect end of stream right now.
No longer going to block - RTSP video needs to be preffed off in 1.4 per a drivers decision to cut scope to only DSDS & QC required features.
blocking-b2g: 1.4+ → 1.4?
One finding on genlock_lock_buffer error, I found the frame->mTime is decoded as zero, if I prevent that frame from calling RenderVideoFrame(), I don't have genlock_lock_buffer error anymore. http://dxr.mozilla.org/mozilla-central/source/content/media/MediaDecoderStateMachine.cpp#2321
Does this symptom also happen in audio streaming case?
In UX point of view, audio stream only case is fine. User will not observe this bug.
blocking-b2g: 1.4? → 1.5?
Comment on attachment 8376828 [details] [diff] [review] WIP: endofstream.v1.0.patch Review of attachment 8376828 [details] [diff] [review]: ----------------------------------------------------------------- Sorry it's taken some time to get back to you on this. f+ for this approach - your patch and explanation seems good to me. Some minor comments below. ::: netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h @@ +47,5 @@ > #define LOGW(msg, ...) PR_LOG(gRtspLog, PR_LOG_WARNING, (msg, ##__VA_ARGS__)) > > // If no access units are received within 5 secs, assume that the rtp > // stream has ended and signal end of stream. > +static int64_t kAccessUnitTimeoutUs = 2000000ll; I don't think this matches the comment. Please verify and change comment as necessary. @@ +905,3 @@ > LOGI("stream ended? aborting."); > + sp<AMessage> endStream = new AMessage('endofstream', id()); > + endStream->setSize("trackIndex", trackIndex); s/endStream/endStreamMsg/
Attachment #8376828 - Flags: feedback?(sworkman) → feedback+
Attached patch Patch v1.1 (obsolete) — Splinter Review
1. Address the review comments. 2. Genlock issue is depended on platform, we found it in Unagi only. Buri and Nexus 5 don't have this problem. 3. Fixed crash problem found when testing the patch in Buri.
Attachment #8376828 - Attachment is obsolete: true
Attachment #8392692 - Flags: review?(sworkman)
Comment on attachment 8392692 [details] [diff] [review] Patch v1.1 Review of attachment 8392692 [details] [diff] [review]: ----------------------------------------------------------------- Getting there. Just some questions and minor changes. ::: content/media/MediaDecoderStateMachine.cpp @@ +2324,5 @@ > + // We should have a positive frame time here, however, we found mTime is > + // equal 0 in end of stream case in Unagi phone. It causes genlock error and > + // block the compositor thread in chrome process for several seconds. > + int64_t postiveTime = currentFrame->mTime - mStartTime; > + if (postiveTime > 0 || (postiveTime == 0 && mPlayDuration == 0)) { I think you can remove this comment. The NS_ASSERTION already explains that we should have a positive frame time. s/postiveTime/frameTime/ Can the condition be the same as the NS_ASSERTION? Or must 'frameTime == mPlayDuration == 0' for the block to be entered? If you must check for frameTime == 0, then just explain that in the comment. ::: content/media/RtspMediaResource.cpp @@ +162,5 @@ > // 3. No data in this buffer > // 4. mIsStarted is not set > while (1) { > + // We have no more data for a giving Rtsp url for audio or video track. > + if (mBufferSlotData[mConsumerIdx].mFrameType & MEDIASTREAM_FRAMETYPE_END_OF_STREAM) { I think you can remove this comment. The code comments itself here. @@ +306,5 @@ > RTSPMLOG("overwrite!! %d time %lld" > ,mTrackIdx,mBufferSlotData[mConsumerIdx].mTime); > + if (aFrameType & MEDIASTREAM_FRAMETYPE_END_OF_STREAM) { > + mBufferSlotData[mProducerIdx].mLength = 0; > + mBufferSlotData[mProducerIdx].mTime = 0; In your comment in MediaDecoderStateMachine.cpp you wrote "we found mTime is equal 0 in end of stream case in Unagi phone...". Is this because you set mTime = 0 here? aFrameTime is always 0 for END_OF_STREAM frames, right? ::: netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h @@ +726,5 @@ > if (response->mStatusCode != 200) { > + // We don't want to notify the user this error. > + // TODO, see bug 984295. > + result = INVALID_OPERATION; > + LOGI("Play request with error status code = %d", response->mStatusCode); Is this required for this patch? If not, I'd prefer that the patch was landed separately and as part of 984295. Or open another bug with 984295 as a follow-up. It's easier for backouts and clearer for revision history. @@ +803,5 @@ > + mRTPConn->removeStream(info->mRTPSocket, info->mRTCPSocket); > + close(info->mRTPSocket); > + close(info->mRTCPSocket); > + } > + break; 'break' needs one more space in front. @@ +812,5 @@ > for (size_t i = 0; i < mTracks.size(); ++i) { > TrackInfo *info = &mTracks.editItemAt(i); > + if (info) { > + if (!mFirstAccessUnit) { > + postQueueEOS(i, ERROR_END_OF_STREAM); Nit: Rather than indent this block of code, you could just do: if (!info) { continue; } Nicer for revision history :) @@ +1340,5 @@ > int64_t mMediaAnchorUs; > int64_t mLastMediaTimeUs; > > + Vector<int64_t> mNumAccessUnitsReceiveds; > + Vector<bool> mCheckPendings; Can you add these to TrackInfo? Then we could keep the original names. ::: netwerk/protocol/rtsp/rtsp/RTSPSource.cpp @@ +594,5 @@ > mListener->OnDisconnected(0, NS_OK); > + } else if (err == INVALID_OPERATION) { > + // We don't want to notify the user this error. > + // TODO, see bug 984295. > + mListener->OnDisconnected(0, NS_ERROR_IN_PROGRESS); As in the other case, please include this only if absolutely necessary for this bug. Otherwise, land it in a separate patch. @@ +606,5 @@ > } > > void RTSPSource::finishDisconnectIfPossible() { > if (mState != DISCONNECTED) { > + if (mHandler != NULL) { if (!mHandler) ... @@ +672,5 @@ > + meta = new mozilla::net::RtspMetaData(); > + meta->SetFrameType(MEDIASTREAM_FRAMETYPE_END_OF_STREAM); > + data.AssignLiteral("END_OF_STREAM"); > + if (mListener) { > + mListener->OnMediaDataAvailable(trackIndex, data, data.Length(), 0, meta.get()); I think you can reorder things here. mState = CONNECTED; if (!mListener) { return; } nsCString data; ... Doesn't look like accessUnit or info are used.
Attachment #8392692 - Flags: review?(sworkman) → review-
blocking-b2g: 1.5? → 1.5+
Thanks for your help to review the patch. Please see my comments inline below. > > ::: content/media/MediaDecoderStateMachine.cpp > @@ +2324,5 @@ > > + // We should have a positive frame time here, however, we found mTime is > > + // equal 0 in end of stream case in Unagi phone. It causes genlock error and > > + // block the compositor thread in chrome process for several seconds. > > + int64_t postiveTime = currentFrame->mTime - mStartTime; > > + if (postiveTime > 0 || (postiveTime == 0 && mPlayDuration == 0)) { > > Can the condition be the same as the NS_ASSERTION? Or must 'frameTime == > mPlayDuration == 0' for the block to be entered? > If you must check for frameTime == 0, then just explain that in the comment. I am trying to filter out incorrect frames here. However, mTime could/should be zero if it is a initial frame (mPlayDuration should be zero for a initial frame). > @@ +306,5 @@ > > RTSPMLOG("overwrite!! %d time %lld" > > ,mTrackIdx,mBufferSlotData[mConsumerIdx].mTime); > > + if (aFrameType & MEDIASTREAM_FRAMETYPE_END_OF_STREAM) { > > + mBufferSlotData[mProducerIdx].mLength = 0; > > + mBufferSlotData[mProducerIdx].mTime = 0; > > In your comment in MediaDecoderStateMachine.cpp you wrote "we found mTime is > equal 0 in end of stream case in Unagi phone...". Is this because you set > mTime = 0 here? > aFrameTime is always 0 for END_OF_STREAM frames, right? I don't think so. Because we check if mFrameType is equal end of stream type in the beginning of RtspTrackBuffer::ReadBuffer() function, and return immediately if it is. I don't observe mFrameTime equal zero in other phone (Hamachi). > ::: netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h > @@ +726,5 @@ > > if (response->mStatusCode != 200) { > > + // We don't want to notify the user this error. > > + // TODO, see bug 984295. > > + result = INVALID_OPERATION; > > + LOGI("Play request with error status code = %d", response->mStatusCode); > > Is this required for this patch? If not, I'd prefer that the patch was > landed separately and as part of 984295. Or open another bug with 984295 as > a follow-up. It's easier for backouts and clearer for revision history. For end of stream, the answer should be no. But it causes a network error message pops out at the end of stream if we don't apply this. I can open the follow up bug for this but it should be landed together. > @@ +1340,5 @@ > > int64_t mMediaAnchorUs; > > int64_t mLastMediaTimeUs; > > > > + Vector<int64_t> mNumAccessUnitsReceiveds; > > + Vector<bool> mCheckPendings; > > Can you add these to TrackInfo? Then we could keep the original names. Good idea. It seems easier for resource management. I'll try it in next patch. > ::: netwerk/protocol/rtsp/rtsp/RTSPSource.cpp > @@ +594,5 @@ > > mListener->OnDisconnected(0, NS_OK); > > + } else if (err == INVALID_OPERATION) { > > + // We don't want to notify the user this error. > > + // TODO, see bug 984295. > > + mListener->OnDisconnected(0, NS_ERROR_IN_PROGRESS); > > As in the other case, please include this only if absolutely necessary for > this bug. Otherwise, land it in a separate patch. Ok, got it.
Thanks Vincent - your comments make sense to me.
Attached patch End of stream patch v1.2 (obsolete) — Splinter Review
Address the review comments.
Attachment #8392692 - Attachment is obsolete: true
Attachment #8398365 - Flags: review?(sworkman)
Depends on: 984295
Comment on attachment 8392692 [details] [diff] [review] Patch v1.1 Review of attachment 8392692 [details] [diff] [review]: ----------------------------------------------------------------- Looks good! Re the second patch which avoids the error message, you can just add that to this bug - no need to open a second one. It will be clear enough in the patch comment why it exists.
Attachment #8392692 - Flags: review+
Comment on attachment 8398365 [details] [diff] [review] End of stream patch v1.2 Review of attachment 8398365 [details] [diff] [review]: ----------------------------------------------------------------- (Ooops hit r+ for the previous patch - had both open in separate tabs!) Looks good! Re the second patch which avoids the error message, you can just add that to this bug - no need to open a second one. It will be clear enough in the patch comment why it exists. ::: content/media/MediaDecoderStateMachine.cpp @@ +2487,5 @@ > TimeStamp presTime = mPlayStartTime - UsecsToDuration(mPlayDuration) + > UsecsToDuration(currentFrame->mTime - mStartTime); > NS_ASSERTION(currentFrame->mTime >= mStartTime, "Should have positive frame time"); > + // Filter out invalid frames by checking the frame time. FrameTime could be > + // zero if it's a initial frame. Thank you - this comment is much clearer. Just to be sure, can you ask cpearce (or someone else from the media team) to check this one? I want to make sure it doesn't affect non-RTSP media. ::: netwerk/protocol/rtsp/rtsp/RTSPConnectionHandler.h @@ +187,5 @@ > > + void setCheckPending(bool flag) { > + for (size_t i = 0; i < mTracks.size(); ++i) { > + setCheckPending(i, flag); > + } void setCheckPendingForAllTracks(... @@ +194,5 @@ > + void setCheckPending(size_t trackIndex, bool flag) { > + TrackInfo *info = &mTracks.editItemAt(trackIndex); > + if (info) { > + info->mCheckPendings = flag; > + } void setCheckPendingForTrack(... @@ +200,5 @@ > + > + bool getCheckPending(size_t trackIndex) { > + TrackInfo *info = &mTracks.editItemAt(trackIndex); > + return info->mCheckPendings; > + } bool getCheckPendingForTrack(... @@ +804,5 @@ > + { > + size_t trackIndex = 0; > + msg->findSize("trackIndex", &trackIndex); > + postQueueEOS(trackIndex, ERROR_END_OF_STREAM); > + TrackInfo *info = &mTracks.editItemAt(trackIndex); In the previous patch you removed the mCheckPendings and mNumAccessUnitsReceiveds elements from those arrays. Do you need to reset to false here before continuing? @@ +1327,5 @@ > // has been established yet. > List<sp<ABuffer> > mPackets; > bool mIsPlayAcked; > + int64_t mNumAccessUnitsReceiveds; > + bool mCheckPendings; s/mNumAccessUnitsReceiveds/mNumAccessUnitsReceived/g s/mCheckPendings/mCheckPending/g
Attachment #8398365 - Flags: review?(sworkman) → review+
Target Milestone: --- → 1.4 S6 (25apr)
Component: Gaia::Video → RTSP
Whiteboard: [FT:RIL]
Flags: in-moztrap+
Blocks: 1006484
Attached patch Patch v1.3 (obsolete) — Splinter Review
Rebased the patch.
Attachment #8398365 - Attachment is obsolete: true
After Bug 992568 is landed, we render the RTSP streaming inside browser rather than using the video app. It helps to prevent the bug I found while testing this patch. Remove the depending on bug 984295 flag based on new finding. Besides, we need this patch to fix the bug 1006484.
No longer depends on: 984295
Attached patch Patch v1.4 r=sworkman (obsolete) — Splinter Review
Rebase again.
Attachment #8425286 - Attachment is obsolete: true
sorry had to back this out since this caused build bustages like https://tbpl.mozilla.org/php/getParsedLog.php?id=40077895&tree=B2g-Inbound
Sorry about that, I found we should use PR_Close instead of using close directly.
Fixed build error in linux64 debug platform.
Attachment #8426015 - Attachment is obsolete: true
(In reply to Vincent Chang[:vchang] from comment #34) > Sorry about that, I found we should use PR_Close instead of using close > directly. Sorry from me too. I saw that when I was doing the review and meant to mention it. Especially since I did the review for the patch that changed sockets to NSPR code.
Try server result looks good in linux x64 opt/debug build. https://tbpl.mozilla.org/?tree=Try&rev=5f21d0a9a34d
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Target Milestone: 1.4 S6 (25apr) → 2.0 S2 (23may)
There are several issues raised by the patch of this bug. 1. It caused a regression in bug 1015169 because RTSP objects will never be released after applying this patch. Fortunately we already found the root cause and bug 1015169 will be landed soon. 2. The end-of-stream event handling proposed by this patch might not be robust enough. It would potentially result in audio/video being out of sync. I filed bug 1017444 to track this issue.
Thanks everyone! Verified it. Cannot reproduce it on latest V2.0 build. Attach the screenshot. (2014-06-11-16-29-07.png) * Build information: - Gaia 8d865839d932bfbd5e157f376f74d8cb12bfdd51 - Gecko https://hg.mozilla.org/releases/mozilla-aurora/rev/1d4046a8cb6c - BuildID 20140610000223 - Version 32.0a2
Status: RESOLVED → VERIFIED
Attached image 2014-06-11-16-29-07.png
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: