1556075 - Intermittent wpt Loading initial page http://web-platform.test:8000/testharness_runner.html failed

Reporter

Description

•

5 years ago

treeherder

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

[task 2019-05-31T18:37:13.389Z] 18:37:13 [task 2019-05-31T18:37:13.456Z] 18:37:13 [task 2019-05-31T18:37:13.803Z] 18:37:13 [task 2019-05-31T18:37:13.803Z] 18:37:13 [task 2019-05-31T18:37:13.803Z] 18:37:13 [task 2019-05-31T18:37:13.804Z] 18:37:13 [task 2019-05-31T18:37:13.804Z] 18:37:13 [task 2019-05-31T18:37:13.805Z] 18:37:13 [task 2019-05-31T18:37:13.805Z] 18:37:13 [task 2019-05-31T18:37:14.136Z] 18:37:14 [task 2019-05-31T18:37:16.728Z] 18:37:16 [task 2019-05-31T18:37:16.728Z] 18:37:16 [task 2019-05-31T18:37:16.728Z] 18:37:16 [task 2019-05-31T18:37:16.728Z] 18:37:16 [task 2019-05-31T18:37:16.728Z] 18:37:16 [task 2019-05-31T18:37:16.729Z] 18:37:16 [task 2019-05-31T18:37:16.892Z] 18:37:16 [task 2019-05-31T18:37:16.893Z] 18:37:16 [task 2019-05-31T18:37:16.894Z] 18:37:16 [task 2019-05-31T18:37:16.899Z] 18:37:16 [task 2019-05-31T18:37:16.899Z] 18:37:16 [task 2019-05-31T18:37:16.900Z] 18:37:16 [task 2019-05-31T18:37:16.900Z] 18:37:16 [task 2019-05-31T18:37:17.382Z] 18:37:17 [task 2019-05-31T18:37:17.382Z] 18:37:17 [task 2019-05-31T18:37:17.382Z] 18:37:17 [task 2019-05-31T18:37:17.382Z] 18:37:17 [task 2019-05-31T18:37:17.382Z] 18:37:17 [task 2019-05-31T18:37:17.383Z] 18:37:17 [task 2019-05-31T18:37:17.384Z] 18:37:17 [task 2019-05-31T18:37:17.618Z] 18:37:17 [task 2019-05-31T18:37:17.619Z] 18:37:17 [task 2019-05-31T18:37:17.619Z] 18:37:17 [task 2019-05-31T18:37:17.619Z] 18:37:17 [task 2019-05-31T18:37:17.619Z] 18:37:17 [task 2019-05-31T18:37:17.619Z] 18:37:17 [task 2019-05-31T18:37:17.619Z] 18:37:17 [task 2019-05-31T18:37:29.842Z] 18:37:29 [task 2019-05-31T18:37:29.842Z] 18:37:29 [task 2019-05-31T18:37:29.842Z] 18:37:29 [task 2019-05-31T18:37:29.842Z] 18:37:29 [task 2019-05-31T18:37:29.843Z] 18:37:29 [task 2019-05-31T18:37:29.844Z] 18:37:29 [task 2019-05-31T18:37:29.844Z] 18:37:29 [task 2019-05-31T18:37:29.844Z] 18:37:29 [task 2019-05-31T18:37:29.845Z] 18:37:29 [task 2019-05-31T18:37:31.031Z] 18:37:31 [task 2019-05-31T18:37:31.035Z] 18:37:31 [task 2019-05-31T18:37:31.036Z] 18:37:31 [task 2019-05-31T18:37:31.036Z] 18:37:31 [task 2019-05-31T18:37:31.037Z] 18:37:31 [task 2019-05-31T18:37:31.149Z] 18:37:31 [task 2019-05-31T18:37:31.150Z] 18:37:31 [task 2019-05-31T18:37:31.150Z] 18:37:31 [task 2019-05-31T18:37:31.176Z] 18:37:31 [task 2019-05-31T18:37:31.391Z] 18:37:31 [task 2019-05-31T18:37:31.608Z] 18:37:31 [task 2019-05-31T18:37:31.831Z] 18:37:31 [task 2019-05-31T18:37:31.832Z] 18:37:31 [task 2019-05-31T18:37:31.832Z] 18:37:31 [task 2019-05-31T18:37:31.832Z] 18:37:31 [task 2019-05-31T18:37:31.832Z] 18:37:31 [task 2019-05-31T18:37:31.832Z] 18:37:31 [task 2019-05-31T18:37:31.876Z] 18:37:31 [task 2019-05-31T18:37:31.977Z] 18:37:31 [task 2019-05-31T18:37:34.947Z] 18:37:34 [task 2019-05-31T18:37:34.948Z] 18:37:34 [task 2019-05-31T18:37:34.949Z] 18:37:34 [task 2019-05-31T18:37:34.949Z] 18:37:34 [task 2019-05-31T18:38:22.496Z] 18:38:22 [task 2019-05-31T18:38:39.101Z] 18:38:39 [task 2019-05-31T18:41:49.908Z] 18:41:49 [task 2019-05-31T18:41:49.909Z] 18:41:49 [task 2019-05-31T18:41:49.978Z] [task 2019-05-31T18:41:49.978Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.978Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.978Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.978Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.978Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.978Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.979Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.979Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.979Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.979Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.979Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.980Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.980Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.980Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.981Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.981Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.981Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.981Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.982Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.982Z] 18:41:49 CRITICAL - [task 2019-05-31T18:41:49.982Z] [task 2019-05-31T18:41:49.982Z] [task 2019-05-31T18:41:49.983Z] 18:41:49 [task 2019-05-31T18:41:49.983Z] 18:41:49 [task 2019-05-31T18:41:49.983Z] 18:41:49 [task 2019-05-31T18:41:49.984Z] 18:41:49 [task 2019-05-31T18:41:50.069Z] 18:41:50 [task 2019-05-31T18:41:50.069Z] 18:41:50 [task 2019-05-31T18:41:50.070Z] 18:41:50 [task 2019-05-31T18:41:50.095Z] 18:41:50 [task 2019-05-31T18:41:55.073Z] 18:41:55 [task 2019-05-31T18:41:55.257Z] 18:41:55 [task 2019-05-31T18:41:55.397Z] 18:41:55 [task 2019-05-31T18:41:55.397Z] 18:41:55 [task 2019-05-31T18:41:55.397Z] 18:41:55 [task 2019-05-31T18:41:55.397Z] 18:41:55 [task 2019-05-31T18:41:55.397Z] 18:41:55 [task 2019-05-31T18:41:55.397Z] 18:41:55 [task 2019-05-31T18:41:55.414Z] 18:41:55 [task 2019-05-31T18:41:55.493Z] 18:41:55 [task 2019-05-31T18:41:58.476Z] 18:41:58 [task 2019-05-31T18:41:58.477Z] 18:41:58 [task 2019-05-31T18:41:58.477Z] 18:41:58 [task 2019-05-31T18:41:58.477Z] 18:41:58 [task 2019-05-31T18:42:26.101Z] 18:42:26 [task 2019-05-31T18:42:27.621Z] 18:42:27 INFO - TEST-OK | /css/css-transforms/parsing/translate-parsing-valid.html | took 3556ms
INFO - PID 12811 | 1559327833450 Marionette INFO Stopped listening on port 2828
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | Suppressions used:
INFO - PID 12811 | count bytes template
INFO - PID 12811 | 28 864 nsComponentManagerImpl
INFO - PID 12811 | 611 17713 libfontconfig.so
INFO - PID 12811 | 1 29 libglib-2.0.so
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | Suppressions used:
INFO - PID 12811 | count bytes template
INFO - PID 12811 | 28 864 nsComponentManagerImpl
INFO - PID 12811 | 2 288 libfontconfig.so
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | Suppressions used:
INFO - PID 12811 | count bytes template
INFO - PID 12811 | 28 864 nsComponentManagerImpl
INFO - PID 12811 | 611 17713 libfontconfig.so
INFO - PID 12811 | 1 29 libglib-2.0.so
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | Suppressions used:
INFO - PID 12811 | count bytes template
INFO - PID 12811 | 28 864 nsComponentManagerImpl
INFO - PID 12811 | 611 17713 libfontconfig.so
INFO - PID 12811 | 1 29 libglib-2.0.so
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | Suppressions used:
INFO - PID 12811 | count bytes template
INFO - PID 12811 | 28 864 nsComponentManagerImpl
INFO - PID 12811 | 611 17713 libfontconfig.so
INFO - PID 12811 | 1 29 libglib-2.0.so
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | -----------------------------------------------------
INFO - PID 12811 | Suppressions used:
INFO - PID 12811 | count bytes template
INFO - PID 12811 | 25 760 nsComponentManagerImpl
INFO - PID 12811 | 5 1040 mozJSComponentLoader::LoadModule
INFO - PID 12811 | 611 17509 libfontconfig.so
INFO - PID 12811 | 34 1496 _PR_Getfd
INFO - PID 12811 | 1 29 libglib-2.0.so
INFO - PID 12811 | -----------------------------------------------------
INFO - Browser exited with return code 0
INFO - PROCESS LEAKS None
INFO - Closing logging queue
INFO - queue closed
INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
INFO - LSan enabled.
INFO - LSan using suppression file /builds/worker/workspace/build/tests/web-platform/prefs/lsan_suppressions.txt
INFO - INFO | runtests.py | ASan running in default memory configuration
INFO - Setting up ssl
INFO - certutil |
INFO - certutil |
INFO - certutil |
INFO - Certificate Nickname Trust Attributes
INFO - SSL,S/MIME,JAR/XPI
INFO -
INFO - web-platform-tests CT,,
INFO -
INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmpJ2jSdI.mozrunner
INFO - Starting runner
INFO - PID 13456 | 1559327854937 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
INFO - PID 13456 | 1559327854938 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: telemetry
INFO - PID 13456 | 1559327854940 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
INFO - PID 13456 | 1559327854940 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
INFO - PID 13456 | 1559327902492 Marionette INFO Listening on port 2828
INFO - PID 13456 | console.info: services.settings: Initialize Remote Settings
INFO - Browser exited with return code -15
INFO - PROCESS LEAKS None
18:41:49 CRITICAL - Loading initial page http://web-platform.test:8000/testharness_runner.html failed. Ensure that the there are no other programs bound to this port and that your firewall rules or network setup does not prevent access.\eTraceback (most recent call last):
File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 132, in load_runner
self.dismiss_alert(lambda: self.marionette.navigate(url))
File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 180, in dismiss_alert
f()
File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 132, in <lambda>
self.dismiss_alert(lambda: self.marionette.navigate(url))
File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1467, in navigate
{"url": url})
File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 36, in _
m._handle_socket_failure()
File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 650, in _handle_socket_failure
reraise(exc, val, tb)
File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
return func(*args, *kwargs)
File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 590, in _send_message
msg = self.client.request(name, params)
File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 273, in request
return self.receive()
File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 159, in receive
raise socket.error("No data received over socket")
18:41:49 CRITICAL - error: No data received over socket
18:41:49 CRITICAL -
WARNING - Command left in command_queue during cleanup: u'init_failed', ()
INFO - Closing logging queue
INFO - queue closed
INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
INFO - LSan enabled.
INFO - LSan using suppression file /builds/worker/workspace/build/tests/web-platform/prefs/lsan_suppressions.txt
INFO - INFO | runtests.py | ASan running in default memory configuration
INFO - Setting up ssl
INFO - certutil |
INFO - certutil |
INFO - certutil |
INFO - Certificate Nickname Trust Attributes
INFO - SSL,S/MIME,JAR/XPI
INFO -
INFO - web-platform-tests CT,,
INFO -
INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmpdcJGgO.mozrunner
INFO - Starting runner
INFO - PID 13641 | 1559328118463 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
INFO - PID 13641 | 1559328118465 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: telemetry
INFO - PID 13641 | 1559328118466 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
INFO - PID 13641 | 1559328118466 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader
INFO - PID 13641 | 1559328146087 Marionette INFO Listening on port 2828
INFO - TEST-START | /css/css-typed-om/stylevalue-serialization/cssImageValue.html

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+2]

