Closed
Bug 949346
Opened 12 years ago
Closed 11 years ago
Intermittent TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_streams_element_capture.html | small-shot.mp3 current time at end: 0.026122093200683594 should be: 0.27
Categories
(Core :: Audio/Video, defect)
Tracking
()
RESOLVED
FIXED
mozilla30
People
(Reporter: cbook, Assigned: jwwang)
References
()
Details
(Keywords: intermittent-failure)
Attachments
(4 files, 3 obsolete files)
|
1.03 KB,
text/html
|
Details | |
|
19.08 KB,
patch
|
jwwang
:
review+
|
Details | Diff | Splinter Review |
|
16.51 KB,
patch
|
jwwang
:
review+
Sylvestre
:
approval-mozilla-aurora+
|
Details | Diff | Splinter Review |
|
16.51 KB,
patch
|
jwwang
:
review+
Sylvestre
:
approval-mozilla-beta+
|
Details | Diff | Splinter Review |
seems this is the mp3 variant of bug 750258
Ubuntu VM 12.04 x64 b2g-inbound debug test mochitest-1 on 2013-12-11 21:19:24 PST for push 4ca61e6ae245
slave: tst-linux64-ec2-468
https://tbpl.mozilla.org/php/getParsedLog.php?id=31854382&tree=B2g-Inbound
155565 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_streams_element_capture.html | small-shot.mp3 current time at end: 0.026122093200683594 should be: 0.27
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Assignee | ||
Comment 21•11 years ago
|
||
https://tbpl.mozilla.org/php/getParsedLog.php?id=34468110&tree=Try&full=1
22:00:51 INFO - 9563 INFO TEST-START | /tests/content/media/test/test_mediarecorder_creation_fail_gstreamer2.html
22:00:51 INFO - 9564 INFO TEST-INFO | /tests/content/media/test/test_mediarecorder_creation_fail_gstreamer2.html | oncanplaythrough
22:00:51 INFO - 9565 INFO TEST-INFO | /tests/content/media/test/test_mediarecorder_creation_fail_gstreamer2.html | duration=3.343616, currentTime=0.156734
It looks like a bug in GStreamerReader that causes premature end of stream. Therefore when onended is received, currentTime is 0.156734 far away from its duration = 3.343616.
Assignee: nobody → jwwang
Status: NEW → ASSIGNED
| Assignee | ||
Comment 22•11 years ago
|
||
The test case in comment #21.
| Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment 24•11 years ago
|
||
I also hit this perma-orange in a patch I'm working on. MP4 Explorer reports that gizmo.mp4 has 166 video samples, but we stop decoding when we reach video sample 91.
| Assignee | ||
Comment 25•11 years ago
|
||
(In reply to Chris Pearce (:cpearce) from comment #24)
> I also hit this perma-orange in a patch I'm working on. MP4 Explorer reports
> that gizmo.mp4 has 166 video samples, but we stop decoding when we reach
> video sample 91.
Did that happen on Linux as well? I once hit a deadlock where 2 gstreamer threads were waiting for some event which never came. I think that is another bug though.
Comment 26•11 years ago
|
||
Yes, I was using Ubuntu 12.04, Gstreamer 0.10 I believe. Opt build in a VMWare Workstaion VM reproduces the bug reliably.
| Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment 28•11 years ago
|
||
(In reply to JW Wang[:jwwang] from comment #21)
> https://tbpl.mozilla.org/php/getParsedLog.php?id=34468110&tree=Try&full=1
>
> 22:00:51 INFO - 9563 INFO TEST-START |
> /tests/content/media/test/test_mediarecorder_creation_fail_gstreamer2.html
> 22:00:51 INFO - 9564 INFO TEST-INFO |
> /tests/content/media/test/test_mediarecorder_creation_fail_gstreamer2.html |
> oncanplaythrough
> 22:00:51 INFO - 9565 INFO TEST-INFO |
> /tests/content/media/test/test_mediarecorder_creation_fail_gstreamer2.html |
> duration=3.343616, currentTime=0.156734
>
> It looks like a bug in GStreamerReader that causes premature end of stream.
> Therefore when onended is received, currentTime is 0.156734 far away from
> its duration = 3.343616.
I have a fix for this in bug 973139. That may fix the MP3 failures here.
I also can reproduce the same type failure for vp9.webm in test_streams_element_capture.html. Presumably that will require a WebM specific fix.
| Assignee | ||
Comment 29•11 years ago
|
||
https://tbpl.mozilla.org/php/getParsedLog.php?id=34778770&tree=Try
8684 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_mediarecorder_creation_fail_gstreamer2.html | wrong currentTime
8913 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_streams_element_capture.html | small-shot.mp3 current time at end: 0.026122093200683594 should be: 0.27
It still happened with bug 973139 landed.
| Assignee | ||
Comment 30•11 years ago
|
||
https://tbpl.mozilla.org/php/getParsedLog.php?id=34778770&tree=Try
nspr log from the try server:
2014-02-17 08:22:09.617026 UTC - -1453921472[9ce64b80]: f2bceb0 StartPlayback()
2014-02-17 08:22:09.617055 UTC - -1453921472[9ce64b80]: f2bceb0 Start DecodeLoop()
2014-02-17 08:22:09.617215 UTC - -1453921472[9ce64b80]: f2bceb0 Decoder writing 1152 frames of data to MediaStream for AudioData at 0
2014-02-17 08:22:09.617262 UTC - -1453921472[9ce64b80]: f2bceb0 Decoder writing 1152 frames of data to MediaStream for AudioData at 26122
2014-02-17 08:22:09.617452 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=2729, rv=0, resPos=6825
2014-02-17 08:22:09.617480 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=6825
2014-02-17 08:22:09.617509 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=0, rv=0, resPos=6825
2014-02-17 08:22:09.617528 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=2729, aLength=5224
2014-02-17 08:22:09.617549 UTC - -1772094656[9abf6ae0]: ReadAndPushData not enough data, bytesRead=2729, aLength=5224, resLength=6825
2014-02-17 08:22:09.617584 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 1601
2014-02-17 08:22:09.617611 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=1601
2014-02-17 08:22:09.617667 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=5224, rv=0, resPos=6825
2014-02-17 08:22:09.617688 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=5224, aLength=5224
2014-02-17 08:22:09.617706 UTC - -1772094656[9abf6ae0]: ReadAndPushData push ret unexpected
2014-02-17 08:22:09.617908 UTC - -1453921472[9ce64b80]: f2bceb0 Exiting DecodeLoop
2014-02-17 08:22:09.617935 UTC - -1453921472[9ce64b80]: f2bceb0 Decode thread finished
In GStreamerReader::ReadAndPushData(), for aLength is 5224 and bytesRead is 2729, it decides the end of the stream is reached and call gst_app_src_end_of_stream() to signify gstreamer. Then we see gst_app_src_push_buffer() fails (ReadAndPushData push ret unexpected) for the stream already reaches the end. Later on decoder thread exists for mReader->DecodeAudioData returns false for the end of the stream.
I think we should not decide end of stream when resource->Read returns zero bytes in GStreamerReader::ReadAndPushData() because there might be network latency and buffer underflow in MediaSource.
| Assignee | ||
Comment 31•11 years ago
|
||
2014-02-17 08:22:09.613781 UTC - -1453921472[9ce64b80]: reset decode
2014-02-17 08:22:09.613819 UTC - -1453921472[9ce64b80]: reset decode done
2014-02-17 08:22:09.613962 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 0
2014-02-17 08:22:09.613999 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=0
2014-02-17 08:22:09.614082 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=6825, rv=0, resPos=6825
2014-02-17 08:22:09.614104 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=6825, aLength=6825
2014-02-17 08:22:09.614139 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 0
2014-02-17 08:22:09.614166 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=0
2014-02-17 08:22:09.614222 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=6825, rv=0, resPos=6825
2014-02-17 08:22:09.614243 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=6825, aLength=6825
2014-02-17 08:22:09.614275 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 34
2014-02-17 08:22:09.614301 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=34
2014-02-17 08:22:09.614356 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=6791, rv=0, resPos=6825
2014-02-17 08:22:09.614376 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=6791, aLength=6791
2014-02-17 08:22:09.614406 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 34
2014-02-17 08:22:09.614432 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=34
2014-02-17 08:22:09.614486 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=6791, rv=0, resPos=6825
2014-02-17 08:22:09.614506 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=6791, aLength=6791
2014-02-17 08:22:09.614647 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 556
2014-02-17 08:22:09.614683 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=556
2014-02-17 08:22:09.614758 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=6269, rv=0, resPos=6825
2014-02-17 08:22:09.614780 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=6269, aLength=6269
2014-02-17 08:22:09.614813 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 556
2014-02-17 08:22:09.614839 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=556
2014-02-17 08:22:09.614895 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=6269, rv=0, resPos=6825
2014-02-17 08:22:09.614915 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=6269, aLength=6269
2014-02-17 08:22:09.615247 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 1078
2014-02-17 08:22:09.615284 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=1078
2014-02-17 08:22:09.615344 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=5747, rv=0, resPos=6825
2014-02-17 08:22:09.615364 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=5747, aLength=5747
2014-02-17 08:22:09.615396 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 1078
2014-02-17 08:22:09.615422 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=1078
2014-02-17 08:22:09.615501 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), size=5747, rv=0, resPos=6825
2014-02-17 08:22:09.615521 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0), bytesRead=5747, aLength=5747
2014-02-17 08:22:09.615900 UTC - -1772094656[9abf6ae0]: (f7ae1a0) seek at 1601
2014-02-17 08:22:09.615937 UTC - -1772094656[9abf6ae0]: ReadAndPushData(f7ae1a0) resource->Read(), resPos=1601
Btw, the logs look suspicious to me.
seek at 0 -> read 6825 bytes
seek at 0 -> read 6825 bytes
seek at 34 -> read 6791 bytes
It looks like a waste of time to read a large chunk, discard it and then seek back to the previous position. This might be another bug though.
| Assignee | ||
Comment 32•11 years ago
|
||
Fix premature end of stream in GStreamerReader caused by underflow of MediaSource.
When the stream size is known be the GStreamer, we will let it handle the end of the stream. In case of unknown stream size, we will do our best guess to determine end of stream only when zero bytes are returned from MediaSource::Read(). This fix is not optimal though, for the backend of MediaSource could suffer from temporary network congestion. However, for it seems there is no reliable way to detect EOS from the interface of MediaSource, we will do our best guess then.
Attachment #8377347 -
Flags: review?(cpearce)
Comment 33•11 years ago
|
||
Comment on attachment 8377347 [details] [diff] [review]
part1_fix.patch
Review of attachment 8377347 [details] [diff] [review]:
-----------------------------------------------------------------
Looks good to me. Just want to check that Alessandro agrees.
Attachment #8377347 -
Flags: review?(cpearce) → review?(alessandro.d)
Comment 34•11 years ago
|
||
Comment on attachment 8377347 [details] [diff] [review]
part1_fix.patch
It is not clear to me when MediaResource can return 0 if it's not at EOS. By (briefly) looking at MediaCacheStream I think it blocks when it isn't at the end of stream and it doesn't have any data.
The patch looks good regardless. Thanks!
Attachment #8377347 -
Flags: review?(alessandro.d) → review+
| Assignee | ||
Comment 35•11 years ago
|
||
(In reply to Alessandro Decina from comment #34)
> Comment on attachment 8377347 [details] [diff] [review]
> part1_fix.patch
>
> It is not clear to me when MediaResource can return 0 if it's not at EOS. By
> (briefly) looking at MediaCacheStream I think it blocks when it isn't at the
> end of stream and it doesn't have any data.
>
> The patch looks good regardless. Thanks!
From the log of comment #30:
2014-02-17 08:22:09.617549 UTC - -1772094656[9abf6ae0]: ReadAndPushData not enough data, bytesRead=2729, aLength=5224, resLength=6825
The stream length was 6825, and it returned only 2729 bytes when 5224 bytes were required. This is suspicious to me. This might be another bug though. I will try to open another bug to investigate the behavior of MediaCacheStream about end of stream handling.
Comment 36•11 years ago
|
||
Was the stream closed? Could you expose MediaCacheStream::IsClosed() and add it to your logging?
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Assignee | ||
Comment 38•11 years ago
|
||
(In reply to Chris Pearce (:cpearce) from comment #36)
> Was the stream closed? Could you expose MediaCacheStream::IsClosed() and add
> it to your logging?
patch: https://hg.mozilla.org/try/rev/2bb0dd8aa420
log produced on my local side:
1985963776[7fa288b42700]: ReadAndPushData insufficient data, bytesRead=2729, aLength=5747, resPos=6825, resLength=6825, IsClosed=0
MediaCacheStream::IsClosed return false as shown in the log. After Read(), the stream offset is 6825 which is the end. It looks like GStreamer asked for (5747) more than the remaining bytes (2729). It is suspicious that GStreamer should know the length and offset of the stream and shouldn't ask for more than the stream can offer.
I will try to print the stream offset before the Read() operation to detect if there is an unexpected Seek() happening on another thread in between GStreamerReader::ReadAndPushData().
| Assignee | ||
Comment 39•11 years ago
|
||
patch: https://hg.mozilla.org/try/rev/eaba43985bb2
log produced on my local side:
1124112640[7f6ed477d220]: ReadAndPushData unexpected seeking, bytesRead=2729, aLength=5747, offset=1078->6825, resLength=6825, IsClosed=0
1124112640[7f6ed477d220]: ReadAndPushData insufficient data, bytesRead=2729, aLength=5747, resPos=6825, resLength=6825, IsClosed=0
Unexpected seeking during GStreamerReader::NeedDataCb() is confirmed.
1078 (offset1) + 5747 (aLength) = 6825 (resLength)
The GStreamer sees the stream offset is 1078 and it wants to read till the end and thus passing aLength=5747 to GStreamerReader::NeedDataCb(). However there is a seeking operation happening on another thread and advances the offset, therefore only 2729 are returned despite 5747 being required. This bug might also account for the strange behavior in comment #31.
I think we might need to add a monitor to GStreamerReader::ReadAndPushData() so that there is no seeking happening in between.
Comment 40•11 years ago
|
||
(In reply to JW Wang[:jwwang] from comment #39)
> I think we might need to add a monitor to GStreamerReader::ReadAndPushData()
> so that there is no seeking happening in between.
You should use MediaResource::ReadAt() instead. This includes the seek inside the MediaResource's lock, so is thread-safe.
For example, I used MediaResource::ReadAt() to do thread-safe reads in the Windows Media Foundation backend:
http://mxr.mozilla.org/mozilla-central/source/content/media/wmf/WMFByteStream.cpp#234
| Assignee | ||
Comment 41•11 years ago
|
||
http://mxr.mozilla.org/mozilla-central/source/content/media/gstreamer/GStreamerReader.cpp#970
If MediaResource::ReadAt() happens on another thread right after resource->Seek(SEEK_SET, aOffset), GStreamer will get an unexpected offset. For that case, we still need lock GStreamerReader::ReadAndPushData(), right?
Comment 42•11 years ago
|
||
Actually, I think that could still fail.
You can (probably) assume that each GStreamer thread that is reading will do a seek right before they read.
alessandro: Do you know if that assumption correct?
So when one thread reads, it will do:
thread 1 -> Seek to offset x
thread 1 -> Read n bytes at offset x.
So if you have multiple threads reading, this could happen:
thread 1 -> Seek to offset x
thread 2 -> Seek to offset y
thread 1 -> Read n bytes at offset y // Wrong! thread 1 expected to read at offset x!
thread 2 -> Read m bytes at offset y+n // Wrong! thread 2 expected to read at offset y!
So I think even if you locked in ReadAndPushData() and in Seek() you could still get errors. The code in WMFByteStream may be wrong too. WMFByteStream synchronizes the seek offset, so reads happen with the seek offset at the time they were called. So I think the above case would also fail with that code. We have a lot of orange on Windows, and was I never able to fix it, this may explain it.
You could test if this is the problem by using a static mozilla::ThreadLocal<int32_t> for the seek offset. This will have a different value per thread. If the bug no longer appears with this change, then you know this is the problem. Unfortunately you can't store 64bit values in a ThreadLocal<T> in 32bit builds, the final solution would need to be an ThreadLocal<int64_t*> I guess, instead of a ThreadLocal<int64_t>. :(
You could also try storing the seek offset in a HashTable, indexed by thread ID, and using MediaResource->ReadAt() with the seek offset from the HashTable. So each thread sees its own seek offset/read cursor. You could also compare values from the HashTable, and if they are not the same, you know you've identified the bug. :) The HashTable needs to be synchronized of course.
Flags: needinfo?(alessandro.d)
| Assignee | ||
Comment 43•11 years ago
|
||
#0 mozilla::ChannelMediaResource::ReadAt (this=0x7f966769fa00, aOffset=0, aBuffer=0x7f965af28a60 "ID3\004", aCount=4096, aBytes=0x7f965af28a38)
#1 0x00007f967ba85d40 in mozilla::GStreamerReader::ParseMP3Headers (this=0x7f9667646800)
#2 0x00007f967ba86504 in mozilla::GStreamerReader::ReadMetadata (this=0x7f9667646800, aInfo=0x7f965af29b90, aTags=0x7f965af29b78)
#3 0x00007f967b9ccf72 in mozilla::MediaDecoderStateMachine::DecodeMetadata (this=0x7f965759b380)
#4 0x00007f967b9c6fa2 in mozilla::MediaDecoderStateMachine::DecodeThreadRun (this=0x7f965759b380)
This callstack is what happened in between GStreamerReader::ReadAndPushData(). ReadAt() changes the stream offset which GStreamer is not aware of and might confuse the state machine of GStreamer.
Is there a way to push this task to the GStreamer thread so that the stream operation is under GStreamer's control? Or can we restore the stream state such that the stream state is consistent through GStreamerReader::ReadAndPushData()?
Comment 44•11 years ago
|
||
(In reply to JW Wang[:jwwang] from comment #43)
> #0 mozilla::ChannelMediaResource::ReadAt (this=0x7f966769fa00, aOffset=0,
> aBuffer=0x7f965af28a60 "ID3\004", aCount=4096, aBytes=0x7f965af28a38)
> #1 0x00007f967ba85d40 in mozilla::GStreamerReader::ParseMP3Headers
> (this=0x7f9667646800)
> #2 0x00007f967ba86504 in mozilla::GStreamerReader::ReadMetadata
> (this=0x7f9667646800, aInfo=0x7f965af29b90, aTags=0x7f965af29b78)
> #3 0x00007f967b9ccf72 in mozilla::MediaDecoderStateMachine::DecodeMetadata
> (this=0x7f965759b380)
> #4 0x00007f967b9c6fa2 in mozilla::MediaDecoderStateMachine::DecodeThreadRun
> (this=0x7f965759b380)
>
> This callstack is what happened in between
> GStreamerReader::ReadAndPushData(). ReadAt() changes the stream offset which
> GStreamer is not aware of and might confuse the state machine of GStreamer.
>
> Is there a way to push this task to the GStreamer thread so that the stream
> operation is under GStreamer's control? Or can we restore the stream state
> such that the stream state is consistent through
> GStreamerReader::ReadAndPushData()?
Oh, funny. If you just move
bool isMP3 = mDecoder->GetResource()->GetContentType().EqualsASCII(AUDIO_MP3);
if (isMP3) {
ParseMP3Headers();
}
up before the pipeline is started, I think we'll be fine.
(...or we could enable gstreamer on windows as well and just let gst parse mp3 headers :P)
Flags: needinfo?(alessandro.d)
Comment 45•11 years ago
|
||
(In reply to Chris Pearce (:cpearce) from comment #42)
> Actually, I think that could still fail.
>
> You can (probably) assume that each GStreamer thread that is reading will do
> a seek right before they read.
>
> alessandro: Do you know if that assumption correct?
With our current pipeline there is only one thread reading. The thread is inside appsrc and loops trying to read from 0 to resource->GetLength() (or EOS, whichever happens first). Every time it needs more data, it calls the NeedData callback from which we call ReadAndPushData.
>
> So when one thread reads, it will do:
>
> thread 1 -> Seek to offset x
> thread 1 -> Read n bytes at offset x.
>
> So if you have multiple threads reading, this could happen:
>
> thread 1 -> Seek to offset x
> thread 2 -> Seek to offset y
> thread 1 -> Read n bytes at offset y // Wrong! thread 1 expected to read
> at offset x!
> thread 2 -> Read m bytes at offset y+n // Wrong! thread 2 expected to read
> at offset y!
>
> So I think even if you locked in ReadAndPushData() and in Seek() you could
> still get errors. The code in WMFByteStream may be wrong too. WMFByteStream
> synchronizes the seek offset, so reads happen with the seek offset at the
> time they were called. So I think the above case would also fail with that
> code. We have a lot of orange on Windows, and was I never able to fix it,
> this may explain it.
Yes (this is all true at least for GStreamerReader)
Comment 46•11 years ago
|
||
(In reply to Alessandro Decina from comment #45)
> (In reply to Chris Pearce (:cpearce) from comment #42)
> > Actually, I think that could still fail.
> >
> > You can (probably) assume that each GStreamer thread that is reading will do
> > a seek right before they read.
> >
> > alessandro: Do you know if that assumption correct?
>
> With our current pipeline there is only one thread reading. The thread is
> inside appsrc and loops trying to read from 0 to resource->GetLength() (or
> EOS, whichever happens first). Every time it needs more data, it calls the
> NeedData callback from which we call ReadAndPushData.
And of course I failed to say explicitly that it doesn't seek before a read, no. It assumes a file-like interface where there's a read pointer that advances as the resource is read.
Comment 47•11 years ago
|
||
Comment on attachment 8377347 [details] [diff] [review]
part1_fix.patch
Review of attachment 8377347 [details] [diff] [review]:
-----------------------------------------------------------------
btw i'm r-'ing this now that we know what's happening, since I think this can actually cause more harm than good (can cause semi silent corruptions).
Attachment #8377347 -
Flags: review+ → review-
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Assignee | ||
Comment 52•11 years ago
|
||
1. print this pointer in nspr logs for debugging multiple GStreamerReader running concurrently
2. Parse MP3 headers before kicking off the gstreamer pipeline such that there are no concurrent stream operations which could screw the state machine of gstreamer
Attachment #8377347 -
Attachment is obsolete: true
Attachment #8378102 -
Flags: review?(alessandro.d)
Updated•11 years ago
|
Attachment #8378102 -
Flags: review?(alessandro.d) → review+
| Assignee | ||
Comment 53•11 years ago
|
||
Btw, the matroskademux seek hack causes gst_app_src_push_buffer return GST_FLOW_WRONG_STATE in GStreamerReader::ReadAndPushData(). Since Bug 973744 will remove this hack, it is no longer a concern.
| Assignee | ||
Comment 54•11 years ago
|
||
Fix build error - unused variable on Linux.
Attachment #8378102 -
Attachment is obsolete: true
Attachment #8378270 -
Flags: review+
| Assignee | ||
Comment 55•11 years ago
|
||
rebase for Bug 973744 landed.
Attachment #8378270 -
Attachment is obsolete: true
Attachment #8378829 -
Flags: review+
| Assignee | ||
Comment 56•11 years ago
|
||
(In reply to JW Wang[:jwwang] from comment #55)
> Created attachment 8378829 [details] [diff] [review]
> part1_fix.patch - v4
>
> rebase for Bug 973744 landed.
try: https://tbpl.mozilla.org/?tree=Try&rev=c9b95a28be54
| Assignee | ||
Updated•11 years ago
|
Keywords: checkin-needed
Comment 57•11 years ago
|
||
Flags: in-testsuite+
Keywords: checkin-needed
Comment 58•11 years ago
|
||
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla30
Comment 59•11 years ago
|
||
Let's give this a day or two to settle down then request uplift to Aurora/Beta.
status-b2g-v1.3:
--- → affected
status-b2g-v1.4:
--- → fixed
status-firefox28:
--- → affected
status-firefox29:
--- → affected
status-firefox30:
--- → fixed
status-firefox-esr24:
--- → unaffected
Comment 60•11 years ago
|
||
No issues so far. I think we should proceed with the aurora/beta approval request :)
Flags: needinfo?(jwwang)
| Assignee | ||
Comment 61•11 years ago
|
||
(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #60)
> No issues so far. I think we should proceed with the aurora/beta approval
> request :)
Sure. What should I do for the process to proceed?
Flags: needinfo?(jwwang)
Comment 62•11 years ago
|
||
Just request approval-mozilla-aurora/beta on the patch.
| Assignee | ||
Comment 63•11 years ago
|
||
Comment on attachment 8378829 [details] [diff] [review]
part1_fix.patch - v4
[Approval Request Comment]
Bug caused by (feature/regressing bug #): 918135
User impact if declined: MP3 duration might be wrong when playing on Linux
Testing completed (on m-c, etc.): yes
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch: none
Attachment #8378829 -
Flags: approval-mozilla-beta?
Attachment #8378829 -
Flags: approval-mozilla-aurora?
| Assignee | ||
Comment 64•11 years ago
|
||
Btw, rebase might be needed.
Are these the repos for aurora and beta?
http://hg.mozilla.org/releases/mozilla-aurora/
http://hg.mozilla.org/releases/mozilla-beta/
| Assignee | ||
Comment 65•11 years ago
|
||
Comment on attachment 8378829 [details] [diff] [review]
part1_fix.patch - v4
rebase needed.
Attachment #8378829 -
Flags: approval-mozilla-beta?
Attachment #8378829 -
Flags: approval-mozilla-aurora?
| Assignee | ||
Comment 66•11 years ago
|
||
[Approval Request Comment]
Bug caused by (feature/regressing bug #): 918135
User impact if declined: MP3 duration might be wrong when playing on Linux
Testing completed (on m-c, etc.): yes
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch:none
try: https://tbpl.mozilla.org/?tree=Try&rev=cd325afefe76
Attachment #8381175 -
Flags: review+
Attachment #8381175 -
Flags: approval-mozilla-aurora?
| Assignee | ||
Comment 67•11 years ago
|
||
[Approval Request Comment]
Bug caused by (feature/regressing bug #): 918135
User impact if declined: MP3 duration might be wrong when playing on Linux
Testing completed (on m-c, etc.): yes
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch:none
try: https://tbpl.mozilla.org/?tree=Try&rev=2ee57e529f31
Attachment #8381176 -
Flags: review+
Attachment #8381176 -
Flags: approval-mozilla-beta?
Updated•11 years ago
|
Attachment #8381175 -
Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Comment 68•11 years ago
|
||
Updated•11 years ago
|
Attachment #8381176 -
Flags: approval-mozilla-beta? → approval-mozilla-beta+
Comment 69•11 years ago
|
||
Comment 70•11 years ago
|
||
Updated•11 years ago
|
Updated•11 years ago
|
status-b2g-v1.3T:
--- → fixed
You need to log in
before you can comment on or make changes to this bug.
Description
•