Closed Bug 1701411 Opened 4 years ago Closed 4 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /mathml/presentation-markup/spaces/mspace-children.html | expected PASS

Categories

(Core :: MathML, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=334648079&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KmhL7GpPQPi0grOjwsJx3Q/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KmhL7GpPQPi0grOjwsJx3Q/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2021-03-27T13:54:11.917Z] 13:54:11     INFO - TEST-START | /mathml/presentation-markup/spaces/mspace-children.html
[task 2021-03-27T13:54:11.932Z] 13:54:11     INFO - Setting pref mathml.scriptsizemultiplier_attribute.disabled (true)
[task 2021-03-27T13:54:11.948Z] 13:54:11     INFO - Setting pref mathml.scriptminsize_attribute.disabled (true)
[task 2021-03-27T13:54:11.961Z] 13:54:11     INFO - Setting pref mathml.deprecated_style_attributes.disabled (true)
[task 2021-03-27T13:54:11.972Z] 13:54:11     INFO - Setting pref mathml.deprecated_menclose_notation_radical.disabled (true)
[task 2021-03-27T13:54:11.982Z] 13:54:11     INFO - Setting pref mathml.mathsize_names.disabled (true)
[task 2021-03-27T13:54:11.995Z] 13:54:11     INFO - Setting pref mathml.mathspace_names.disabled (true)
[task 2021-03-27T13:54:12.005Z] 13:54:12     INFO - Setting pref mathml.mfrac_linethickness_names.disabled (true)
[task 2021-03-27T13:54:12.014Z] 13:54:12     INFO - Setting pref mathml.deprecated_alignment_attributes.disabled (true)
[task 2021-03-27T13:54:12.023Z] 13:54:12     INFO - Setting pref mathml.script_shift_attributes.disabled (true)
[task 2021-03-27T13:54:12.032Z] 13:54:12     INFO - Setting pref mathml.mfrac_bevelled_attribute.disabled (true)
[task 2021-03-27T13:54:12.048Z] 13:54:12     INFO - Setting pref mathml.mfenced_element.disabled (true)
[task 2021-03-27T13:54:12.058Z] 13:54:12     INFO - Setting pref layout.css.math-style.enabled (true)
[task 2021-03-27T13:54:12.093Z] 13:54:12     INFO - PID 8373 | 1616853252091	Marionette	INFO	Testing http://web-platform.test:8000/mathml/presentation-markup/spaces/mspace-children.html == http://web-platform.test:8000/mathml/presentation-markup/spaces/mspace-children-ref.html
[task 2021-03-27T13:54:32.080Z] 13:54:32     INFO - TEST-UNEXPECTED-TIMEOUT | /mathml/presentation-markup/spaces/mspace-children.html | expected PASS
[task 2021-03-27T13:54:32.081Z] 13:54:32     INFO - TEST-INFO took 20163ms
[task 2021-03-27T13:54:32.096Z] 13:54:32     INFO - PID 8373 | 1616853272094	Marionette	INFO	Stopped listening on port 49984
[task 2021-03-27T13:54:34.048Z] 13:54:34     INFO - PID 8373 | console.error: "Could not load engine ddg@search.mozilla.org: TypeError: can't access property \"installBuiltinAddon\", AddonManagerInternal._getProviderByName(...) is undefined"
[task 2021-03-27T13:54:34.048Z] 13:54:34     INFO - PID 8373 | console.error: "Could not load engine ebay@search.mozilla.org: TypeError: can't access property \"installBuiltinAddon\", AddonManagerInternal._getProviderByName(...) is undefined"
[task 2021-03-27T13:54:34.052Z] 13:54:34     INFO - PID 8373 | console.warn: SearchService: "_init: abandoning init due to shutting down"
[task 2021-03-27T13:54:34.061Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/ExtensionParent.jsm, line 1738: AbortError: IOUtils: Shutting down and refusing additional I/O tasks
[task 2021-03-27T13:54:34.065Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/ExtensionParent.jsm, line 1738: AbortError: IOUtils: Shutting down and refusing additional I/O tasks
[task 2021-03-27T13:54:34.066Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: uncaught exception: 2147500036
[task 2021-03-27T13:54:34.070Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: uncaught exception: 2147500036
[task 2021-03-27T13:54:34.070Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: uncaught exception: 2147500036
[task 2021-03-27T13:54:34.070Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: uncaught exception: 2147500036
[task 2021-03-27T13:54:34.070Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: uncaught exception: 2147500036
[task 2021-03-27T13:54:34.070Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: uncaught exception: 2147500036
[task 2021-03-27T13:54:34.070Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/CrashMonitor.jsm, line 201: AbortError: IOUtils: Shutting down and refusing additional I/O tasks
[task 2021-03-27T13:54:34.072Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/ExtensionParent.jsm, line 1738: AbortError: IOUtils: Shutting down and refusing additional I/O tasks
[task 2021-03-27T13:54:34.072Z] 13:54:34     INFO - PID 8373 | JavaScript error: resource://gre/modules/JSONFile.jsm, line 196: Error: Data is not ready.
[task 2021-03-27T13:54:34.483Z] 13:54:34     INFO - PID 8373 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-03-27T13:54:34.523Z] 13:54:34     INFO - Browser exited with return code 0
[task 2021-03-27T13:54:34.524Z] 13:54:34     INFO - PROCESS LEAKS None
[task 2021-03-27T13:54:34.526Z] 13:54:34     INFO - Closing logging queue
[task 2021-03-27T13:54:34.527Z] 13:54:34     INFO - queue closed
[task 2021-03-27T13:54:34.546Z] 13:54:34     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmp6ufgj8dk
[task 2021-03-27T13:54:34.561Z] 13:54:34     INFO - Starting runner
[task 2021-03-27T13:54:35.159Z] 13:54:35     INFO - PID 8800 | 1616853275158	Marionette	INFO	Marionette enabled
[task 2021-03-27T13:54:35.401Z] 13:54:35     INFO - PID 8581 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmp546c9me1/search.json.mozlz4", (void 0)))
[task 2021-03-27T13:54:36.477Z] 13:54:36     INFO - PID 8581 | 1616853276476	Marionette	INFO	Listening on port 56238
[task 2021-03-27T13:54:36.529Z] 13:54:36     INFO - TEST-START | /mathml/relations/html5-tree/class-1.html
<...>
[task 2021-03-27T13:55:39.033Z] 13:55:39     INFO - No more tests
[task 2021-03-27T13:55:39.053Z] 13:55:39     INFO - PID 11469 | 1616853339051	Marionette	INFO	Stopped listening on port 54002
[task 2021-03-27T13:55:39.557Z] 13:55:39     INFO - Browser exited with return code 0
[task 2021-03-27T13:55:39.559Z] 13:55:39     INFO - PROCESS LEAKS None
[task 2021-03-27T13:55:39.560Z] 13:55:39     INFO - Closing logging queue
[task 2021-03-27T13:55:39.560Z] 13:55:39     INFO - queue closed
[task 2021-03-27T13:55:39.561Z] 13:55:39     INFO - PROCESS LEAKS None
[task 2021-03-27T13:55:39.578Z] 13:55:39     INFO - Got 1 unexpected results, with 0 unexpected passes
[task 2021-03-27T13:55:39.578Z] 13:55:39     INFO - SUITE-END | took 995s
[task 2021-03-27T13:55:39.635Z] 13:55:39     INFO - Removed font: Ahem.ttf
[task 2021-03-27T13:55:39.699Z] 13:55:39     INFO - Closing logging queue
[task 2021-03-27T13:55:39.700Z] 13:55:39     INFO - queue closed
[task 2021-03-27T13:55:40.163Z] 13:55:40    ERROR - Return code: 1
[task 2021-03-27T13:55:40.164Z] 13:55:40    ERROR - Got 1 unexpected statuses
[task 2021-03-27T13:55:40.164Z] 13:55:40  WARNING - # TBPL WARNING #
[task 2021-03-27T13:55:40.164Z] 13:55:40  WARNING - setting return code to 1
[task 2021-03-27T13:55:40.165Z] 13:55:40     INFO - Running post-action listener: _package_coverage_data
[task 2021-03-27T13:55:40.165Z] 13:55:40     INFO - Running post-action listener: _resource_record_post_action
[task 2021-03-27T13:55:40.165Z] 13:55:40     INFO - Running post-action listener: process_java_coverage_data
[task 2021-03-27T13:55:40.165Z] 13:55:40     INFO - Running post-action listener: stop_device
[task 2021-03-27T13:55:40.166Z] 13:55:40     INFO - [mozharness: 2021-03-27 13:55:40.165379Z] Finished run-tests step (success)
[task 2021-03-27T13:55:40.166Z] 13:55:40     INFO - Running post-run listener: _resource_record_post_run
[task 2021-03-27T13:55:40.284Z] 13:55:40     INFO - Total resource usage - Wall time: 1028s; CPU: 44%; Read bytes: 0; Write bytes: 5067390976; Read time: 0; Write time: 29171588
[task 2021-03-27T13:55:40.284Z] 13:55:40     INFO - TinderboxPrint: CPU usage<br/>43.7%
[task 2021-03-27T13:55:40.284Z] 13:55:40     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2021-03-27T13:55:40.284Z] 13:55:40     INFO - TinderboxPrint: I/O write bytes / time<br/>5,067,390,976 / 29,171,588
[task 2021-03-27T13:55:40.284Z] 13:55:40     INFO - TinderboxPrint: CPU idle<br/>1,050.5 (25.8%)
[task 2021-03-27T13:55:40.284Z] 13:55:40     INFO - TinderboxPrint: CPU iowait<br/>1,242.5 (30.6%)
[task 2021-03-27T13:55:40.284Z] 13:55:40     INFO - TinderboxPrint: CPU system<br/>367.8 (9.0%)
[task 2021-03-27T13:55:40.285Z] 13:55:40     INFO - TinderboxPrint: CPU user<br/>1,391.1 (34.2%)
[task 2021-03-27T13:55:40.285Z] 13:55:40     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2021-03-27T13:55:40.285Z] 13:55:40     INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-03-27T13:55:40.286Z] 13:55:40     INFO - start-emulator - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-03-27T13:55:40.286Z] 13:55:40     INFO - verify-device - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-03-27T13:55:40.287Z] 13:55:40     INFO - install - Wall time: 14s; CPU: 25%; Read bytes: 0; Write bytes: 544768; Read time: 0; Write time: 0
[task 2021-03-27T13:55:40.296Z] 13:55:40     INFO - run-tests - Wall time: 1014s; CPU: 44%; Read bytes: 0; Write bytes: 5066846208; Read time: 0; Write time: 29171588
[task 2021-03-27T13:55:40.519Z] 13:55:40  WARNING - returning nonzero exit status 1
[task 2021-03-27T13:55:40.553Z] cleanup
[task 2021-03-27T13:55:40.553Z] + cleanup
[task 2021-03-27T13:55:40.553Z] + local rv=1
[task 2021-03-27T13:55:40.553Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2021-03-27T13:55:40.553Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2021-03-27T13:55:40.555Z] + '[' ']'
[task 2021-03-27T13:55:40.555Z] + true
[task 2021-03-27T13:55:40.555Z] + cleanup_xvfb
[task 2021-03-27T13:55:40.556Z] ++ pidof Xvfb
[task 2021-03-27T13:55:40.577Z] + local xvfb_pid=50
[task 2021-03-27T13:55:40.577Z] + local vnc=false
[task 2021-03-27T13:55:40.577Z] + local interactive=false
[task 2021-03-27T13:55:40.597Z] + '[' -n 50 ']'
[task 2021-03-27T13:55:40.598Z] + [[ false == false ]]
[task 2021-03-27T13:55:40.598Z] + [[ false == false ]]
[task 2021-03-27T13:55:40.599Z] + kill 50
[task 2021-03-27T13:55:40.599Z] + screen -XS xvfb quit
[task 2021-03-27T13:55:40.599Z] + exit 1
[taskcluster 2021-03-27 13:55:40.946Z] === Task Finished ===
[taskcluster 2021-03-27 13:55:46.953Z] Unsuccessful task run with exit code: 1 completed in 1485.122 seconds```
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.