Assignee

Comment 2

•

5 years ago

There is nothing wrong with navigate() but the local web server serving this page:

[task 2019-05-31T18:41:49.978Z] 18:41:49 CRITICAL - Loading initial page http://web-platform.test:8000/testharness_runner.html failed. Ensure that the there are no other programs bound to this port and that your firewall rules or network setup does not prevent access.\eTraceback (most recent call last):

Moving for further investigation into the web-platform-tests component.

Component: Marionette → web-platform-tests

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+2]

Assignee

Comment 5

•

5 years ago

I see this locally now every time I run wpt tests. The problem here seems to be is:

06-24 08:11:16.690 10947 10974 I Gecko : FATAL ERROR: Non-local network connections are disabled and a connection attempt to web-platform.test (100.91.234.14) was made.
06-24 08:11:16.690 10947 10974 I Gecko : You should only access hostnames available via the test networking proxy (if running mochitests) or from a test-specific httpd.js server (if running xpcshell tests). Browser services should be disabled or redirected to a local server.

Running ifconfig my local IP is 100.91.234.14, which is also the setting in /etc/hosts/. I wonder why don't we use 127.0.0.1 or localhost here with a proper adb revers setting. That would at least also stop the problem for me with adb remount issues when switching the local IP too often.

Flags: needinfo?(james)

