Simplify http/tests/media/video-play-stall.html

https://bugs.webkit.org/show_bug.cgi?id=140630

Reviewed by Brent Fulgham.

Source/WebCore:

Test: http/tests/media/video-play-waiting.html

* platform/graphics/avfoundation/MediaPlayerPrivateAVFoundation.cpp:
(WebCore::MediaPlayerPrivateAVFoundation::play): Add more logging.
(WebCore::MediaPlayerPrivateAVFoundation::updateStates): MediaPlayerAVPlayerItemStatusPlaybackBufferEmpty
    always maps to HaveCurrentData.
(WebCore::MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification): Don't log FunctionType,
    doing so it needlessly verbose.
(WebCore::MediaPlayerPrivateAVFoundation::dispatchNotification): Ditto.
* platform/graphics/avfoundation/objc/MediaPlayerPrivateAVFoundationObjC.mm:
(-[WebCoreAVFMovieObserver observeValueForKeyPath:ofObject:change:context:]): Log KVO property
    values and notification state.

LayoutTests:

* http/tests/media/video-play-stall-expected.txt:
* http/tests/media/video-play-stall.html:
* http/tests/media/video-play-waiting-expected.txt: Added.
* http/tests/media/video-play-waiting.html: Added.
* media/content/long-test.mp4: Added. New media file with 30 second duration.
* media/content/long-test.ogv: Ditto.
* platform/mac/TestExpectations: Remove video-play-stall.html from the skip list. Mark
    video-play-waiting.html as flakey as it sometimes times out.


Canonical link: https://commits.webkit.org/158951@main
git-svn-id: https://svn.webkit.org/repository/webkit/trunk@179220 268f45cc-cd09-0410-ab3c-d52691b4dbfc

LayoutTests/ChangeLog

@@ -1,3 +1,19 @@
+2015-01-27  Eric Carlson  <eric.carlson@apple.com>
+
+        Simplify http/tests/media/video-play-stall.html
+        https://bugs.webkit.org/show_bug.cgi?id=140630
+
+        Reviewed by Brent Fulgham.
+
+        * http/tests/media/video-play-stall-expected.txt:
+        * http/tests/media/video-play-stall.html:
+        * http/tests/media/video-play-waiting-expected.txt: Added.
+        * http/tests/media/video-play-waiting.html: Added.
+        * media/content/long-test.mp4: Added. New media file with 30 second duration.
+        * media/content/long-test.ogv: Ditto.
+        * platform/mac/TestExpectations: Remove video-play-stall.html from the skip list. Mark 
+            video-play-waiting.html as flakey as it sometimes times out.
+
 2015-01-27  Brent Fulgham  <bfulgham@apple.com>
 
         [Win] Another round of bug filing and expectation updates.

LayoutTests/http/tests/media/video-play-stall-expected.txt

@@ -1,12 +1,14 @@
-Test that stalled, timeupdate and waiting events are sent when media load stalls in the middle.
 
-RUN(video.play())
+Test that a stalled event is sent when media loading stalls.
+
 EVENT(durationchange)
 EVENT(loadedmetadata)
 EVENT(loadeddata)
 EVENT(canplay)
-EVENT(timeupdate)
-EVENT(waiting)
+RUN(video.play())
 EVENT(stalled)
+EXPECTED (video.currentTime != '0') OK
+EXPECTED (video.playbackRate === '1') OK
+EXPECTED (video.paused === 'false') OK
 END OF TEST
 

LayoutTests/http/tests/media/video-play-stall.html

