Closed Bug 1172133 Opened 10 years ago Closed 10 years ago

Intermittent test_cache_https.html | Test timed out

Categories

(Core :: DOM: Core & HTML, defect)

ARM
Android
defect
Not set
normal

Tracking

()

RESOLVED WORKSFORME
Tracking Status
firefox41 --- affected

People

(Reporter: RyanVM, Assigned: bkelly)

Details

(Keywords: intermittent-failure)

09:19:29 INFO - 263 INFO TEST-START | dom/cache/test/mochitest/test_cache_https.html 09:24:45 INFO - 264 INFO TEST-PASS | dom/cache/test/mochitest/test_cache_https.html | order argument should be valid 09:24:45 INFO - 265 INFO TEST-UNEXPECTED-FAIL | dom/cache/test/mochitest/test_cache_https.html | Test timed out. - expected PASS 09:24:45 INFO - 266 INFO TEST-OK | dom/cache/test/mochitest/test_cache_https.html | took 301944ms
Hmm, all android opt.
Assignee: nobody → bkelly
Status: NEW → ASSIGNED
Geoff, is this something that is caused by Panda devices, or other known Android test instability issues?
Flags: needinfo?(gbrown)
All of these are on Android 4.3, which runs in an Android emulator, running on aws hosts -- not on Pandas. This does not look like any Android instability issue that I am aware of. Actually most tests are running well in this environment now. Comparing a logcat from a successful run: http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/27f954e05df928be917628685c94456abd821f400f3c3985bfecf0292442101b43553e21186e0d63822e0974ba6f914522c03bebc00ec1dd76b72e1bdb7efef6 08-05 07:45:46.680 775 795 I GeckoDump: ⰲ겿{"action":"test_start","time":1438785946683,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html"}ⰲ겿 08-05 07:45:46.920 282 283 D dalvikvm: GC_CONCURRENT freed 717K, 37% free 5632K/8820K, paused 23ms+46ms, total 499ms 08-05 07:45:50.820 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785950822,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"order argument should be valid","status":"PASS"}ⰲ겿 08-05 07:45:50.910 775 836 I Gecko : 08-05 07:45:50.910 775 836 I Gecko : ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost 08-05 07:45:50.910 775 836 I Gecko : 08-05 07:45:50.930 775 836 I Gecko : 08-05 07:45:50.930 775 836 I Gecko : ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost 08-05 07:45:50.930 775 836 I Gecko : 08-05 07:45:51.242 775 795 W GeckoConsole: [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/dom/cache/test/mochitest/test_cache_https.html" line: 0}] 08-05 07:45:58.700 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785958702,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Correct context for messages received on the worker","status":"PASS"}ⰲ겿 08-05 07:45:58.710 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785958709,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Worker: true: Cache entry should be deleted","status":"PASS"}ⰲ겿 08-05 07:45:58.850 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785958823,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Correct context for messages received on the worker","status":"PASS"}ⰲ겿 08-05 07:45:58.870 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785958860,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Worker: true: Cache entry should be deleted","status":"PASS"}ⰲ겿 08-05 07:45:58.880 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785958882,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Correct context for messages received on the worker","status":"PASS"}ⰲ겿 08-05 07:45:58.900 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785958893,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Worker: true: Cache should be deleted","status":"PASS"}ⰲ겿 08-05 07:45:58.910 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785958911,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Correct context for messages received on the worker","status":"PASS"}ⰲ겿 08-05 07:46:03.580 775 795 W GeckoConsole: [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/dom/cache/test/mochitest/message_receiver.html" line: 0}] 08-05 07:46:04.730 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785964735,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"ServiceWorker: true: Cache entry should be deleted","status":"PASS"}ⰲ겿 08-05 07:46:04.790 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785964794,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"ServiceWorker: true: Cache entry should be deleted","status":"PASS"}ⰲ겿 08-05 07:46:04.870 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785964861,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"ServiceWorker: true: Cache should be deleted","status":"PASS"}ⰲ겿 08-05 07:46:05.381 775 795 W GeckoConsole: [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/dom/cache/test/mochitest/frame.html" line: 0}] 08-05 07:46:06.330 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785966329,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Window: true: Cache entry should be deleted","status":"PASS"}ⰲ겿 08-05 07:46:06.360 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785966358,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Window: true: Cache entry should be deleted","status":"PASS"}ⰲ겿 08-05 07:46:06.452 775 795 I GeckoDump: ⰲ겿{"action":"test_status","time":1438785966442,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Window: true: Cache should be deleted","status":"PASS"}ⰲ겿 08-05 07:46:06.741 775 795 I GeckoDump: MEMORY STAT | vsize 757MB | residentFast 190MB | heapAllocated 77MB 08-05 07:46:06.960 775 795 I GeckoDump: ⰲ겿{"action":"test_end","time":1438785966961,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","status":"OK","message":"Finished in 20277ms","extra":{"runtime":20277}}ⰲ겿 ...to a failure: http://mozilla-releng-blobs.s3.amazonaws.com/blobs/fx-team/sha512/a30e63c68264dfeaa5ea5375fbc0ef735abeb80163b58e7162cf110cdc8936eea36128ceb8f71e8c89e27ac0d6774e53bf7340c177d9e337e40df348d8385e9f 07-23 05:55:35.870 793 813 I GeckoDump: ⰲ겿{"action":"test_start","time":1437656135872,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html"}ⰲ겿 07-23 05:55:38.361 793 813 I GeckoDump: ⰲ겿{"action":"test_status","time":1437656138359,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"order argument should be valid","status":"PASS"}ⰲ겿 07-23 05:55:38.430 793 854 I Gecko : 07-23 05:55:38.430 793 854 I Gecko : ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost 07-23 05:55:38.430 793 854 I Gecko : 07-23 05:55:38.451 793 854 I Gecko : 07-23 05:55:38.451 793 854 I Gecko : ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost 07-23 05:55:38.451 793 854 I Gecko : 07-23 05:55:38.710 793 813 W GeckoConsole: [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/dom/cache/test/mochitest/test_cache_https.html" line: 0}] ... (unrelated idle activity) ... 07-23 06:00:37.780 793 813 I GeckoDump: ⰲ겿{"action":"test_status","time":1437656437764,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","subtest":"Test timed out.","status":"FAIL","expected":"PASS","stack":" reportError@SimpleTest/TestRunner.js:334:7\n TestRunner._checkForHangs@SimpleTest/TestRunner.js:354:7\n"}ⰲ겿 07-23 06:00:38.930 793 813 I GeckoDump: MEMORY STAT | vsize 710MB | residentFast 183MB | heapAllocated 46MB 07-23 06:00:39.020 793 813 I GeckoDump: ⰲ겿{"action":"test_end","time":1437656439013,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/cache/test/mochitest/test_cache_https.html","status":"OK","message":"Finished in 303138ms","extra":{"runtime":303138}}ⰲ겿 In the failed cases, the test never gets to "Correct context for messages received on the worker" -- http://hg.mozilla.org/mozilla-central/annotate/b12a261ee32e/dom/cache/test/mochitest/worker_driver.js#l34
Flags: needinfo?(gbrown)
That smells a lot like the worker not starting up... :(
This hasn't happened in a month.
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → WORKSFORME
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.