Intermittent toolkit/components/extensions/test/mochitest/test_ext_redirect_jar.html | frame 1 loaded - Expected: loaded, Actual: timed_out

RESOLVED FIXED in Firefox 56

Status

defect
P5
normal
RESOLVED FIXED
2 years ago
Last year

People

(Reporter: intermittent-bug-filer, Assigned: mixedpuppy)

Tracking

({intermittent-failure})

unspecified
mozilla57
Dependency tree / graph
Bug Flags:
qe-verify -

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox55 unaffected, firefox56 fixed, firefox57 fixed)

Details

(Whiteboard: [stockwell fixed:timing])

Attachments

(1 attachment)

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=125471419&repo=autoland

https://queue.taskcluster.net/v1/task/dbOklNo-SnS3xUjsAIy7Cw/runs/0/artifacts/public/logs/live_backing.log

[task 2017-08-24T09:59:59.973888Z] 09:59:59     INFO - GECKO(1411) | [Child 1658] WARNING: NS_ENSURE_TRUE(mRequest) failed: file /home/worker/workspace/build/src/netwerk/base/nsBaseChannel.cpp, line 943
[task 2017-08-24T09:59:59.977159Z] 09:59:59     INFO - GECKO(1411) | [Child 1658] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /home/worker/workspace/build/src/parser/html/nsHtml5StreamParser.cpp, line 977
[task 2017-08-24T10:00:00.132595Z] 10:00:00     INFO - GECKO(1411) | [Child 1658] WARNING: stylo: ServoStyleSets cannot respond to document state changes yet (only matters for chrome documents). See bug 1290285.: file /home/worker/workspace/build/src/layout/base/PresShell.cpp, line 4300
[task 2017-08-24T10:00:00.197269Z] 10:00:00     INFO - TEST-INFO | started process screentopng
[task 2017-08-24T10:00:01.487599Z] 10:00:01     INFO - TEST-INFO | screentopng: exit 0
[task 2017-08-24T10:00:01.490433Z] 10:00:01     INFO - Buffered messages logged at 09:59:44
[task 2017-08-24T10:00:01.492452Z] 10:00:01     INFO - SpawnTask.js | Entering test test_redirect_to_jar
[task 2017-08-24T10:00:01.494362Z] 10:00:01     INFO - Extension loaded
[task 2017-08-24T10:00:01.499613Z] 10:00:01     INFO - Buffered messages finished
[task 2017-08-24T10:00:01.508968Z] 10:00:01     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_redirect_jar.html | frame 1 loaded - Expected: loaded, Actual: timed_out 
[task 2017-08-24T10:00:01.512079Z] 10:00:01     INFO -     @moz-extension://f7b48374-89d1-457d-bb49-f58ba672b57a/%7B7b92c97e-1dbf-4c72-81b5-2b48a3811493%7D.js:23:7
[task 2017-08-24T10:00:01.522297Z] 10:00:01     INFO -     async*@moz-extension://f7b48374-89d1-457d-bb49-f58ba672b57a/%7B7b92c97e-1dbf-4c72-81b5-2b48a3811493%7D.js:1:2
[task 2017-08-24T10:00:01.527210Z] 10:00:01     INFO -     
[task 2017-08-24T10:00:01.529216Z] 10:00:01     INFO - Not taking screenshot here: see the one that was previously logged
[task 2017-08-24T10:00:01.534859Z] 10:00:01     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_redirect_jar.html | frame 1 redirected - Expected: moz-extension://f7b48374-89d1-457d-bb49-f58ba672b57a/finished.html, Actual: undefined 
[task 2017-08-24T10:00:01.537241Z] 10:00:01     INFO -     @moz-extension://f7b48374-89d1-457d-bb49-f58ba672b57a/%7B7b92c97e-1dbf-4c72-81b5-2b48a3811493%7D.js:24:7
[task 2017-08-24T10:00:01.542028Z] 10:00:01     INFO -     async*@moz-extension://f7b48374-89d1-457d-bb49-f58ba672b57a/%7B7b92c97e-1dbf-4c72-81b5-2b48a3811493%7D.js:1:2
[task 2017-08-24T10:00:01.547988Z] 10:00:01     INFO -
This test was just added in bug 1390346. Shane, can you please investigate?
Blocks: 1390346
Flags: needinfo?(mixedpuppy)
Assignee: nobody → mixedpuppy
Flags: needinfo?(mixedpuppy)
Comment on attachment 8900914 [details]
Bug 1393402 fix intermittent by removing early testing timeout

https://reviewboard.mozilla.org/r/172346/#review177642

r=me for a bump in timout for linux servo debug intermittent
Attachment #8900914 - Flags: review+
The timer is quite arbitrary. Why do you think that 5s instead of 2s fixes the issue?

The expected behavior of the test is that the following line is triggered:

  s.onload = () => resolve(['loaded', s.contentWindow.location.href]);

That happens after the following has happened:
1. Request to /intercept?r=[random_number]
2. Background page of extension intercepts request and requests a redirect to a moz-extension:-URL.
3. moz-extension resource data is loaded and used to construct the frame's document.
4. Frame's document has finished.

(before the original big was fixed, step 3 failed; without triggering the s.onerror event, hence the need for the timer).

With the bug fix, this time out condition is not expected to occur (i.e. s.onload is fired eventually), so how about removing the setTimeout and adding a comment for what it means if the test does unexpectedly time out? (i.e. either the request was handled too slowly, or the request was incorrectly handled).

(The only purpose of the timer in the original bug report is to detect that the bug has *likely* occurred, so that it is easier to see whether the bug is still present.)
Pushed by mixedpuppy@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/1c3d0a6605a3
set longer timeout for document load r=mixedpuppy
Whiteboard: [stockwell fixed:other]
https://hg.mozilla.org/mozilla-central/rev/1c3d0a6605a3
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla57
It seems that the failure is still occuring.

Shane, how about removing the line (as I suggested in comment 4)?

If the test still times out after removing the line, then there might be an actual error.
Status: RESOLVED → REOPENED
Flags: needinfo?(mixedpuppy)
Resolution: FIXED → ---
https://hg.mozilla.org/releases/mozilla-beta/rev/8081a895e435
Whiteboard: [stockwell fixed:other] → [stockwell needswork]
Target Milestone: mozilla57 → ---
Started a try from reviewboard, will run the test a bunch of times to see if this fixes it.
Flags: needinfo?(mixedpuppy)
Comment on attachment 8900914 [details]
Bug 1393402 fix intermittent by removing early testing timeout

https://reviewboard.mozilla.org/r/172346/#review181140
Attachment #8900914 - Flags: review+
Pushed by mixedpuppy@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/020c55bcd806
fix intermittent by removing early testing timeout r=mixedpuppy
https://hg.mozilla.org/mozilla-central/rev/020c55bcd806
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla57
Whiteboard: [stockwell needswork] → [stockwell fixed:timing]
Flags: qe-verify-
Product: Toolkit → WebExtensions
You need to log in before you can comment on or make changes to this bug.