@@ -1,41 +1,45 @@
-<video></video>
-<p>Test that stalled, timeupdate and waiting events are sent when media load stalls in the middle.</p>
-<script src=../../media-resources/media-file.js></script>
-<script src=../../media-resources/video-test.js></script>
-<script>
-
-    var timeupdateCount = 0;
-    var waitingCount = 0;
-
-    waitForEvent('durationchange');
-    waitForEvent('loadedmetadata');
-    waitForEvent('loadeddata');
-    waitForEvent('canplaythrough');
-    waitForEvent('canplay', function () {
-
-        mediaElement.addEventListener('timeupdate', function () {
-            // timeupdate events are fired as playback progresses so only verify that at least one
-            // event is fired
-            ++timeupdateCount;
-            if (timeupdateCount == 1)
-                consoleWrite("EVENT(timeupdate)");
-        } );
-
-        waitForEvent('waiting', function () {
-            ++waitingCount;
-            if (waitingCount > 1)
-                failTest("too many 'waiting' events fired.");
-
-            waitForEvent('timeupdate');
-        } );
-
-        waitForEventAndEnd('stalled');
-    } );
-
-    // Find a supported media file.
-    var mediaFile = findMediaFile("video", "content/test");
-    var mimeType = mimeTypeForFile(mediaFile);
-
-    video.src = "http://127.0.0.1:8000/resources/load-and-stall.cgi?name=../../../media/" + mediaFile + "&mimeType=" + mimeType + "&stallAt=100000&stallFor=6";
-    run("video.play()");
-</script>
+<!DOCTYPE html>
+<html>
+    <head>
+        <title>'stalled' event test</title>
+        <script src=../../media-resources/media-file.js></script>
+        <script src=../../media-resources/video-test.js></script>
+        <script>
+
+            var playCount = 0;
+
+            function start() 
+            {
+                findMediaElement();
+                waitForEvent('durationchange');
+                waitForEvent('loadedmetadata');
+                waitForEvent('loadeddata');
+
+                mediaElement.addEventListener('canplay', function () {
+                    // 'stalled' takes three seconds to fire, so 'canplay' may fire more than once
+                    // depending on how the engine parses incoming media data.
+                    if (++playCount > 1)
+                        return;
+                    consoleWrite("EVENT(canplay)");
+                    run("video.play()");
+                } );
+
+                waitForEvent('stalled', function () {
+                    testExpected("video.currentTime", 0, "!=");
+                    testExpected("video.playbackRate", 1, "===");
+                    testExpected("video.paused", false, "===");
+                    endTest();
+                } );
+
+                var mediaFile = findMediaFile("video", "../../../../media/content/long-test");
+                var mimeType = mimeTypeForFile(mediaFile);
+                video.src = "http://127.0.0.1:8000/media/resources/serve-video.php?name=" + mediaFile + "&type=" + mimeType + "&stallOffset=100000&stallDuration=60&chunkSize=1024";
+            }
+
+        </script>
+    </head>
+    <body onload="start()">
+        <video controls></video>
+        <p>Test that a stalled event is sent when media loading stalls.</p>
+    </body>
+</html>

LayoutTests/http/tests/media/video-play-waiting-expected.txt

@@ -0,0 +1,12 @@
+
+Test that a waiting event is sent when media loading stalls after having sent 'canplay'.
+
+EVENT(durationchange)
+EVENT(loadedmetadata)
+EVENT(loadeddata)
+EVENT(canplay)
+RUN(video.play())
+EVENT(timeupdate)
+EVENT(waiting)
+END OF TEST
+

LayoutTests/http/tests/media/video-play-waiting.html

@@ -0,0 +1,30 @@
+<video controls></video>
+<p>Test that a waiting event is sent when media loading stalls after having sent 'canplay'.</p>
+<script src=../../media-resources/media-file.js></script>
+<script src=../../media-resources/video-test.js></script>
+<script>
+
+    var timeupdateCount = 0;
+
+    waitForEvent('durationchange');
+    waitForEvent('loadedmetadata');
+    waitForEvent('loadeddata');
+    waitForEventAndEnd('waiting');
+
+    waitForEvent('canplay', function () {
+        run("video.play()");
+    } );
+
+    mediaElement.addEventListener('timeupdate', function () {
+        // 'timeupdate' events are also fired as playback progresses so only verify that at least one
+        // event is fired.
+        if (++timeupdateCount == 1)
+            consoleWrite("EVENT(timeupdate)");
+    } );
+
+    // Find a supported media file.
+    var mediaFile = findMediaFile("video", "../../../../media/content/long-test");
+    var mimeType = mimeTypeForFile(mediaFile);
+
+    video.src = "http://127.0.0.1:8000/media/resources/serve-video.php?name=" + mediaFile + "&type=" + mimeType + "&stallOffset=100000&stallDuration=60&chunkSize=1024";
+</script>

LayoutTests/platform/mac/TestExpectations

@@ -1064,9 +1064,10 @@ webkit.org/b/112492 media/track/track-language-preference.html [ Skip ]
 webkit.org/b/112492 media/track/track-prefer-captions.html [ Skip ]
 
 webkit.org/b/136708 http/tests/media/video-play-stall-seek.html
-webkit.org/b/136708 http/tests/media/video-play-stall.html
 webkit.org/b/136708 media/media-fullscreen-not-in-document.html
 
+webkit.org/b/140639 http/tests/media/video-play-waiting.html [ Pass Timeout ]
+
 # This test requires generation of progress events during loading
 webkit.org/b/100984 media/progress-events-generated-correctly.html [ Failure ]
 

Source/WebCore/ChangeLog

@@ -1,3 +1,23 @@
+2015-01-27  Eric Carlson  <eric.carlson@apple.com>
+
+        Simplify http/tests/media/video-play-stall.html
+        https://bugs.webkit.org/show_bug.cgi?id=140630
+
+        Reviewed by Brent Fulgham.
+
+        Test: http/tests/media/video-play-waiting.html
+
+        * platform/graphics/avfoundation/MediaPlayerPrivateAVFoundation.cpp:
+        (WebCore::MediaPlayerPrivateAVFoundation::play): Add more logging.
+        (WebCore::MediaPlayerPrivateAVFoundation::updateStates): MediaPlayerAVPlayerItemStatusPlaybackBufferEmpty
+            always maps to HaveCurrentData.
+        (WebCore::MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification): Don't log FunctionType,
+            doing so it needlessly verbose.
+        (WebCore::MediaPlayerPrivateAVFoundation::dispatchNotification): Ditto.
+        * platform/graphics/avfoundation/objc/MediaPlayerPrivateAVFoundationObjC.mm:
+        (-[WebCoreAVFMovieObserver observeValueForKeyPath:ofObject:change:context:]): Log KVO property 
+            values and notification state.
+
 2015-01-27  Commit Queue  <commit-queue@webkit.org>
 
         Unreviewed, rolling out r179192.

