Closed Bug 987106 Opened 7 years ago Closed 6 years ago

Intermittent test_new_audio.html | Test timed out.

Categories

(Core :: Audio/Video, defect)

Product:
Core
Component:
Audio/Video
Platform:
x86
Windows 7
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1001317

People

(Reporter: cbook, Assigned: jwwang)

References

(
URL
)

Details

(Keywords: intermittent-failure) 

Windows 7 32-bit mozilla-inbound debug test mochitest-1 on 2014-03-24 04:10:28 PDT for push e10a3c75e704

slave: t-w732-ix-034

https://tbpl.mozilla.org/php/getParsedLog.php?id=36597938&tree=Mozilla-Inbound



4854 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_new_audio.html | Test timed out.
Here is the event sequence I observed from the logs:

1. MediaDecoder::NotifyDownloadEnded is called for download is complete
2. MediaDecoder::ResourceLoaded is called by MediaDecoder::NotifyDownloadEnded
3. It returns immediately from ResourceLoaded for mPlayState is PLAY_STATE_LOADING
4. some unknown seek cause ChannelMediaResource to go back to offset 0
5. MediaDecoder::MetadataLoaded is called which won't call ResourceLoaded for the seeking in step 4
6. Download is complete again. MediaCacheStream::NotifyDataEnded will not call ChannelMediaResource::CacheClientNotifyDataEnded for |mDidNotifyDataEnded| is set true in last download complete.

It looks like we have to reset |mDidNotifyDataEnded| somewhere for ChannelMediaResource::CacheClientNotifyDataEnded can fire again. Does that make sense?
Assignee: nobody → jwwang
Flags: needinfo?(cpearce)
Btw, it looks suspicious to me that having to discard previous data in order to download later data. When you seek to position 0, you end up having to open a channel again to download data that is downloaded and discarded.
What's the actual failure here? What event are we not getting? canplaythrough?


(In reply to JW Wang[:jwwang] from comment #20)
> Here is the event sequence I observed from the logs:
> 
> 1. MediaDecoder::NotifyDownloadEnded is called for download is complete
> 2. MediaDecoder::ResourceLoaded is called by
> MediaDecoder::NotifyDownloadEnded
> 3. It returns immediately from ResourceLoaded for mPlayState is
> PLAY_STATE_LOADING
> 4. some unknown seek cause ChannelMediaResource to go back to offset 0

We're probably loading an Ogg file. For non-indexed Ogg files we seek to the end of stream, determine the timestamp there, and then seek to the start of stream. This is so that we can calculate the duration as $timestamp_at_end-$timestamp_at_start.


> 5. MediaDecoder::MetadataLoaded is called which won't call ResourceLoaded
> for the seeking in step 4

I'm not sure this is correct. I could be wrong, the code is convoluted.

Based on my reading of MediaDecoder::MetadataLoaded(), we will call ResourceLoaded() if notifyResourceIsLoaded is true, which is calculated as:

  bool notifyResourceIsLoaded = !mCalledResourceLoaded &&
                                IsDataCachedToEndOfResource();



> 6. Download is complete again. MediaCacheStream::NotifyDataEnded will not
> call ChannelMediaResource::CacheClientNotifyDataEnded for
> |mDidNotifyDataEnded| is set true in last download complete.
> 
> It looks like we have to reset |mDidNotifyDataEnded| somewhere for
> ChannelMediaResource::CacheClientNotifyDataEnded can fire again. Does that
> make sense?

I think we should be detecting when we've blocked calling ResourceLoaded in MetadataLoaded, like the current code is trying to do.
Flags: needinfo?(cpearce)
(In reply to Chris Pearce (:cpearce) from comment #22)
> What's the actual failure here? What event are we not getting?
> canplaythrough?

The failure is caused by timeout which is because autoplay is not activated.
Here is the event sequence:

1. MediaDecoder::NotifyDownloadEnded is called for download is complete
2. MediaDecoder::ResourceLoaded is called by MediaDecoder::NotifyDownloadEnded
3. It returns immediately from ResourceLoaded for mPlayState is PLAY_STATE_LOADING
4. Some unknown seek cause ChannelMediaResource to go back to offset 0 and open a new channel for download (in ChannelMediaResource::CacheClientSeek())
5. MediaDecoder::MetadataLoaded is called.
   bool notifyResourceIsLoaded = !mCalledResourceLoaded && IsDataCachedToEndOfResource();
   mCalledResourceLoaded is false for step 3
   IsDataCachedToEndOfResource() is also false for step 4
6. |notifyResourceIsLoaded| is false and ResourceLoaded() is not called.
7. MediaCacheStream::NotifyDataEnded
   It won't notify download ended for |mDidNotifyDataEnded| is set true in last download ended.
8. MediaDecoder is waiting in PLAY_STATE_PAUSED and autoplay can never activate for the media element.
(In reply to Chris Pearce (:cpearce) from comment #22)
> We're probably loading an Ogg file. For non-indexed Ogg files we seek to the
> end of stream, determine the timestamp there, and then seek to the start of
> stream. This is so that we can calculate the duration as
> $timestamp_at_end-$timestamp_at_start.
The test failed in playing owl.mp3.

> I'm not sure this is correct. I could be wrong, the code is convoluted.
> 
> Based on my reading of MediaDecoder::MetadataLoaded(), we will call
> ResourceLoaded() if notifyResourceIsLoaded is true, which is calculated as:
> 
>   bool notifyResourceIsLoaded = !mCalledResourceLoaded &&
>                                 IsDataCachedToEndOfResource();
> 
notifyResourceIsLoaded is false for IsDataCachedToEndOfResource() returns false for some unknown seeking to offset 0 which opens a new channel for downloading and cache needs to be refilled.

> I think we should be detecting when we've blocked calling ResourceLoaded in
> MetadataLoaded, like the current code is trying to do.
I think the problem is when ChannelMediaResource open a new channel, |mCacheStream| doesn't reset its state and still keeps the state left from the previous channel. That is why |mDidNotifyDataEnded| is not reset to false when a new channel is opened. I am think about turning |mCacheStream| into an AutoPtr so we don't need to add a reset() function to it.
Depends on: 1001317
Bug 1001317 should solve the autoplay problem.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1001317
You need to log in before you can comment on or make changes to this bug.