Open Bug 1075573 Opened 5 years ago Updated 3 years ago

Intermittent widgets/test_videocontrols_standalone.html | Test timed out. - expected PASS

Categories

(Core :: Widget, defect, P3)

ARM
Android
defect

Tracking

()

Tracking Status
firefox35 --- unaffected
firefox36 --- disabled
firefox37 --- disabled
firefox38 --- disabled
firefox-esr31 --- unaffected

People

(Reporter: cbook, Unassigned)

References

()

Details

(Keywords: intermittent-failure, Whiteboard: tpi:-)

Attachments

(1 file)

Android 2.3 Emulator mozilla-inbound opt test mochitest-16

https://treeherder.mozilla.org/ui/logviewer.html#?job_id=2680994&repo=mozilla-inbound

06:50:04 INFO - 338 INFO TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_standalone.html | Test timed out. - expected PASS
:wesj -- It was months ago, but you were the last one to touch this test. Can you tell what's going wrong? It is failing very frequently, on Android only.
Flags: needinfo?(wjohnston)
From http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/fd567ae3c782deaee8b432022f5a574b85e8bee5e92b360d52ef175fa461ae2d5d45f172966d760c94f6dddeb90744a4f7356ab79c334bb7214837ef772956eb:

11-26 10:04:00.625 I/GeckoDump(  584): ⰲ겿{"action":"test_start","time":1417025040603,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/toolkit/content/tests/widgets/test_videocontrols_standalone.html"}ⰲ겿
11-26 10:04:02.475 D/GeckoTabs(  584): handleMessage: Tab:Added
11-26 10:04:02.505 D/GeckoToolbar(  584): onTabChanged: MENU_UPDATED
11-26 10:04:02.505 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: MENU_UPDATED
11-26 10:04:02.505 D/GeckoToolbar(  584): onTabChanged: ADDED
11-26 10:04:02.505 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: ADDED
11-26 10:04:02.605 D/GeckoTabs(  584): handleMessage: Content:StateChange
11-26 10:04:02.757 D/GeckoToolbar(  584): onTabChanged: SELECTED
11-26 10:04:02.782 D/GeckoToolbarDisplayLayout(  584): updateFavicon(null)
11-26 10:04:02.816 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: SELECTED
11-26 10:04:02.845 D/GeckoToolbar(  584): onTabChanged: UNSELECTED
11-26 10:04:02.845 D/GeckoTabs(  584): handleMessage: Content:StateChange
11-26 10:04:02.855 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 0: UNSELECTED
11-26 10:04:02.885 D/GeckoToolbar(  584): onTabChanged: MENU_UPDATED
11-26 10:04:02.895 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: MENU_UPDATED
11-26 10:04:02.895 D/GeckoToolbar(  584): onTabChanged: START
11-26 10:04:02.895 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: START
11-26 10:04:03.349 D/GeckoTabs(  584): handleMessage: Content:LocationChange
11-26 10:04:03.395 D/GeckoThumbnailHelper(  584): Using new thumbnail size: 58240 (width 160 - height 91)
11-26 10:04:03.395 D/GeckoThumbnailHelper(  584): Sending thumbnail event: 160, 91
11-26 10:04:03.406 D/GeckoTabs(  584): handleMessage: Content:SecurityChange
11-26 10:04:03.665 D/GeckoTabs(  584): handleMessage: Content:StateChange
11-26 10:04:03.749 W/GeckoConsole(  584): [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "http://mochi.test:8888/tests/toolkit/content/tests/widgets/test_videocontrols_standalone.html" line: 0}]
11-26 10:04:04.066 D/GeckoToolbar(  584): onTabChanged: STOP
11-26 10:04:04.066 I/GeckoToolbarDisplayLayout(  584): zerdatime 2297339 - Throbber start
11-26 10:04:04.105 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: STOP
11-26 10:04:04.285 D/GeckoTabs(  584): handleMessage: Tab:ViewportMetadata
11-26 10:04:04.816 D/GeckoToolbar(  584): onTabChanged: MENU_UPDATED
11-26 10:04:04.816 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: MENU_UPDATED
11-26 10:04:04.816 D/GeckoToolbar(  584): onTabChanged: LOCATION_CHANGE
11-26 10:04:04.816 D/GeckoToolbarDisplayLayout(  584): updateFavicon(null)
11-26 10:04:04.825 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: LOCATION_CHANGE
11-26 10:04:04.825 D/GeckoToolbar(  584): onTabChanged: SECURITY_CHANGE
11-26 10:04:04.845 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: SECURITY_CHANGE
11-26 10:04:04.845 D/GeckoToolbar(  584): onTabChanged: MENU_UPDATED
11-26 10:04:04.845 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: MENU_UPDATED
11-26 10:04:04.877 D/GeckoToolbar(  584): onTabChanged: START
11-26 10:04:04.877 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: START
11-26 10:04:05.015 D/GeckoToolbar(  584): onTabChanged: VIEWPORT_CHANGE
11-26 10:04:05.015 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: VIEWPORT_CHANGE
11-26 10:04:06.866 I/AndroidMediaPluginHost(  584): Android Version is: 10
11-26 10:04:06.866 I/AndroidMediaPluginHost(  584): Android Release Version is: 2.3.7
11-26 10:04:06.881 I/AndroidMediaPluginHost(  584): Android Device is: sdk
11-26 10:04:06.881 I/AndroidMediaPluginHost(  584): Android Manufacturer is: unknown
11-26 10:04:06.885 I/AndroidMediaPluginHost(  584): Android Hardware is: goldfish
11-26 10:04:06.897 I/AndroidMediaPluginHost(  584): Loading OMX Plugin: nullptr
11-26 10:04:07.285 D/GeckoTabs(  584): handleMessage: Content:LocationChange
11-26 10:04:07.385 D/GeckoTabs(  584): handleMessage: Content:SecurityChange
11-26 10:04:07.485 D/GeckoToolbar(  584): onTabChanged: TITLE
11-26 10:04:07.515 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: TITLE
11-26 10:04:07.529 D/GeckoToolbar(  584): onTabChanged: MENU_UPDATED
11-26 10:04:07.529 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: MENU_UPDATED
11-26 10:04:07.539 D/GeckoToolbar(  584): onTabChanged: LOCATION_CHANGE
11-26 10:04:07.539 D/GeckoToolbarDisplayLayout(  584): updateFavicon(null)
11-26 10:04:07.556 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: LOCATION_CHANGE
11-26 10:04:07.556 D/GeckoToolbar(  584): onTabChanged: MENU_UPDATED
11-26 10:04:07.556 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: MENU_UPDATED
11-26 10:04:07.577 D/GeckoToolbar(  584): onTabChanged: SECURITY_CHANGE
11-26 10:04:07.577 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: SECURITY_CHANGE
11-26 10:04:09.705 I/SUTAgentAndroid(  302): 10.0.2.2 : activity
11-26 10:04:10.529 D/dalvikvm(  302): GC_EXPLICIT freed 10K, 52% free 2815K/5767K, external 716K/1038K, paused 771ms
11-26 10:04:12.798 D/GeckoTabs(  584): handleMessage: DOMTitleChanged
11-26 10:04:12.798 D/GeckoToolbar(  584): onTabChanged: TITLE
11-26 10:04:12.865 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: TITLE
11-26 10:04:14.137 D/GeckoTabs(  584): handleMessage: Tab:ViewportMetadata
11-26 10:04:14.145 D/GeckoToolbar(  584): onTabChanged: VIEWPORT_CHANGE
11-26 10:04:14.145 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: VIEWPORT_CHANGE
11-26 10:04:14.317 D/GeckoTabs(  584): handleMessage: Tab:ViewportMetadata
11-26 10:04:14.317 D/GeckoToolbar(  584): onTabChanged: VIEWPORT_CHANGE
11-26 10:04:14.317 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: VIEWPORT_CHANGE
11-26 10:04:14.817 W/AudioFlinger(   37): write blocked for 96 msecs, 2 delayed writes, thread 0xc658
11-26 10:04:17.865 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:17.885 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:17.915 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:17.935 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:17.945 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:17.955 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:17.985 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:18.015 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:18.026 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:18.045 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:18.055 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:18.075 D/GeckoLayerClient(  584): Aborting draw due to resolution change: 1.0 != 1.0448979
11-26 10:04:19.718 D/GeckoTabs(  584): handleMessage: Content:PageShow
11-26 10:04:19.718 D/GeckoToolbar(  584): onTabChanged: PAGE_SHOW
11-26 10:04:19.718 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: PAGE_SHOW
11-26 10:04:20.169 E/LoadFaviconTask(  584): Error reading favicon
11-26 10:04:20.169 E/LoadFaviconTask(  584): java.net.UnknownHostException: mochi.test
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at java.net.InetAddress.lookupHostByName(InetAddress.java:506)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at java.net.InetAddress.getAllByNameImpl(InetAddress.java:294)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at java.net.InetAddress.getAllByName(InetAddress.java:256)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:136)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:164)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:119)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:359)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:555)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:487)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:465)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at android.net.http.AndroidHttpClient.execute(AndroidHttpClient.java:243)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.tryDownloadRecurse(LoadFaviconTask.java:128)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.downloadAndDecodeImage(LoadFaviconTask.java:245)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.downloadFavicon(LoadFaviconTask.java:222)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.doInBackground(LoadFaviconTask.java:434)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask$1.run(LoadFaviconTask.java:304)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1088)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:581)
11-26 10:04:20.169 E/LoadFaviconTask(  584): 	at java.lang.Thread.run(Thread.java:1019)
11-26 10:04:20.255 E/LoadFaviconTask(  584): Error reading favicon
11-26 10:04:20.255 E/LoadFaviconTask(  584): java.net.UnknownHostException: mochi.test
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at java.net.InetAddress.lookupHostByName(InetAddress.java:497)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at java.net.InetAddress.getAllByNameImpl(InetAddress.java:294)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at java.net.InetAddress.getAllByName(InetAddress.java:256)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:136)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:164)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:119)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:359)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:555)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:487)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:465)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at android.net.http.AndroidHttpClient.execute(AndroidHttpClient.java:243)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.tryDownloadRecurse(LoadFaviconTask.java:128)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.downloadAndDecodeImage(LoadFaviconTask.java:245)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.downloadFavicon(LoadFaviconTask.java:222)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask.doInBackground(LoadFaviconTask.java:474)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at org.mozilla.gecko.favicons.LoadFaviconTask$1.run(LoadFaviconTask.java:304)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1088)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:581)
11-26 10:04:20.255 E/LoadFaviconTask(  584): 	at java.lang.Thread.run(Thread.java:1019)
11-26 10:04:20.255 D/GeckoToolbar(  584): onTabChanged: FAVICON
11-26 10:04:20.255 D/GeckoToolbarDisplayLayout(  584): updateFavicon(android.graphics.Bitmap@406050f8)
11-26 10:04:20.277 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: FAVICON
11-26 10:04:20.536 D/GeckoTabs(  584): handleMessage: Content:StateChange
11-26 10:04:20.725 D/GeckoToolbar(  584): onTabChanged: STOP
11-26 10:04:20.725 I/GeckoToolbarDisplayLayout(  584): zerdatime 2314000 - Throbber stop
11-26 10:04:20.785 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: STOP
11-26 10:04:22.417 D/GeckoThumbnailHelper(  584): handleThumbnailData: 58240
11-26 10:04:22.455 D/GeckoThumbnailHelper(  584): Using new thumbnail size: 58240 (width 160 - height 91)
11-26 10:04:22.469 D/GeckoThumbnailHelper(  584): Sending thumbnail event: 160, 91
11-26 10:04:23.009 D/GeckoThumbnailHelper(  584): handleThumbnailData: 58240
11-26 10:04:23.417 D/GeckoToolbar(  584): onTabChanged: THUMBNAIL
11-26 10:04:23.417 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: THUMBNAIL
11-26 10:04:23.716 D/GeckoToolbar(  584): onTabChanged: THUMBNAIL
11-26 10:04:23.716 D/GeckoBrowserApp(  584): BrowserApp.onTabChanged: 3: THUMBNAIL
...
11-26 10:09:14.975 I/GeckoDump(  584): ⰲ겿{"action":"test_status","time":1417025354966,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/toolkit/content/tests/widgets/test_videocontrols_standalone.html","subtest":"Test timed out.","status":"FAIL","expected":"PASS"}ⰲ겿
I notice that when this test succeeds, the logcat typically shows something like:

http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-central/sha512/fd54ddabbda8f954d8b6d4e971414899227369d8a2e01a05a1c278c39c7babd0e19e66ae6e8bc807582bbaa14370637e4c7a8a2d41344224bcf09de881eddd9c

12-05 06:08:27.188 I/Gecko   (  592): *************************
12-05 06:08:27.188 I/Gecko   (  592): A coding exception was thrown and uncaught in a Task.
12-05 06:08:27.188 I/Gecko   (  592): 
12-05 06:08:27.236 I/Gecko   (  592): Full message: TypeError: tab.browser is null
12-05 06:08:27.236 I/Gecko   (  592): Full stack: Reader.parseDocumentFromTab<@chrome://browser/content/Reader.js:202:9
12-05 06:08:27.236 I/Gecko   (  592): TaskImpl_run@resource://gre/modules/Task.jsm:314:40
12-05 06:08:27.236 I/Gecko   (  592): Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:870:23
12-05 06:08:27.236 I/Gecko   (  592): this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:749:7
12-05 06:08:27.236 I/Gecko   (  592): this.PromiseWalker.scheduleWalkerLoop/<@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:691:37
12-05 06:08:27.236 I/Gecko   (  592): 
12-05 06:08:27.236 I/Gecko   (  592): *************************
12-05 06:08:27.296 W/GeckoConsole(  592): [JavaScript Error: "Error parsing document from tab: TypeError: tab.browser is null" {file: "chrome://browser/content/browser.js" line: 4250}]

I don't know if this is related to this failure.
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=c3ed673841ee suggests that the timeout happens when video.paused and "play" is never received.
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=b8f00581aebf is more conclusive: in the one timeout, the video is paused and the test waits for "play" but it is never received. In all the other cases, the video is not paused and the test passes.
Given the frequency of this bug and the lack of attention it's gotten, I intend to disable it by the end of the week per the test disabling policy.
Can we just disable on Android? I'd like to keep it running on desktop platforms.
Flags: needinfo?(ryanvm)
OS: Mac OS X → Android
Hardware: x86 → ARM
Of course.
Flags: needinfo?(ryanvm)
:jaws, :wesj -- Just before we disable this on Android, I'd like to check that you noticed Comment 168: This fails when the video is initially paused -- we never get "play". Is this path testing "autoplay"? I know there has been some discussion about autoplay on mobile -- is autoplay disabled on Android? Alternately, I wonder why the video is sometimes paused, and if that might be a difference between desktop and mobile.
Flags: needinfo?(jaws)
Using Firefox for Android in my spare time, I occasionally notice that videos don't autoplay. I'm not sure if there is a race condition with loading or what, but this patch will try to kick off play() when the metadata is loaded.

The goal for this test is to make sure that a change doesn't get introduced that breaks-the-world for standalone videos (see bug 678465).

remote: You can view the progress of your build at the following URL:
remote:   https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=0fcbf6e24564
remote: Alternatively, view them on TBPL (soon to be deprecated):
remote:   https://tbpl.mozilla.org/?tree=Try&rev=0fcbf6e24564
Flags: needinfo?(jaws)