Henrik Skupin [:whimboo][⌚️UTC+2]

Assignee

Comment 6

•

5 years ago

Note, that when I change the code in fennec.py to:

new_hosts = make_hosts_file(config, "127.0.0.1") # moznetwork.get_ip())

it works fine.

Henrik Skupin [:whimboo][⌚️UTC+2]

Assignee

Comment 7

•

5 years ago

Maybe we should reopen bug 1560033, and discuss it over there?

James Graham [:jgraham]

Comment 8

•

5 years ago

If using the localhost ip works here I agree we should do that.

Flags: needinfo?(james)

Henrik Skupin [:whimboo][⌚️UTC+2]

Assignee

Comment 9

•

5 years ago

This should be fixed with bug 1560033.

Depends on: 1560033

Firefox Bug Husbandry Bot

Comment 10

•

5 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED

Closed: 5 years ago

Resolution: --- → INCOMPLETE

Henrik Skupin [:whimboo][⌚️UTC+2]

Assignee

Comment 11

•

5 years ago

Marking as fixed based on the landing of my patch over on bug 1560033. If it's not fixed feel free to reopen.

Assignee: nobody → hskupin

status-firefox70: --- → fixed

Priority: P5 → P1

Resolution: INCOMPLETE → FIXED

Summary: Intermittent wpt self.dismiss_alert(lambda: self.marionette.navigate(url)) → Intermittent wpt Loading initial page http://web-platform.test:8000/testharness_runner.html failed

Target Milestone: --- → mozilla70

Bugzilla

Quick Search

Intermittent wpt Loading initial page http://web-platform.test:8000/testharness_runner.html failed

Categories

(Testing :: web-platform-tests, defect, P1)

Tracking

(firefox70 fixed)

People

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

References

Details

(Keywords: intermittent-failure, regression)

Crash Data

Security

(public)

User Story

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Comment 7

Comment 8

Comment 9

Comment 10

Comment 11