Closed
Bug 1502092
Opened 6 years ago
Closed 5 years ago
Intermittent http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html | application timed out after 370 seconds with no output
Categories
(GeckoView :: Media, defect, P5)
GeckoView
Media
Tracking
(geckoview64 wontfix, firefox64 wontfix, firefox65 fixed)
RESOLVED
FIXED
mozilla65
People
(Reporter: gbrown, Assigned: jchen)
References
Details
Attachments
(1 file)
This is a frequent intermittent seen only on the Android 7.0 x86 test platform: https://treeherder.mozilla.org/logviewer.html#?job_id=207730610&repo=mozilla-inbound&lineNumber=4076 [task 2018-10-25T09:18:24.010Z] 09:18:24 INFO - REFTEST TEST-START | http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html [task 2018-10-25T09:18:24.010Z] 09:18:24 INFO - REFTEST INFO | RESTORE PREFERENCE pref(dom.disable_open_during_load,true) [task 2018-10-25T09:18:24.010Z] 09:18:24 INFO - REFTEST INFO | RESTORE PREFERENCE pref(media.navigator.permission.disabled,false) [task 2018-10-25T09:18:24.010Z] 09:18:24 INFO - REFTEST INFO | SET PREFERENCE pref(media.navigator.permission.disabled,true) [task 2018-10-25T09:18:24.010Z] 09:18:24 INFO - REFTEST INFO | SET PREFERENCE pref(dom.disable_open_during_load,false) [task 2018-10-25T09:18:24.011Z] 09:18:24 INFO - REFTEST TEST-LOAD | http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html | 643 / 3618 (17%) [task 2018-10-25T09:18:24.011Z] 09:18:24 INFO - REFTEST TEST-PASS | http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html | (LOAD ONLY) [task 2018-10-25T09:18:24.011Z] 09:18:24 INFO - REFTEST TEST-END | http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html [task 2018-10-25T09:24:56.011Z] 09:24:56 INFO - wait for org.mozilla.geckoview.test complete; top activity=org.mozilla.geckoview.test [task 2018-10-25T09:24:56.115Z] 09:24:56 INFO - Browser unexpectedly found running. Killing... [task 2018-10-25T09:24:56.116Z] 09:24:56 INFO - REFTEST TEST-INFO | started process screentopng [task 2018-10-25T09:24:56.445Z] 09:24:56 INFO - REFTEST TEST-INFO | screentopng: exit 0 [task 2018-10-25T09:25:10.387Z] 09:25:10 WARNING - TEST-UNEXPECTED-FAIL | http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html | application timed out after 370 seconds with no output [task 2018-10-25T09:25:10.388Z] 09:25:10 INFO - INFO | automation.py | Application ran for: 0:08:11.694749 https://taskcluster-artifacts.net/Jdxeqx4bQwCsI71qZ2hcLQ/0/public/test_info//logcat-emulator-5554.log 10-25 10:18:14.530 2365 2380 I Gecko : REFTEST TEST-LOAD | http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html | 643 / 3618 (17%) 10-25 10:18:14.530 2365 2380 I Gecko : 10-25 10:18:14.530 2365 2380 I Gecko : {"action":"log","time":1540459094530,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"START http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html"} 10-25 10:18:14.540 2365 2380 E GeckoConsole: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html" line: 0}] 10-25 10:18:14.550 2365 2740 I libOpenSLES: Emulating old channel mask behavior (ignoring positional mask 0x3, using default mask 0x3 based on channel count of 2) 10-25 10:18:14.550 2365 2740 W AudioTrack: AUDIO_OUTPUT_FLAG_FAST denied by server; frameCount 4096 10-25 10:18:14.550 2365 2740 D AudioTrack: Client defaulted notificationFrames to 2048 for frameCount 4096 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] OnDocumentLoad triggering AfterOnLoadScripts"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"Initializing canvas snapshot"} 10-25 10:18:14.550 2365 2380 W GeckoConsole: [JavaScript Warning: "Use of Mutation Events is deprecated. Use MutationObserver instead." {file: "resource://reftest/reftest-content.js" line: 772}] 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] AfterOnLoadScripts belatedly entering WaitForTestEnd"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] WaitForTestEnd: Adding listeners"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"Initializing canvas snapshot"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: dispatching MozReftestInvalidate"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: STATE_WAITING_FOR_SPELL_CHECKS"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: STATE_WAITING_FOR_APZ_FLUSH"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: APZ flush not required"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: STATE_WAITING_TO_FINISH"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] MakeProgress: Completed"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] RecordResult fired"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"RecordResult fired"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"test_status","time":1540459094550,"thread":null,"pid":null,"source":"reftest","test":"http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html","subtest":"(LOAD ONLY)","status":"PASS"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"test_end","time":1540459094550,"thread":null,"pid":null,"source":"reftest","test":"http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html","status":"OK"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"Loading a blank page"} 10-25 10:18:14.550 2365 2380 W GeckoConsole: [JavaScript Warning: "Navigation to toplevel data: URI not allowed (Blocked loading of: “data:text/html,2â€)"] 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] AfterPaintListener in http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html"} 10-25 10:18:14.550 2365 2380 I Gecko : 10-25 10:18:14.550 2365 2380 I Gecko : {"action":"log","time":1540459094550,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] AfterPaintListener in http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html"} 10-25 10:18:14.570 2365 2380 I Gecko : 10-25 10:18:14.570 2365 2380 I Gecko : {"action":"log","time":1540459094570,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] AfterPaintListener in http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html"} 10-25 10:18:14.570 2365 2380 I Gecko : 10-25 10:18:14.570 2365 2380 I Gecko : {"action":"log","time":1540459094570,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"[CONTENT] AfterPaintListener in http://10.0.2.2:8854/tests/dom/media/tests/crashtests/1185191.html"} 10-25 10:18:20.640 1053 1053 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1140 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1443 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1053 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1140 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1443 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 2625 2710 W System.err: java.lang.IllegalStateException 10-25 10:18:20.640 2625 2710 W System.err: at android.media.MediaCodec.native_flush(Native Method) 10-25 10:18:20.640 2625 2710 W System.err: at android.media.MediaCodec.flush(MediaCodec.java:2052) 10-25 10:18:20.640 2625 2710 W System.err: at org.mozilla.gecko.media.LollipopAsyncCodec.flush(LollipopAsyncCodec.java:178) 10-25 10:18:20.640 2625 2710 W System.err: at org.mozilla.gecko.media.Codec.flush(Codec.java:537) 10-25 10:18:20.640 2625 2710 W System.err: at org.mozilla.gecko.media.ICodec$Stub.onTransact(ICodec.java:121) 10-25 10:18:20.640 2625 2710 W System.err: at android.os.Binder.execTransact(Binder.java:565) 10-25 10:18:20.640 2625 2638 W System.err: java.lang.IllegalStateException 10-25 10:18:20.640 2625 2638 W System.err: at android.media.MediaCodec.native_stop(Native Method) 10-25 10:18:20.640 2625 2638 W System.err: at android.media.MediaCodec.stop(MediaCodec.java:2005) 10-25 10:18:20.640 2625 2638 W System.err: at org.mozilla.gecko.media.LollipopAsyncCodec.stop(LollipopAsyncCodec.java:173) 10-25 10:18:20.640 2625 2638 W System.err: at org.mozilla.gecko.media.Codec.stop(Codec.java:524) 10-25 10:18:20.640 2625 2638 W System.err: at org.mozilla.gecko.media.ICodec$Stub.onTransact(ICodec.java:114) 10-25 10:18:20.640 2625 2638 W System.err: at android.os.Binder.execTransact(Binder.java:565) 10-25 10:18:20.640 1053 1053 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1140 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1443 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1053 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 1053 1140 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.640 2625 2638 W System.err: java.lang.IllegalStateException 10-25 10:18:20.640 2625 2638 W System.err: at android.media.MediaCodec.native_flush(Native Method) 10-25 10:18:20.640 2625 2638 W System.err: at android.media.MediaCodec.flush(MediaCodec.java:2052) 10-25 10:18:20.640 2625 2638 W System.err: at org.mozilla.gecko.media.LollipopAsyncCodec.flush(LollipopAsyncCodec.java:178) 10-25 10:18:20.640 2625 2638 W System.err: at org.mozilla.gecko.media.Codec.flush(Codec.java:537) 10-25 10:18:20.640 2625 2638 W System.err: at org.mozilla.gecko.media.ICodec$Stub.onTransact(ICodec.java:121) 10-25 10:18:20.640 2625 2638 W System.err: at android.os.Binder.execTransact(Binder.java:565) 10-25 10:18:20.640 2625 2710 W System.err: java.lang.IllegalStateException 10-25 10:18:20.640 2625 2710 W System.err: at android.media.MediaCodec.native_stop(Native Method) 10-25 10:18:20.640 2625 2710 W System.err: at android.media.MediaCodec.stop(MediaCodec.java:2005) 10-25 10:18:20.640 2625 2710 W System.err: at org.mozilla.gecko.media.LollipopAsyncCodec.stop(LollipopAsyncCodec.java:173) 10-25 10:18:20.640 2625 2710 W System.err: at org.mozilla.gecko.media.Codec.stop(Codec.java:524) 10-25 10:18:20.640 2625 2710 W System.err: at org.mozilla.gecko.media.ICodec$Stub.onTransact(ICodec.java:114) 10-25 10:18:20.640 2625 2710 W System.err: at android.os.Binder.execTransact(Binder.java:565) 10-25 10:18:20.650 1053 1443 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.650 1053 1053 E ResourceManagerService: Rejected removeResource call with invalid pid. 10-25 10:18:20.650 2625 2625 I GeckoMediaManager: Media service has been unbound. Stopping. 10-25 10:18:20.650 2625 2625 I Process : Sending signal. PID: 2625 SIG: 9 10-25 10:18:20.670 1319 1861 I ActivityManager: Process org.mozilla.geckoview.test:media (pid 2625) has died 10-25 10:18:20.670 1319 1861 D ActivityManager: cleanUpApplicationRecord -- 2625 10-25 10:24:34.950 2365 2371 I art : Thread[3,tid=2371,WaitingInMainSignalCatcherLoop,Thread*=0xe199fc00,peer=0x12c00310,"Signal Catcher"]: reacting to signal 3
Comment hidden (Intermittent Failures Robot) |
Reporter | ||
Comment 2•6 years ago
|
||
:davidb - Can you find someone to look at this? It is the main intermittent failure preventing us from moving Android 7.0 x86 crashtests to tier 1.
Flags: needinfo?(dbolter)
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Priority: -- → P5
Assignee | ||
Comment 5•6 years ago
|
||
Seems like this hasn't happened in the last few days?
Status: NEW → RESOLVED
Closed: 6 years ago
Flags: needinfo?(nchen)
Resolution: --- → WORKSFORME
Reporter | ||
Comment 6•6 years ago
|
||
Sorry, but it is still happening. https://treeherder.mozilla.org/logviewer.html#?job_id=210818078&repo=autoland&lineNumber=4090 https://treeherder.mozilla.org/logviewer.html#?job_id=210755215&repo=autoland&lineNumber=4090 (Remember that since this task is tier 3, it is hidden and not sheriffed; most failures will not be classified and will not show in the intermittent failures view / reports.)
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 8•5 years ago
|
||
1185191.html loads a URI on finishing the test, which can race with the crashtest framework loading another URI on test finish. This patch fixes that race.
Assignee | ||
Updated•5 years ago
|
Assignee: nobody → nchen
Pushed by nchen@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/b02a1825a239 Fix finish race in 1185191.html; r=gbrown
Comment 10•5 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/b02a1825a239
Status: REOPENED → RESOLVED
Closed: 6 years ago → 5 years ago
status-firefox65:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 65
Comment 11•5 years ago
|
||
64=wontfix because we don't need to uplift this test fix.
status-firefox64:
--- → wontfix
Updated•5 years ago
|
Product: Firefox for Android → GeckoView
Updated•5 years ago
|
Keywords: intermittent-failure
Target Milestone: Firefox 65 → mozilla65
Comment 13•2 years ago
|
||
Moving some media bugs to the new GeckoView::Media component.
Component: General → Media
You need to log in
before you can comment on or make changes to this bug.
Description
•