Source/WebCore/platform/graphics/avfoundation/MediaPlayerPrivateAVFoundation.cpp

@@ -229,8 +229,10 @@ void MediaPlayerPrivateAVFoundation::play()
     // or the audio may start playing before we can render video.
     if (!m_cachedHasVideo || hasAvailableVideoFrame())
         platformPlay();
-    else
+    else {
+        LOG(Media, "MediaPlayerPrivateAVFoundation::play(%p) - waiting for first video frame", this);
         m_playWhenFramesAvailable = true;
+    }
 }
 
 void MediaPlayerPrivateAVFoundation::pause()
@@ -523,16 +525,12 @@ void MediaPlayerPrivateAVFoundation::updateStates()
                 break;
 
             case MediaPlayerAVPlayerItemStatusReadyToPlay:
-                // If the readyState is already HaveEnoughData, don't go lower because of this state change.
-                if (m_readyState == MediaPlayer::HaveEnoughData)
-                    break;
-                FALLTHROUGH;
+                if (m_readyState != MediaPlayer::HaveEnoughData && maxTimeLoaded() > currentMediaTime())
+                    m_readyState = MediaPlayer::HaveFutureData;
+                break;
 
             case MediaPlayerAVPlayerItemStatusPlaybackBufferEmpty:
-                if (maxTimeLoaded() > currentMediaTime())
-                    m_readyState = MediaPlayer::HaveFutureData;
-                else
-                    m_readyState = MediaPlayer::HaveCurrentData;
+                m_readyState = MediaPlayer::HaveCurrentData;
                 break;
             }
 
@@ -782,10 +780,12 @@ static const char* notificationName(MediaPlayerPrivateAVFoundation::Notification
 
 void MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(Notification notification)
 {
-    LOG(Media, "MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(%p) - notification %s", this, notificationName(notification));
+    if (notification.type() != Notification::FunctionType)
+        LOG(Media, "MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(%p) - notification %s", this, notificationName(notification));
+
     m_queueMutex.lock();
 
-    // It is important to always process the properties in the order that we are notified, 
+    // It is important to always process the properties in the order that we are notified,
     // so always go through the queue because notifications happen on different threads.
     m_queuedNotifications.append(notification);
 
@@ -802,7 +802,8 @@ void MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(Notification
     m_queueMutex.unlock();
 
     if (delayDispatch) {
-        LOG(Media, "MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(%p) - early return", this);
+        if (notification.type() != Notification::FunctionType)
+            LOG(Media, "MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(%p) - early return", this);
         return;
     }
 
@@ -833,7 +834,8 @@ void MediaPlayerPrivateAVFoundation::dispatchNotification()
             return;
     }
 
-    LOG(Media, "MediaPlayerPrivateAVFoundation::dispatchNotification(%p) - dispatching %s", this, notificationName(notification));
+    if (notification.type() != Notification::FunctionType)
+        LOG(Media, "MediaPlayerPrivateAVFoundation::dispatchNotification(%p) - dispatching %s", this, notificationName(notification));
 
     switch (notification.type()) {
     case Notification::ItemDidPlayToEndTime:

Source/WebCore/platform/graphics/avfoundation/objc/MediaPlayerPrivateAVFoundationObjC.mm

@@ -2941,13 +2941,20 @@ - (void)observeValueForKeyPath:keyPath ofObject:(id)object change:(NSDictionary
     UNUSED_PARAM(object);
     id newValue = [change valueForKey:NSKeyValueChangeNewKey];
 
-    LOG(Media, "WebCoreAVFMovieObserver::observeValueForKeyPath(%p) - keyPath = %s", self, [keyPath UTF8String]);
-
     if (!m_callback)
         return;
 
     bool willChange = [[change valueForKey:NSKeyValueChangeNotificationIsPriorKey] boolValue];
 
+#if !LOG_DISABLED
+    if (willChange)
+        LOG(Media, "WebCoreAVFMovieObserver::observeValueForKeyPath(%p) - will change, keyPath = %s", self, [keyPath UTF8String]);
+    else {
+        RetainPtr<NSString> valueString = adoptNS([[NSString alloc] initWithFormat:@"%@", newValue]);
+        LOG(Media, "WebCoreAVFMovieObserver::observeValueForKeyPath(%p) - did change, keyPath = %s, value = %s", self, [keyPath UTF8String], [valueString.get() UTF8String]);
+    }
+#endif
+
     WTF::Function<void ()> function;
 
     if (context == MediaPlayerAVFoundationObservationContextAVPlayerLayer) {