Bug 92881 - HTMLMediaElement may fire the seeked event before currentTime reaches the seek time
Summary: HTMLMediaElement may fire the seeked event before currentTime reaches the see...
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Media (show other bugs)
Version: 528+ (Nightly build)
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Ami Fischman
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-08-01 10:23 PDT by Victoria Kirst
Modified: 2012-08-05 17:54 PDT (History)
5 users (show)

See Also:


Attachments
Patch (8.60 KB, patch)
2012-08-01 14:25 PDT, Ami Fischman
no flags Details | Formatted Diff | Diff
Archive of layout-test-results from gce-cr-linux-04 (1.25 MB, application/zip)
2012-08-01 15:24 PDT, WebKit Review Bot
no flags Details
Patch (8.56 KB, patch)
2012-08-03 14:28 PDT, Ami Fischman
no flags Details | Formatted Diff | Diff
Archive of layout-test-results from gce-cq-01 (607.07 KB, application/zip)
2012-08-03 18:31 PDT, WebKit Review Bot
no flags Details
Archive of layout-test-results from gce-cr-linux-01 (369.64 KB, application/zip)
2012-08-03 19:45 PDT, WebKit Review Bot
no flags Details
Patch (8.54 KB, patch)
2012-08-03 23:47 PDT, Ami Fischman
no flags Details | Formatted Diff | Diff
Archive of layout-test-results from gce-cr-linux-02 (358.59 KB, application/zip)
2012-08-04 04:22 PDT, WebKit Review Bot
no flags Details
Patch (8.51 KB, patch)
2012-08-04 16:13 PDT, Ami Fischman
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Victoria Kirst 2012-08-01 10:23:14 PDT
This bug was uncovered when trying to make the media/video-seek-past-end-paused.html pass again.
(see reverted CL: https://bugs.webkit.org/show_bug.cgi?id=83505)

Here is the relevant code snippet:

    video.addEventListener('seeked', seeked);
    video.currentTime = 500;
    ...

    function seeked()
    {
      reportExpected(mediaElement.currentTime == mediaElement.duration, "mediaElement.currentTime", "==", "mediaElement.duration", mediaElement.currentTime);
    }

On certain platforms, currentTime is sometimes a number close to zero instead of being equal to the media element's duration. Seems like the problem may be that HTMLMediaElement::mediaPlayerTimeChanged() will consider a pending seek completed when mediaPlayerTimeChanged() is called. It does not check to make sure that the current time does indeed match the seek time. Needs more investigation.

(This bug does not appear to be chromium-specific, but there is a Chrome-side bug here as well: crbug.com/122448)
Comment 1 Ami Fischman 2012-08-01 14:25:41 PDT
Created attachment 155884 [details]
Patch
Comment 2 WebKit Review Bot 2012-08-01 15:24:51 PDT
Comment on attachment 155884 [details]
Patch

Attachment 155884 [details] did not pass chromium-ews (chromium-xvfb):
Output: http://queues.webkit.org/results/13415335

New failing tests:
media/media-fragments/TC0080-TC0089.html
media/media-fragments/TC0090-TC0099.html
media/media-fragments/TC0001-TC0009.html
media/media-fragments/TC0070-TC0079.html
media/media-fragments/TC0020-TC0029.html
media/media-fragments/TC0050-TC0059.html
Comment 3 WebKit Review Bot 2012-08-01 15:24:55 PDT
Created attachment 155900 [details]
Archive of layout-test-results from gce-cr-linux-04

The attached test failures were seen while running run-webkit-tests on the chromium-ews.
Bot: gce-cr-linux-04  Port: <class 'webkitpy.common.config.ports.ChromiumXVFBPort'>  Platform: Linux-2.6.39-gcg-201203291735-x86_64-with-Ubuntu-10.04-lucid
Comment 4 Eric Carlson 2012-08-02 13:39:28 PDT
Comment on attachment 155884 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=155884&action=review

> LayoutTests/media/video-seek-past-end-paused.html:30
> +                // wait 2 timeupdate events so we are sure the media engine is
> +                // playing the media.

Minor nit: I would prefer to have comments-as-sentences as we do in WebKit proper. Here and throughout the file.
Comment 5 Ami Fischman 2012-08-03 14:28:18 PDT
Created attachment 156457 [details]
Patch
Comment 6 Ami Fischman 2012-08-03 14:28:52 PDT
(In reply to comment #4)
> (From update of attachment 155884 [details])
> View in context: https://bugs.webkit.org/attachment.cgi?id=155884&action=review
> 
> > LayoutTests/media/video-seek-past-end-paused.html:30
> > +                // wait 2 timeupdate events so we are sure the media engine is
> > +                // playing the media.
> 
> Minor nit: I would prefer to have comments-as-sentences as we do in WebKit proper. Here and throughout the file.

Done.  Thanks for the quick review.
Comment 7 WebKit Review Bot 2012-08-03 18:31:39 PDT
Comment on attachment 156457 [details]
Patch

Rejecting attachment 156457 [details] from commit-queue.

New failing tests:
media/media-fragments/TC0080-TC0089.html
media/media-fragments/TC0090-TC0099.html
media/media-fragments/TC0001-TC0009.html
http/tests/cache/post-redirect-get.php
media/media-fragments/TC0070-TC0079.html
media/media-fragments/TC0020-TC0029.html
http/tests/cache/post-with-cached-subresources.php
media/media-fragments/TC0050-TC0059.html
Full output: http://queues.webkit.org/results/13438004
Comment 8 WebKit Review Bot 2012-08-03 18:31:43 PDT
Created attachment 156498 [details]
Archive of layout-test-results from gce-cq-01

The attached test failures were seen while running run-webkit-tests on the commit-queue.
Bot: gce-cq-01  Port: <class 'webkitpy.common.config.ports.ChromiumXVFBPort'>  Platform: Linux-2.6.39-gcg-201203291735-x86_64-with-Ubuntu-10.04-lucid
Comment 9 WebKit Review Bot 2012-08-03 19:45:07 PDT
Comment on attachment 156457 [details]
Patch

Attachment 156457 [details] did not pass chromium-ews (chromium-xvfb):
Output: http://queues.webkit.org/results/13423984

New failing tests:
media/media-fragments/TC0080-TC0089.html
media/media-fragments/TC0090-TC0099.html
media/media-fragments/TC0001-TC0009.html
media/media-fragments/TC0070-TC0079.html
media/media-fragments/TC0020-TC0029.html
media/media-fragments/TC0050-TC0059.html
Comment 10 WebKit Review Bot 2012-08-03 19:45:11 PDT
Created attachment 156507 [details]
Archive of layout-test-results from gce-cr-linux-01

The attached test failures were seen while running run-webkit-tests on the chromium-ews.
Bot: gce-cr-linux-01  Port: <class 'webkitpy.common.config.ports.ChromiumXVFBPort'>  Platform: Linux-2.6.39-gcg-201203291735-x86_64-with-Ubuntu-10.04-lucid
Comment 11 Ami Fischman 2012-08-03 23:47:24 PDT
Created attachment 156518 [details]
Patch
Comment 12 WebKit Review Bot 2012-08-04 04:22:50 PDT
Comment on attachment 156518 [details]
Patch

Attachment 156518 [details] did not pass chromium-ews (chromium-xvfb):
Output: http://queues.webkit.org/results/13437200

New failing tests:
media/media-fragments/TC0011.html
media/media-fragments/TC0055.html
fast/loader/unload-form-post-about-blank.html
fast/frames/cached-frame-counter.html
media/media-fragments/TC0038.html
media/media-fragments/TC0006.html
media/media-fragments/TC0004.html
http/tests/xmlhttprequest/zero-length-response.html
http/tests/security/script-crossorigin-loads-correctly.html
platform/chromium/virtual/gpu/fast/canvas/webgl/shader-precision-format.html
fast/loader/loadInProgress.html
fast/canvas/webgl/shader-precision-format.html
media/media-fragments/TC0053.html
media/media-fragments/TC0039.html
media/media-fragments/TC0024.html
media/media-fragments/TC0015.html
media/media-fragments/TC0036.html
media/media-fragments/TC0017.html
media/media-fragments/TC0059.html
media/media-fragments/TC0072.html
media/media-fragments/TC0051.html
media/media-fragments/TC0078.html
media/media-fragments/TC0005.html
media/media-fragments/TC0054.html
media/media-fragments/TC0037.html
media/media-fragments/TC0035.html
media/media-fragments/TC0052.html
Comment 13 WebKit Review Bot 2012-08-04 04:22:54 PDT
Created attachment 156529 [details]
Archive of layout-test-results from gce-cr-linux-02

The attached test failures were seen while running run-webkit-tests on the chromium-ews.
Bot: gce-cr-linux-02  Port: <class 'webkitpy.common.config.ports.ChromiumXVFBPort'>  Platform: Linux-2.6.39-gcg-201203291735-x86_64-with-Ubuntu-10.04-lucid
Comment 14 Ami Fischman 2012-08-04 16:13:47 PDT
Created attachment 156540 [details]
Patch
Comment 15 Ami Fischman 2012-08-04 16:16:19 PDT
It was crazy to use == on floating-point values, and doubly so when one of the values is the timestamp of a frame and the other is a (massaged) user-supplied value; the test failures from the cr-linux bot demonstrate that it's easy to cook up scenarios like: current: 6.50022, lastSeekTime: 6.5.

Updated patch instead inspects m_player->seeking() to decide whether the seek is complete.
Comment 16 Eric Carlson 2012-08-04 20:18:11 PDT
(In reply to comment #15)
> It was crazy to use == on floating-point values, and doubly so when one of the values is the timestamp of a frame and the other is a (massaged) user-supplied value; the test failures from the cr-linux bot demonstrate that it's easy to cook up scenarios like: current: 6.50022, lastSeekTime: 6.5.
> 
  That *should* have worked. HTMLMediaElement::seek asks the media engine to translate the user supplied seek time into the nearest time in the media container's timescale:

    time = m_player->mediaTimeForTimeValue(time)
    . . .
    m_lastSeekTime = time

so m_player->currentTime() should be the same once seeking has completed.
Comment 17 WebKit Review Bot 2012-08-04 20:24:06 PDT
Comment on attachment 156540 [details]
Patch

Clearing flags on attachment: 156540

Committed r124713: <http://trac.webkit.org/changeset/124713>
Comment 18 WebKit Review Bot 2012-08-04 20:24:11 PDT
All reviewed patches have been landed.  Closing bug.
Comment 19 Ami Fischman 2012-08-04 20:30:51 PDT
(In reply to comment #16)
> (In reply to comment #15)
> > It was crazy to use == on floating-point values, and doubly so when one of the values is the timestamp of a frame and the other is a (massaged) user-supplied value; the test failures from the cr-linux bot demonstrate that it's easy to cook up scenarios like: current: 6.50022, lastSeekTime: 6.5.
> > 
>   That *should* have worked. HTMLMediaElement::seek asks the media engine to translate the user supplied seek time into the nearest time in the media container's timescale

For the record, the chromium impl of mediaTimeForTimeValue is only concerned with pure-math rounding effects.  It doesn't inspect the media's framerate or anything like that.

I wonder if that in itself is a bug in chromium's WebMediaPlayerImpl, and if it is how it could be observed from a layouttest.
Comment 20 Eric Carlson 2012-08-05 14:08:35 PDT
(In reply to comment #19)
> 
> For the record, the chromium impl of mediaTimeForTimeValue is only concerned with pure-math rounding effects.  It doesn't inspect the media's framerate or anything like that.
> 
> I wonder if that in itself is a bug in chromium's WebMediaPlayerImpl, and if it is how it could be observed from a layouttest.

I would definitely call that a bug. The intent of the API is to convert an arbitrary floating point time value into the closest value that exists in the current media resource's time scale. It was added specifically for problems with seeking, see https://bugs.webkit.org/show_bug.cgi?id=48530.

I think you could create a test that uses a media file format that has rational time values, eg. a QuickTime or MPEG-4 file (not sure about WebM), seek to a time value that is not a multiple of the file's time scale, and check the current time after a seek.
Comment 21 Ami Fischman 2012-08-05 17:54:00 PDT
(In reply to comment #20)
> (In reply to comment #19)
> > 
> > For the record, the chromium impl of mediaTimeForTimeValue is only concerned with pure-math rounding effects.  It doesn't inspect the media's framerate or anything like that.
> > 
> > I wonder if that in itself is a bug in chromium's WebMediaPlayerImpl, and if it is how it could be observed from a layouttest.
> 
> I would definitely call that a bug. The intent of the API is to convert an arbitrary floating point time value into the closest value that exists in the current media resource's time scale. It was added specifically for problems with seeking, see https://bugs.webkit.org/show_bug.cgi?id=48530.

Thanks for the background.

> I think you could create a test that uses a media file format that has rational time values, eg. a QuickTime or MPEG-4 file (not sure about WebM), seek to a time value that is not a multiple of the file's time scale, and check the current time after a seek.

What would you be looking for the current time to be to test the bug?  My point was that chromium's MediaPlayer implementation (WebMediaPlayerImpl) does the right thing in terms of the seek ('seeked' is fired after the seek is complete, with currentTime being the timestamp of the first frame >= the seek target), so between WMPI & HTMLMediaElement, the layouttest can't observe anything going wrong.

Also, not knowing the vagaries of media containers very well, I wonder whether it's really possible to answer the contract you expect of mediaTimeForTimeValue.  Can't frames in common formats (webm, mp4) have pretty much arbitrary timestamps?
Perhaps put another way: what's a "time scale"?  I assumed you were using it in terms of frame rate, but the CL linked above states: "test.mp4 has a time scale of 2500, 0.0004 seconds".  IIUC you're suggesting that a MediaPlayer playing this test.mp4 (test-25fps.mp4 nowadays?) should return 0.0396 when asked mediaTimeForTimeValue(0.0396), but have a currentTime of 0.04 when the seeked event fires?  That would still not allow reverting to the float== test to determine when to call HTMLMediaElement::finishSeek().