Bug 70448 – compositing/video tests time out on Lion

• Status: RESOLVED
• Resolution: FIXED
• Component: Media

[Simon Fraser (smfr)]

These two tests time out for me every time I run them on Lion:

+compositing/video/video-poster.html	expected actual diff pretty diff		text	pass
+compositing/video/video-with-invalid-source.html	expected actual diff pretty diff		text	pass

This is in DRT, so WebKit1. The tests also time out when run directly from DRT.

[Simon Fraser (smfr)]

Output with media logging turned on:

HTMLMediaElement::HTMLMediaElement
HTMLMediaElement::removedFromDocument
CONSOLE MESSAGE: line 31: event.type load
HTMLMediaElement::canPlayType(video/ogg) -> 
HTMLMediaElement::scheduleLoad
HTMLMediaElement::prepareForLoad
HTMLMediaElement::cancelPendingEventsAndCallbacks
HTMLMediaElement::setPlaybackRate(1.000000)
HTMLMediaElement::setShouldDelayLoadEvent(true)
HTMLMediaElement::selectMediaResource
HTMLMediaElement::loadResource(file:///Volumes/SSData/Development/OSX/webkit/OpenSource/LayoutTests/compositing/resources/video.mp4, )
HTMLMediaElement::loadResource - m_currentSrc -> file:///Volumes/SSData/Development/OSX/webkit/OpenSource/LayoutTests/compositing/resources/video.mp4
MediaPlayerPrivateAVFoundation::MediaPlayerPrivateAVFoundation(0x10b033760)
HTMLMediaElement::mediaPlayerEngineUpdated
Layer became composited, count=1
MediaPlayerPrivateAVFoundationObjC::platformLayer(0x10b033760)
MediaPlayerPrivateAVFoundation::load(0x10b033760)
HTMLMediaElement::setNetworkState(2) - current state is 2
MediaPlayerPrivateAVFoundationObjC::createAVAssetForURL(0x10b033760)
MediaPlayerPrivateAVFoundationObjC::checkPlayability(0x10b033760)
Layer lost compositing, count=0
HTMLMediaElement::selectMediaResource, using 'src' attribute url
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - notification 11
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - early return
MediaPlayerPrivateAVFoundation::mainThreadCallback(0x10b033760)
MediaPlayerPrivateAVFoundation::dispatchNotification(0x10b033760) - dispatching 11
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - entering with networkState = 2, readyState = 0
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - exiting with networkState = 2, readyState = 0
MediaPlayerPrivateAVFoundation::playabilityKnown(0x10b033760)
MediaPlayerPrivateAVFoundationObjC::beginLoadingMetadata(0x10b033760) - requesting metadata loading
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - notification 10
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - early return
MediaPlayerPrivateAVFoundation::mainThreadCallback(0x10b033760)
MediaPlayerPrivateAVFoundation::dispatchNotification(0x10b033760) - dispatching 10
HTMLMediaElement::mediaPlayerCharacteristicChanged
WebCoreAVFMovieObserver:tracksChanged(0x10b033760) - hasVideo = true, hasAudio = false, hasCaptions = false
MediaPlayerPrivateAVFoundation:setNaturalSize(0x10b033760) - size = 352 x 288
HTMLMediaElement::mediaPlayerSizeChanged
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - entering with networkState = 2, readyState = 0
MediaPlayerPrivateAVFoundation::prepareToPlay(0x10b033760)
MediaPlayerPrivateAVFoundationObjC::createAVPlayerItem(0x10b033760)
MediaPlayerPrivateAVFoundationObjC::createAVPlayer(0x10b033760)
HTMLMediaElement::setReadyState(1) - current state is 0,
HTMLMediaElement::updatePlayState - shouldBePlaying = false, playerPaused = true
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - exiting with networkState = 2, readyState = 1
WebCoreAVFMovieObserver:observeValueForKeyPath(0x10b02afa0) - keyPath = tracks
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - notification 2
MediaPlayerPrivateAVFoundation::dispatchNotification(0x10b033760) - dispatching 2
WebCoreAVFMovieObserver:tracksChanged(0x10b033760) - hasVideo = true, hasAudio = false, hasCaptions = false
MediaPlayerPrivateAVFoundation:setNaturalSize(0x10b033760) - size = 352 x 288
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - entering with networkState = 2, readyState = 1
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - exiting with networkState = 2, readyState = 1
WebCoreAVFMovieObserver:observeValueForKeyPath(0x10b02afa0) - keyPath = rate
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - notification 12
MediaPlayerPrivateAVFoundation::dispatchNotification(0x10b033760) - dispatching 12
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - entering with networkState = 2, readyState = 1
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - exiting with networkState = 2, readyState = 1
HTMLMediaElement::mediaPlayerRateChanged
HTMLMediaElement::invalidateCachedTime
HTMLMediaElement::invalidateCachedTime
WebCoreAVFMovieObserver:observeValueForKeyPath(0x10b02afa0) - keyPath = status
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - notification 3
MediaPlayerPrivateAVFoundation::dispatchNotification(0x10b033760) - dispatching 3
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - entering with networkState = 2, readyState = 1
MediaPlayerPrivateAVFoundation::duration(0x10b033760) - caching 0.995000
HTMLMediaElement::setNetworkState(3) - current state is 2
HTMLMediaElement::setReadyState(3) - current state is 1,
HTMLMediaElement::setShouldDelayLoadEvent(false)
HTMLMediaElement::updatePlayState - shouldBePlaying = false, playerPaused = true
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - exiting with networkState = 3, readyState = 3
WebCoreAVFMovieObserver:observeValueForKeyPath(0x10b02afa0) - keyPath = presentationSize
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x10b033760) - notification 6
MediaPlayerPrivateAVFoundation::dispatchNotification(0x10b033760) - dispatching 6
MediaPlayerPrivateAVFoundation:setNaturalSize(0x10b033760) - size = 352 x 288
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - entering with networkState = 3, readyState = 3
MediaPlayerPrivateAVFoundation::updateStates(0x10b033760) - exiting with networkState = 3, readyState = 3
FAIL: Timed out waiting for notifyDone to be called
FAIL: Timed out waiting for notifyDone to be called
Content-Type: text/plain
A <video> should not have a layer until playback begins.
This test can not be run manually, it requires layoutTestController.layerTreeAsText.

