Closed Bug 1580643 Opened 5 years ago Closed 5 years ago

Intermittent fission dom/security/test/csp/test_navigate_to.html | Test timed out.

Categories

(Core :: DOM: Security, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1586684

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, regression, test-disabled, Whiteboard: [domsecurity-intermittent])

Attachments

(1 file)

Filed by: cbrindusan [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=266192487&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/TurVx7KASx2FnFRXra3INg/runs/0/artifacts/public/logs/live_backing.log


[task 2019-09-11T22:25:36.719Z] 22:25:36 INFO - TEST-START | dom/security/test/csp/test_navigate_to.html
[task 2019-09-11T22:25:36.779Z] 22:25:36 INFO - GECKO(2700) | ++DOMWINDOW == 35 (0x7f8354309c00) [pid = 2874] [serial = 538] [outer = 0x7f83586a46a0]
[task 2019-09-11T22:25:36.815Z] 22:25:36 INFO - GECKO(2700) | [Parent 2700, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4443
[task 2019-09-11T22:25:36.883Z] 22:25:36 INFO - GECKO(2700) | ++DOCSHELL 0x7f834d058800 == 8 [pid = 2874] [id = {1d1ef1a8-68a8-466e-9d8f-92fbe55e12af}]
[task 2019-09-11T22:25:36.884Z] 22:25:36 INFO - GECKO(2700) | ++DOMWINDOW == 36 (0x7f83546af2e0) [pid = 2874] [serial = 539] [outer = (nil)]
[task 2019-09-11T22:25:36.899Z] 22:25:36 INFO - GECKO(2700) | ++DOMWINDOW == 37 (0x7f835460d000) [pid = 2874] [serial = 540] [outer = 0x7f83546af2e0]
[task 2019-09-11T22:25:36.961Z] 22:25:36 INFO - GECKO(2700) | ++DOMWINDOW == 38 (0x7f8354adc400) [pid = 2874] [serial = 541] [outer = 0x7f83546af2e0]
[task 2019-09-11T22:25:37.017Z] 22:25:37 INFO - GECKO(2700) | [Child 2874, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/base/LocationBase.cpp, line 150
[task 2019-09-11T22:25:37.017Z] 22:25:37 INFO - GECKO(2700) | JavaScript error: http://mochi.test:8888/tests/dom/security/test/csp/file_navigate_to.sjs?csp=navigate-to%20www.mozilla.com&target=http%3A//www.example.com/, line 9: :
[task 2019-09-11T22:25:37.093Z] 22:25:37 INFO - GECKO(2700) | [Parent 2700, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4443
[task 2019-09-11T22:25:37.129Z] 22:25:37 INFO - GECKO(2700) | ++DOMWINDOW == 39 (0x7f8354ada800) [pid = 2874] [serial = 542] [outer = 0x7f83546af2e0]
[task 2019-09-11T22:25:37.170Z] 22:25:37 INFO - GECKO(2700) | [Parent 2700, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4443
[task 2019-09-11T22:25:37.294Z] 22:25:37 INFO - GECKO(2700) | [Parent 2700, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4443
[task 2019-09-11T22:25:37.450Z] 22:25:37 INFO - GECKO(2700) | [Child 2874, Main Thread] WARNING: CompleteRedirectSetup failed, HttpChannelChild already open?: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 2125
[task 2019-09-11T22:25:37.486Z] 22:25:37 INFO - GECKO(2700) | [Parent 2700, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4443
[task 2019-09-11T22:25:37.562Z] 22:25:37 INFO - GECKO(2700) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp58HzIo.mozrunner/runtests_leaks_tab_pid3136.log
[task 2019-09-11T22:25:37.586Z] 22:25:37 INFO - GECKO(2700) | --DOMWINDOW == 38 (0x7f8354ab4400) [pid = 2874] [serial = 510] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_header_dual.sjs?test5]
[task 2019-09-11T22:25:37.586Z] 22:25:37 INFO - GECKO(2700) | --DOMWINDOW == 37 (0x7f835430bc00) [pid = 2874] [serial = 515] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/test_meta_whitespace_skipping.html]
[task 2019-09-11T22:25:37.586Z] 22:25:37 INFO - GECKO(2700) | --DOMWINDOW == 36 (0x7f8354ac3000) [pid = 2874] [serial = 512] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_header_dual.sjs?test7]
[task 2019-09-11T22:25:37.586Z] 22:25:37 INFO - GECKO(2700) | --DOMWINDOW == 35 (0x7f8354307c00) [pid = 2874] [serial = 509] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_header_dual.sjs?test4]
[task 2019-09-11T22:25:37.586Z] 22:25:37 INFO - GECKO(2700) | --DOMWINDOW == 34 (0x7f8354acc000) [pid = 2874] [serial = 514] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-09-11T22:25:37.586Z] 22:25:37 INFO - GECKO(2700) | --DOMWINDOW == 33 (0x7f835430e000) [pid = 2874] [serial = 503] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/test_meta_header_dual.html]
[task 2019-09-11T22:25:37.588Z] 22:25:37 INFO - GECKO(2700) | --DOMWINDOW == 32 (0x7f8354ab8400) [pid = 2874] [serial = 511] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_header_dual.sjs?test6]
[task 2019-09-11T22:25:37.712Z] 22:25:37 INFO - GECKO(2700) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-11T22:25:37.868Z] 22:25:37 INFO - GECKO(2700) | WARN 2019-09-11T22:25:37Z: audio_thread_priority::rt_linux: Could not make thread real-time.
[task 2019-09-11T22:25:37.868Z] 22:25:37 INFO - GECKO(2700) | WARN 2019-09-11T22:25:37Z: audioipc_client: Could not promote audio threads to real-time during initialization.
[task 2019-09-11T22:25:37.884Z] 22:25:37 INFO - GECKO(2700) | ++DOCSHELL 0x7f61562b7000 == 1 [pid = 3136] [id = {e59d9855-619d-4095-9f5b-da1dc930ef0e}]
[task 2019-09-11T22:25:37.920Z] 22:25:37 INFO - GECKO(2700) | ++DOMWINDOW == 1 (0x7f615738cf20) [pid = 3136] [serial = 1] [outer = (nil)]
[task 2019-09-11T22:25:37.921Z] 22:25:37 INFO - GECKO(2700) | ++DOMWINDOW == 2 (0x7f6156267400) [pid = 3136] [serial = 2] [outer = 0x7f615738cf20]
[task 2019-09-11T22:25:37.997Z] 22:25:37 INFO - GECKO(2700) | ++DOMWINDOW == 3 (0x7f6156392c00) [pid = 3136] [serial = 3] [outer = 0x7f615738cf20]
[task 2019-09-11T22:25:41.713Z] 22:25:41 INFO - GECKO(2700) | --DOCSHELL 0x7f834d058800 == 7 [pid = 2874] [id = {1d1ef1a8-68a8-466e-9d8f-92fbe55e12af}] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_navigate_to.sjs?csp=navigate-to%20www.example.com&target=http%3A//www.example.com/]
[task 2019-09-11T22:25:41.714Z] 22:25:41 INFO - GECKO(2700) | --DOCSHELL 0x7f834d062800 == 6 [pid = 2874] [id = {29bbcb4e-da51-4a2f-b9ac-83fc829c84b4}] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multi_policy_injection_bypass.html]
[task 2019-09-11T22:25:41.715Z] 22:25:41 INFO - GECKO(2700) | --DOCSHELL 0x7f834d064000 == 5 [pid = 2874] [id = {28c3c941-7d6f-4727-9810-d1ca40123f10}] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multi_policy_injection_bypass_2.html]
[task 2019-09-11T22:25:41.715Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 31 (0x7f83546bb400) [pid = 2874] [serial = 523] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:25:41.716Z] 22:25:41 INFO - GECKO(2700) | --DOCSHELL 0x7f834e62f000 == 4 [pid = 2874] [id = {e1e7082c-7a8a-47ba-aaca-09fdb22ea1e4}] [url = about:blank]
[task 2019-09-11T22:25:41.717Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 30 (0x7f8354618800) [pid = 2874] [serial = 518] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-09-11T22:25:41.717Z] 22:25:41 INFO - GECKO(2700) | --DOCSHELL 0x7f834d059800 == 3 [pid = 2874] [id = {370f4d9d-f904-419d-96d1-a3262ae92f6f}] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multipart_testserver.sjs?partcspdoc]
[task 2019-09-11T22:25:41.718Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 29 (0x7f83546ba800) [pid = 2874] [serial = 522] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:25:41.718Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 28 (0x7f8354a40000) [pid = 2874] [serial = 526] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-09-11T22:25:41.719Z] 22:25:41 INFO - GECKO(2700) | --DOCSHELL 0x7f834d059000 == 2 [pid = 2874] [id = {3533db87-8949-430c-bbb9-cc8034f337f5}] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multipart_testserver.sjs?doc]
[task 2019-09-11T22:25:41.795Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 27 (0x7f83546ae5c0) [pid = 2874] [serial = 521] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multi_policy_injection_bypass_2.html]
[task 2019-09-11T22:25:41.795Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 26 (0x7f83546ae3e0) [pid = 2874] [serial = 520] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multi_policy_injection_bypass.html]
[task 2019-09-11T22:25:41.796Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 25 (0x7f83546ae7a0) [pid = 2874] [serial = 504] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_header_dual.sjs?test8]
[task 2019-09-11T22:25:41.796Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 24 (0x7f83546aed40) [pid = 2874] [serial = 529] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multipart_testserver.sjs?partcspdoc]
[task 2019-09-11T22:25:41.797Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 23 (0x7f83546ae020) [pid = 2874] [serial = 516] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_whitespace_skipping.html]
[task 2019-09-11T22:25:41.797Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 22 (0x7f83546ae200) [pid = 2874] [serial = 528] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multipart_testserver.sjs?doc]
[task 2019-09-11T22:25:41.797Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 21 (0x7f83546af2e0) [pid = 2874] [serial = 539] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_navigate_to.sjs?csp=navigate-to%20www.example.com&target=http%3A//www.example.com/]
[task 2019-09-11T22:25:41.798Z] 22:25:41 INFO - GECKO(2700) | --DOMWINDOW == 20 (0x7f83546af100) [pid = 2874] [serial = 534] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:25:45.793Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 19 (0x7f83546b9000) [pid = 2874] [serial = 527] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/test_multipartchannel.html]
[task 2019-09-11T22:25:45.793Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 18 (0x7f8354ac7000) [pid = 2874] [serial = 513] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_header_dual.sjs?test8]
[task 2019-09-11T22:25:45.794Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 17 (0x7f8354aaf800) [pid = 2874] [serial = 537] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-09-11T22:25:45.795Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 16 (0x7f8354aaec00) [pid = 2874] [serial = 536] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multipart_testserver.sjs?partcspdoc]
[task 2019-09-11T22:25:45.796Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 15 (0x7f8354a47400) [pid = 2874] [serial = 525] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multi_policy_injection_bypass_2.html]
[task 2019-09-11T22:25:45.796Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 14 (0x7f8354618000) [pid = 2874] [serial = 531] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:25:45.797Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 13 (0x7f8354613c00) [pid = 2874] [serial = 517] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_meta_whitespace_skipping.html]
[task 2019-09-11T22:25:45.797Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 12 (0x7f83546bc000) [pid = 2874] [serial = 532] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multipart_testserver.sjs?doc]
[task 2019-09-11T22:25:45.797Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 11 (0x7f835460d000) [pid = 2874] [serial = 540] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:25:45.798Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 10 (0x7f8354adc400) [pid = 2874] [serial = 541] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_navigate_to.sjs?csp=navigate-to%20www.mozilla.com&target=http%3A//www.example.com/]
[task 2019-09-11T22:25:45.798Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 9 (0x7f8354a45800) [pid = 2874] [serial = 535] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:25:45.798Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 8 (0x7f8354a3c400) [pid = 2874] [serial = 533] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multipart_testserver.sjs?partcspdoc]
[task 2019-09-11T22:25:45.798Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 7 (0x7f835460a400) [pid = 2874] [serial = 519] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/test_multi_policy_injection_bypass.html]
[task 2019-09-11T22:25:45.798Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 6 (0x7f8354a40c00) [pid = 2874] [serial = 524] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_multi_policy_injection_bypass.html]
[task 2019-09-11T22:25:45.798Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 5 (0x7f835460b800) [pid = 2874] [serial = 530] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:25:45.798Z] 22:25:45 INFO - GECKO(2700) | --DOMWINDOW == 4 (0x7f8354ada800) [pid = 2874] [serial = 542] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/security/test/csp/file_navigate_to.sjs?csp=navigate-to%20www.example.com&target=http%3A//www.example.com/]
[task 2019-09-11T22:25:50.150Z] 22:25:50 INFO - GECKO(2700) | --DOMWINDOW == 2 (0x7f6156267400) [pid = 3136] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-11T22:31:04.196Z] 22:31:04 INFO - TEST-INFO | started process screentopng
[task 2019-09-11T22:31:04.432Z] 22:31:04 INFO - TEST-INFO | screentopng: exit 0
[task 2019-09-11T22:31:04.433Z] 22:31:04 INFO - Buffered messages logged at 22:25:37
[task 2019-09-11T22:31:04.433Z] 22:31:04 INFO - TEST-PASS | dom/security/test/csp/test_navigate_to.html | should be blocked in test 0(navigate-to www.mozilla.com, http://www.example.com/)!
[task 2019-09-11T22:31:04.434Z] 22:31:04 INFO - TEST-PASS | dom/security/test/csp/test_navigate_to.html | should be allowed in test 1(navigate-to www.example.com, http://www.example.com/)!
[task 2019-09-11T22:31:04.434Z] 22:31:04 INFO - Buffered messages finished
[task 2019-09-11T22:31:04.434Z] 22:31:04 INFO - TEST-UNEXPECTED-FAIL | dom/security/test/csp/test_navigate_to.html | Test timed out.

Whiteboard: [domsecurity-intermittent]

The test was added here: https://hg.mozilla.org/mozilla-central/rev/90b53eda6606ea56e4db7538588420d1db8c3e0d
Christoph, wanna forward this to Benjamin (his account is disabled) to take a look and try to fix this on fission? Cause it's failing quite frequently: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-09-07&endday=2019-09-14&tree=trunk&bug=1580643
Maybe the info here can be useful for him: https://wiki.mozilla.org/Project_Fission/Enabling_Tests_with_Fission

Flags: needinfo?(ckerschb)
Blocks: 1582881

Pernosco link (with some points of interest in the notebook): https://pernos.co/debug/yojlep7WAe7seW_0sLU45A/index.html#f{m[Arqk,A4JE_,t[xg,CDQ_,f{e[Arqk,A4I6_,s{afyCPZxAA,bASE,oAsmjJw,uAr8LWA___

It looks like we're getting ChangeFrameRemoteness called on the child docshell, which tears it down and cancels the channel.

The channel in question here isn't that the one that initiated the process switch though, so when we receive DocumentChannelParent::RecvCancel, it's actually cancelling the load (of file_navigate_to.sjs for the current test).

I think we finish one subtest (based on the blocking events, or the load started event), and then we have a race between that subtest's process switch (for www.example.com), and the current subtests attempt to load file_navigate_to.sjs.

What should we do if we receive a request to tear down a docshell (because it's moved to another process), but by the time we get the message, we've already started loading a new document (and one that can be in-process)?

Nika, will any of your in-flight changes affect the ordering here?

Flags: needinfo?(nika)

Avoid frequent intermittent test failures on fission.

Keywords: leave-open
Pushed by gbrown@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/0281767ae1a5 Skip test_navigate_to.html on fission; r=mccr8

We discussed this at the meeting yesterday. I don't think my changes will fix this issue.

Flags: needinfo?(nika)
No longer blocks: 1582881

A possible plan here using DocumentChannel.

  • Associate each DocumentChannelParent with the CanonicalBrowsingContext that it is loading for.
  • If we get a new DocumentChannelParent for a CanonicalBrowsingContext, then cancel the load on the old one, and replace it.
  • If we get a new DocumentChannelParent, and the CanonicalBrowsingContext is currently undergoing a process switch, or has done one (such that the PID for CBC doesn't match the OtherPid() of the DocumentChannelParent), then disconnect the associated DocumentChannelChild (set mDoingProcessSwitch, maybe SendCancelForProcessSwitch()).

That should let the new load from the docshell complete without being cancelled when the old docshell is torn down (since the new load is associated with the BrowsingContext which remains alive), and once we get OnStartRequest called for the new load, we'll go through the process switching logic to pick a destination process (which maybe be back to the old process).

Flags: needinfo?(ckerschb)

This intermittent should have been resolved by bug 1586684, hence marking as a duplicate.

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: