1600374 - Intermittent TEST-UNEXPECTED-TIMEOUT | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | Https downgrade prefetch => No headers - Test timed out

Status: RESOLVED DUPLICATE of bug 1569098

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

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=278810898&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/GOheq21qR_6e9lYcVz7pRA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-11-29T18:58:12.583Z] 18:58:12 INFO - TEST-START | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html
[task 2019-11-29T18:58:12.584Z] 18:58:12 INFO - Closing window 31
[task 2019-11-29T18:58:12.632Z] 18:58:12 INFO - PID 17772 | --DOCSHELL 0x7fca59c54800 == 3 [pid = 18102] [id = {675bb8bf-b380-4365-ade0-c410ae7cbc55}] [url = https://web-platform.test:8443/fetch/metadata/resources/post-to-owner.py?iframe-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Fpost-to-owner.py%3Fiframe-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.632Z] 18:58:12 INFO - PID 17772 | --DOCSHELL 0x7fca5a745800 == 2 [pid = 18102] [id = {be4f1506-5a44-4a6d-b778-c621a8a46011}] [url = https://web-platform.test:8443/fetch/metadata/resources/record-header.py?file=embed-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Frecord-header.py%3Ffile%3Dembed-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.633Z] 18:58:12 INFO - PID 17772 | --DOCSHELL 0x7fca59c5e000 == 1 [pid = 18102] [id = {c697477e-22eb-49b9-9e1a-18bef1ae25cd}] [url = https://web-platform.test:8443/fetch/metadata/resources/record-header.py?file=object-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Frecord-header.py%3Ffile%3Dobject-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.669Z] 18:58:12 INFO - PID 17772 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-29T18:58:12.685Z] 18:58:12 INFO - PID 17772 | ++DOCSHELL 0x7f9ab6ed6000 == 1 [pid = 18135] [id = {44e607dc-85f9-41b1-a863-91c5449fc929}]
[task 2019-11-29T18:58:12.763Z] 18:58:12 INFO - PID 17772 | --DOCSHELL 0x7fca595d6000 == 0 [pid = 18102] [id = {869c9692-79e0-453b-8ac5-74a384018838}] [url = http://web-platform.test:8000/fetch/metadata/redirect/redirect-http-upgrade.tentative.sub.html]
[task 2019-11-29T18:58:12.764Z] 18:58:12 INFO - PID 17772 | ++DOMWINDOW == 1 (0x7f9ab6d1ef20) [pid = 18135] [serial = 1] [outer = (nil)]
[task 2019-11-29T18:58:12.766Z] 18:58:12 INFO - PID 17772 | [Child 18135, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2019-11-29T18:58:12.767Z] 18:58:12 INFO - PID 17772 | ++DOMWINDOW == 2 (0x7f9ab6eaf000) [pid = 18135] [serial = 2] [outer = 0x7f9ab6d1ef20]
[task 2019-11-29T18:58:12.840Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 9 (0x7fca5941e2e0) [pid = 18102] [serial = 6] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/post-to-owner.py?top-level-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Fpost-to-owner.py%3Ftop-level-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.845Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 8 (0x7fca5941e880) [pid = 18102] [serial = 13] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/record-header.py?file=object-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Frecord-header.py%3Ffile%3Dobject-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.845Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 7 (0x7fca5941e6a0) [pid = 18102] [serial = 10] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/record-header.py?file=embed-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Frecord-header.py%3Ffile%3Dembed-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.845Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 6 (0x7fca5941e100) [pid = 18102] [serial = 5] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/post-to-owner.py?iframe-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Fpost-to-owner.py%3Fiframe-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.845Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 5 (0x7fca55233000) [pid = 18102] [serial = 12] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/post-to-owner.py?top-level-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Fpost-to-owner.py%3Ftop-level-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.849Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 4 (0x7fca55296c00) [pid = 18102] [serial = 14] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/record-header.py?file=object-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Frecord-header.py%3Ffile%3Dobject-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.849Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 3 (0x7fca5522f400) [pid = 18102] [serial = 11] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/record-header.py?file=embed-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Frecord-header.py%3Ffile%3Dembed-https-redirectfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.849Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 2 (0x7fca5a786000) [pid = 18102] [serial = 9] [outer = (nil)] [url = https://web-platform.test:8443/fetch/metadata/resources/post-to-owner.py?iframe-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&location=https%3A%2F%2Fweb-platform.test%3A8443%2Ffetch%2Fmetadata%2Fresources%2Fpost-to-owner.py%3Fiframe-navigationfbbfeb37-8a24-42ec-9099-f472792c904f&count=1]
[task 2019-11-29T18:58:12.849Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 1 (0x7fca59cd4400) [pid = 18102] [serial = 4] [outer = (nil)] [url = http://web-platform.test:8000/fetch/metadata/redirect/redirect-http-upgrade.tentative.sub.html]
[task 2019-11-29T18:58:12.849Z] 18:58:12 INFO - PID 17772 | --DOMWINDOW == 0 (0x7fca5941df20) [pid = 18102] [serial = 1] [outer = (nil)] [url = http://web-platform.test:8000/fetch/metadata/redirect/redirect-http-upgrade.tentative.sub.html]
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | nsStringStats
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => mAllocCount: 12474
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => mReallocCount: 0
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => mFreeCount: 12474
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => mShareCount: 16584
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => mAdoptCount: 637
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => mAdoptFreeCount: 661
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => Process ID: 18102, Thread ID: 140507522021184
[task 2019-11-29T18:58:12.930Z] 18:58:12 INFO - PID 17772 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpkkfCk7.mozrunner/runtests_leaks_930_tab_pid18182.log
[task 2019-11-29T18:58:12.946Z] 18:58:12 INFO - PID 17772 | [Child 18182, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 729

[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => mAdoptFreeCount: 661
[task 2019-11-29T18:58:12.874Z] 18:58:12 INFO - PID 17772 | => Process ID: 18102, Thread ID: 140507522021184
[task 2019-11-29T18:58:12.930Z] 18:58:12 INFO - PID 17772 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpkkfCk7.mozrunner/runtests_leaks_930_tab_pid18182.log
[task 2019-11-29T18:58:12.946Z] 18:58:12 INFO - PID 17772 | [Child 18182, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 729
[task 2019-11-29T18:58:13.063Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 3 (0x7f9ab700bc00) [pid = 18135] [serial = 3] [outer = 0x7f9ab6d1ef20]
[task 2019-11-29T18:58:13.111Z] 18:58:13 INFO - PID 17772 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-11-29T18:58:13.111Z] 18:58:13 INFO - PID 17772 | [Child 18182, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/workspace/build/src/dom/media/CubebUtils.cpp, line 381
[task 2019-11-29T18:58:13.208Z] 18:58:13 INFO - PID 17772 | [Parent 17772, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-11-29T18:58:13.216Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 4 (0x7f9ab700ec00) [pid = 18135] [serial = 4] [outer = 0x7f9ab6d1ef20]
[task 2019-11-29T18:58:13.253Z] 18:58:13 INFO - PID 17772 | [Child 18182, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1799
[task 2019-11-29T18:58:13.374Z] 18:58:13 INFO - PID 17772 | ++DOCSHELL 0x7f9ab7054000 == 2 [pid = 18135] [id = {4d4bda8f-be7c-4d42-95fd-2b1232900e74}]
[task 2019-11-29T18:58:13.375Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 5 (0x7f9ab6d1f100) [pid = 18135] [serial = 5] [outer = (nil)]
[task 2019-11-29T18:58:13.376Z] 18:58:13 INFO - PID 17772 | ++DOCSHELL 0x7f9ab8039800 == 3 [pid = 18135] [id = {9c8e0d3b-28f9-467a-b2c2-dfc7e36f64e6}]
[task 2019-11-29T18:58:13.376Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 6 (0x7f9ab6d1f2e0) [pid = 18135] [serial = 6] [outer = (nil)]
[task 2019-11-29T18:58:13.377Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 7 (0x7f9ab8086000) [pid = 18135] [serial = 7] [outer = 0x7f9ab6d1f2e0]
[task 2019-11-29T18:58:13.675Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 8 (0x7f9ab7010c00) [pid = 18135] [serial = 8] [outer = 0x7f9ab6d1f2e0]
[task 2019-11-29T18:58:13.824Z] 18:58:13 INFO - PID 17772 | [Parent 17772, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-11-29T18:58:13.845Z] 18:58:13 INFO - PID 17772 | ++DOCSHELL 0x7f9ab8042000 == 4 [pid = 18135] [id = {11fae607-a918-428c-af81-ec2cd3f77070}]
[task 2019-11-29T18:58:13.846Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 9 (0x7f9ab6d1f6a0) [pid = 18135] [serial = 9] [outer = (nil)]
[task 2019-11-29T18:58:13.847Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 10 (0x7f9ab8091800) [pid = 18135] [serial = 10] [outer = 0x7f9ab6d1f6a0]
[task 2019-11-29T18:58:13.861Z] 18:58:13 INFO - PID 17772 | [Child 18135, Main Thread] WARNING: Listener is not retargetable: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 3429
[task 2019-11-29T18:58:13.862Z] 18:58:13 INFO - PID 17772 | [Child 18135, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/workspace/build/src/parser/html/nsHtml5StreamParser.cpp, line 1142
[task 2019-11-29T18:58:13.862Z] 18:58:13 INFO - PID 17772 | ++DOMWINDOW == 11 (0x7f9ab2d37400) [pid = 18135] [serial = 11] [outer = 0x7f9ab6d1f100]
[task 2019-11-29T18:58:13.878Z] 18:58:13 INFO - PID 17772 | [Parent 17772, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-11-29T18:58:14.101Z] 18:58:14 INFO - PID 17772 | ++DOCSHELL 0x7f9ab803c800 == 5 [pid = 18135] [id = {49ae060a-6582-498f-9bbe-742ce1badb85}]
[task 2019-11-29T18:58:14.101Z] 18:58:14 INFO - PID 17772 | ++DOMWINDOW == 12 (0x7f9ab6d1f880) [pid = 18135] [serial = 12] [outer = (nil)]
[task 2019-11-29T18:58:14.101Z] 18:58:14 INFO - PID 17772 | ++DOMWINDOW == 13 (0x7f9ab2d87000) [pid = 18135] [serial = 13] [outer = 0x7f9ab6d1f880]
[task 2019-11-29T18:58:14.101Z] 18:58:14 INFO - PID 17772 | [Child 18135, Main Thread] WARNING: Listener is not retargetable: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 3429
[task 2019-11-29T18:58:14.102Z] 18:58:14 INFO - PID 17772 | [Child 18135, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/workspace/build/src/parser/html/nsHtml5StreamParser.cpp, line 1142
[task 2019-11-29T18:58:23.161Z] 18:58:23 INFO - PID 17772 | --DOCSHELL 0x7f9ab8039800 == 4 [pid = 18135] [id = {9c8e0d3b-28f9-467a-b2c2-dfc7e36f64e6}] [url = http://web-platform.test:8000/fetch/metadata/resources/post-to-owner.py?top-level-navigationf0c8bd5a-7fce-40b3-a403-0b664e1ff07e&location=http%3A%2F%2Fweb-platform.test%3A8000%2Ffetch%2Fmetadata%2Fresources%2Fpost-to-owner.py%3Ftop-level-navigationf0c8bd5a-7fce-40b3-a403-0b664e1ff07e&count=1]
[task 2019-11-29T18:58:27.265Z] 18:58:27 INFO - PID 17772 | --DOMWINDOW == 12 (0x7f9ab8086000) [pid = 18135] [serial = 7] [outer = (nil)] [url = about:blank]
[task 2019-11-29T18:58:27.266Z] 18:58:27 INFO - PID 17772 | --DOMWINDOW == 11 (0x7f9ab700bc00) [pid = 18135] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2019-11-29T18:58:27.266Z] 18:58:27 INFO - PID 17772 | --DOMWINDOW == 10 (0x7f9ab6eaf000) [pid = 18135] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-11-29T18:58:43.475Z] 18:58:43 INFO -
[task 2019-11-29T18:58:43.475Z] 18:58:43 INFO - TEST-PASS | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | Https downgrade iframe
[task 2019-11-29T18:58:43.476Z] 18:58:43 INFO - TEST-PASS | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | Https downgrade top level navigation
[task 2019-11-29T18:58:43.476Z] 18:58:43 INFO - TEST-PASS | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | Https downgrade embed
[task 2019-11-29T18:58:43.476Z] 18:58:43 INFO - TEST-PASS | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | Https downgrade fetch() api
[task 2019-11-29T18:58:43.476Z] 18:58:43 INFO - TEST-PASS | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | Https downgrade object
[task 2019-11-29T18:58:43.476Z] 18:58:43 INFO - TEST-UNEXPECTED-TIMEOUT | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | Https downgrade prefetch => No headers - Test timed out
[task 2019-11-29T18:58:43.477Z] 18:58:43 INFO - TEST-INFO | expected FAIL
[task 2019-11-29T18:58:43.480Z] 18:58:43 INFO - ..............................
[task 2019-11-29T18:58:43.480Z] 18:58:43 INFO - TEST-TIMEOUT | /fetch/metadata/redirect/redirect-https-downgrade.tentative.sub.html | took 30907ms

Comment 2

[Intermittent Failures Robot]

3 failures in 4867 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 3

Platform breakdown:

• macosx1014-64: 2
• linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1600374&startday=2019-12-09&endday=2019-12-15&tree=all