No src, no poster 
  PASS: wants layers = false, has layers = false


#EOF
HTMLMediaElement::stop
HTMLMediaElement::userCancelledLoad
HTMLMediaElement::cancelPendingEventsAndCallbacks
HTMLMediaElement::stop
HTMLMediaElement::userCancelledLoad
HTMLMediaElement::cancelPendingEventsAndCallbacks
HTMLMediaElement::~HTMLMediaElement
MediaPlayerPrivateAVFoundationObjC::cancelLoad(0x10b033760)
MediaPlayerPrivateAVFoundation::tearDownVideoRendering(0x10b033760)
MediaPlayerPrivateAVFoundationObjC::platformLayer(0x10b033760)
MediaPlayerPrivateAVFoundation::~MediaPlayerPrivateAVFoundation(0x10b033760)
Program ended with exit code: 0

[Simon Fraser (smfr)]

The 'canplaythrough' event never comes in.

[Simon Fraser (smfr)]

Looks like a bug in HTMLMediaElement::setReadyState()

[Jer Noble]

Created attachment 111705 [details]
Patch

[Eric Carlson]

Comment on attachment 111705 [details]
Patch

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

> Source/WebCore/ChangeLog:13
> +        AVFoundation will occasionally fill it's playback buffers before collecting enough
> +        statistical information to answer YES to isLikelyToKeepUp.  In this situation, set the
> +        ready state to HAVE_ENOUGH_DATA, on the presumption that if the playback buffers are
> +        full, playback will probably not stall.

It would be good to have this comment...

> Source/WebCore/platform/graphics/avfoundation/MediaPlayerPrivateAVFoundation.cpp:453
>              case MediaPlayerAVPlayerItemStatusPlaybackLikelyToKeepUp:
> +            case MediaPlayerAVPlayerItemStatusPlaybackBufferFull:

...here as well.

[Jer Noble]

Committed r97944: <http://trac.webkit.org/changeset/97944>

[Simon Fraser (smfr)]

Still failing for me:

HTMLMediaElement::HTMLMediaElement
HTMLMediaElement::removedFromDocument
HTMLMediaElement::canPlayType(video/ogg) -> 
HTMLMediaElement::scheduleLoad
HTMLMediaElement::prepareForLoad
HTMLMediaElement::cancelPendingEventsAndCallbacks
HTMLMediaElement::setPlaybackRate(1.000000)
HTMLMediaElement::setShouldDelayLoadEvent(true)
HTMLMediaElement::selectMediaResource
HTMLMediaElement::loadResource(file:///Volumes/SSData/Development/OSX/webkit/OpenSource/LayoutTests/compositing/resources/video.mp4, )
HTMLMediaElement::loadResource - m_currentSrc -> file:///Volumes/SSData/Development/OSX/webkit/OpenSource/LayoutTests/compositing/resources/video.mp4
MediaPlayerPrivateAVFoundation::MediaPlayerPrivateAVFoundation(0x107c0e5e0)
HTMLMediaElement::mediaPlayerEngineUpdated
MediaPlayerPrivateAVFoundationObjC::platformLayer(0x107c0e5e0)
MediaPlayerPrivateAVFoundation::load(0x107c0e5e0)
HTMLMediaElement::setNetworkState(2) - current state is 2
MediaPlayerPrivateAVFoundationObjC::createAVAssetForURL(0x107c0e5e0)
MediaPlayerPrivateAVFoundationObjC::checkPlayability(0x107c0e5e0)
HTMLMediaElement::selectMediaResource, using 'src' attribute url
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - notification 11
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - early return
MediaPlayerPrivateAVFoundation::mainThreadCallback(0x107c0e5e0)
MediaPlayerPrivateAVFoundation::dispatchNotification(0x107c0e5e0) - dispatching 11
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - entering with networkState = 2, readyState = 0
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - exiting with networkState = 2, readyState = 0
MediaPlayerPrivateAVFoundation::playabilityKnown(0x107c0e5e0)
MediaPlayerPrivateAVFoundationObjC::beginLoadingMetadata(0x107c0e5e0) - requesting metadata loading
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - notification 10
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - early return
MediaPlayerPrivateAVFoundation::mainThreadCallback(0x107c0e5e0)
MediaPlayerPrivateAVFoundation::dispatchNotification(0x107c0e5e0) - dispatching 10
HTMLMediaElement::mediaPlayerCharacteristicChanged
WebCoreAVFMovieObserver:tracksChanged(0x107c0e5e0) - hasVideo = true, hasAudio = false, hasCaptions = false
MediaPlayerPrivateAVFoundation:setNaturalSize(0x107c0e5e0) - size = 352 x 288
HTMLMediaElement::mediaPlayerSizeChanged
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - entering with networkState = 2, readyState = 0
MediaPlayerPrivateAVFoundation::prepareToPlay(0x107c0e5e0)
MediaPlayerPrivateAVFoundationObjC::createAVPlayerItem(0x107c0e5e0)
MediaPlayerPrivateAVFoundationObjC::createAVPlayer(0x107c0e5e0)
HTMLMediaElement::setReadyState(1) - current state is 0,
HTMLMediaElement::updatePlayState - shouldBePlaying = false, playerPaused = true
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - exiting with networkState = 2, readyState = 1
WebCoreAVFMovieObserver:observeValueForKeyPath(0x107c0d000) - keyPath = tracks
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - notification 2
MediaPlayerPrivateAVFoundation::dispatchNotification(0x107c0e5e0) - dispatching 2
WebCoreAVFMovieObserver:tracksChanged(0x107c0e5e0) - hasVideo = true, hasAudio = false, hasCaptions = false
MediaPlayerPrivateAVFoundation:setNaturalSize(0x107c0e5e0) - size = 352 x 288
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - entering with networkState = 2, readyState = 1
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - exiting with networkState = 2, readyState = 1
WebCoreAVFMovieObserver:observeValueForKeyPath(0x107c0d000) - keyPath = rate
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - notification 12
MediaPlayerPrivateAVFoundation::dispatchNotification(0x107c0e5e0) - dispatching 12
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - entering with networkState = 2, readyState = 1
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - exiting with networkState = 2, readyState = 1
HTMLMediaElement::mediaPlayerRateChanged
HTMLMediaElement::invalidateCachedTime
HTMLMediaElement::invalidateCachedTime
WebCoreAVFMovieObserver:observeValueForKeyPath(0x107c0d000) - keyPath = status
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - notification 3
MediaPlayerPrivateAVFoundation::dispatchNotification(0x107c0e5e0) - dispatching 3
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - entering with networkState = 2, readyState = 1
MediaPlayerPrivateAVFoundation::duration(0x107c0e5e0) - caching 0.995000
HTMLMediaElement::setNetworkState(3) - current state is 2
HTMLMediaElement::setReadyState(3) - current state is 1,
HTMLMediaElement::setShouldDelayLoadEvent(false)
HTMLMediaElement::updatePlayState - shouldBePlaying = false, playerPaused = true
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - exiting with networkState = 3, readyState = 3
WebCoreAVFMovieObserver:observeValueForKeyPath(0x107c0d000) - keyPath = presentationSize
MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(0x107c0e5e0) - notification 6
MediaPlayerPrivateAVFoundation::dispatchNotification(0x107c0e5e0) - dispatching 6
MediaPlayerPrivateAVFoundation:setNaturalSize(0x107c0e5e0) - size = 352 x 288
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - entering with networkState = 3, readyState = 3
MediaPlayerPrivateAVFoundation::updateStates(0x107c0e5e0) - exiting with networkState = 3, readyState = 3
FAIL: Timed out waiting for notifyDone to be called
FAIL: Timed out waiting for notifyDone to be called
Content-Type: text/plain
A <video> should not have a layer until playback begins.
This test can not be run manually, it requires layoutTestController.layerTreeAsText.

No src, no poster 
  PASS: wants layers = false, has layers = false


#EOF
HTMLMediaElement::stop
HTMLMediaElement::userCancelledLoad
HTMLMediaElement::cancelPendingEventsAndCallbacks
HTMLMediaElement::stop
HTMLMediaElement::userCancelledLoad
HTMLMediaElement::cancelPendingEventsAndCallbacks
HTMLMediaElement::~HTMLMediaElement
MediaPlayerPrivateAVFoundationObjC::cancelLoad(0x107c0e5e0)
MediaPlayerPrivateAVFoundation::tearDownVideoRendering(0x107c0e5e0)
MediaPlayerPrivateAVFoundationObjC::platformLayer(0x107c0e5e0)
MediaPlayerPrivateAVFoundation::~MediaPlayerPrivateAVFoundation(0x107c0e5e0)

[Jer Noble]

The poster test begins succeeding when you null out the <video> element's poster attribute; so yes, this patch probably doesn't fix that problem.  I'm looking into it more.

[Jer Noble]

Created attachment 112282 [details]
Patch

[Jer Noble]

Committed r98359: <http://trac.webkit.org/changeset/98359>