Closed Bug 1550034 Opened 1 year ago Closed 1 year ago

Intermittent browser/base/content/test/performance/browser_startup_content_mainthreadio.js | unused whitelist entry Web Content: /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi -

Categories

(Firefox :: General, defect, P5)

defect

Tracking

()

RESOLVED FIXED
Firefox 68
Tracking Status
firefox-esr60 --- unaffected
firefox67 --- unaffected
firefox68 --- fixed

People

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

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=245302323&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/bLT8082dQT-VPNTqkjWwCw/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://queue.taskcluster.net/v1/task/bLT8082dQT-VPNTqkjWwCw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


TEST-START | browser/base/content/test/performance/browser_startup_content_mainthreadio.js
[task 2019-05-08T11:13:44.680Z] 11:13:44 INFO - TEST-INFO | started process screentopng
[task 2019-05-08T11:13:45.372Z] 11:13:45 INFO - TEST-INFO | screentopng: exit 0
[task 2019-05-08T11:13:45.373Z] 11:13:45 INFO - Buffered messages logged at 11:13:44
[task 2019-05-08T11:13:45.374Z] 11:13:45 INFO - Entering test bound
[task 2019-05-08T11:13:45.376Z] 11:13:45 INFO - whitelisted paths for Web Content process:
[task 2019-05-08T11:13:45.377Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/omni.ja - stat: 1
[task 2019-05-08T11:13:45.378Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/omni.ja - stat: 1
[task 2019-05-08T11:13:45.379Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/chrome.manifest - stat: 1, close: 1
[task 2019-05-08T11:13:45.379Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest - stat: 1, close: 1
[task 2019-05-08T11:13:45.380Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi - stat: 1
[task 2019-05-08T11:13:45.380Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi - stat: 1
[task 2019-05-08T11:13:45.381Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | Found profile for Web Content process -
[task 2019-05-08T11:13:45.382Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/omni.ja
[task 2019-05-08T11:13:45.383Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/omni.ja
[task 2019-05-08T11:13:45.385Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/chrome.manifest
[task 2019-05-08T11:13:45.387Z] 11:13:45 INFO - (NSPRIOInterposer) close - /builds/worker/workspace/build/application/firefox/chrome.manifest
[task 2019-05-08T11:13:45.391Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest
[task 2019-05-08T11:13:45.392Z] 11:13:45 INFO - (NSPRIOInterposer) close - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest
[task 2019-05-08T11:13:45.393Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi
[task 2019-05-08T11:13:45.395Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/omni.ja as many times as expected in Web Content process -
[task 2019-05-08T11:13:45.396Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/omni.ja as many times as expected in Web Content process -
[task 2019-05-08T11:13:45.398Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/chrome.manifest as many times as expected in Web Content process -
[task 2019-05-08T11:13:45.399Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | close on /builds/worker/workspace/build/application/firefox/chrome.manifest as many times as expected in Web Content process -
[task 2019-05-08T11:13:45.403Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/chrome.manifest as many times as expected in Web Content process -
[task 2019-05-08T11:13:45.406Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | close on /builds/worker/workspace/build/application/firefox/browser/chrome.manifest as many times as expected in Web Content process -
[task 2019-05-08T11:13:45.408Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi as many times as expected in Web Content process -
[task 2019-05-08T11:13:45.409Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi allowed 1 more times in Web Content process -
[task 2019-05-08T11:13:45.410Z] 11:13:45 INFO - Buffered messages finished
[task 2019-05-08T11:13:45.415Z] 11:13:45 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | unused whitelist entry Web Content: /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi -
[task 2019-05-08T11:13:45.416Z] 11:13:45 INFO - Stack trace:
[task 2019-05-08T11:13:45.417Z] 11:13:45 INFO - chrome://mochikit/content/browser-test.js:test_ok:1314
[task 2019-05-08T11:13:45.423Z] 11:13:45 INFO - chrome://mochitests/content/browser/browser/base/content/test/performance/browser_startup_content_mainthreadio.js:null:399
[task 2019-05-08T11:13:45.424Z] 11:13:45 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1116
[task 2019-05-08T11:13:45.425Z] 11:13:45 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1144
[task 2019-05-08T11:13:45.426Z] 11:13:45 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1000
[task 2019-05-08T11:13:45.427Z] 11:13:45 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
[task 2019-05-08T11:13:45.429Z] 11:13:45 INFO - whitelisted paths for Privileged Content process:
[task 2019-05-08T11:13:45.430Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/omni.ja - stat: 1
[task 2019-05-08T11:13:45.431Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/omni.ja - stat: 1
[task 2019-05-08T11:13:45.432Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/chrome.manifest - stat: 1, close: 1
[task 2019-05-08T11:13:45.434Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest - stat: 1, close: 1
[task 2019-05-08T11:13:45.435Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi - stat: 1
[task 2019-05-08T11:13:45.436Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | Found profile for Privileged Content process -
[task 2019-05-08T11:13:45.438Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/omni.ja
[task 2019-05-08T11:13:45.439Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/omni.ja
[task 2019-05-08T11:13:45.440Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/chrome.manifest
[task 2019-05-08T11:13:45.442Z] 11:13:45 INFO - (NSPRIOInterposer) close - /builds/worker/workspace/build/application/firefox/chrome.manifest
[task 2019-05-08T11:13:45.443Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest
[task 2019-05-08T11:13:45.445Z] 11:13:45 INFO - (NSPRIOInterposer) close - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest
[task 2019-05-08T11:13:45.448Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi
[task 2019-05-08T11:13:45.449Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/omni.ja as many times as expected in Privileged Content process -
[task 2019-05-08T11:13:45.450Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/omni.ja as many times as expected in Privileged Content process -
[task 2019-05-08T11:13:45.451Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/chrome.manifest as many times as expected in Privileged Content process -
[task 2019-05-08T11:13:45.454Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | close on /builds/worker/workspace/build/application/firefox/chrome.manifest as many times as expected in Privileged Content process -
[task 2019-05-08T11:13:45.455Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/chrome.manifest as many times as expected in Privileged Content process -
[task 2019-05-08T11:13:45.456Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | close on /builds/worker/workspace/build/application/firefox/browser/chrome.manifest as many times as expected in Privileged Content process -
[task 2019-05-08T11:13:45.459Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi as many times as expected in Privileged Content process -
[task 2019-05-08T11:13:45.460Z] 11:13:45 INFO - whitelisted paths for WebExtensions process:
[task 2019-05-08T11:13:45.462Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/omni.ja - stat: 1
[task 2019-05-08T11:13:45.462Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/omni.ja - stat: 1
[task 2019-05-08T11:13:45.464Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/chrome.manifest - stat: 1, close: 1
[task 2019-05-08T11:13:45.467Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest - stat: 1, close: 1
[task 2019-05-08T11:13:45.468Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi - stat: 1
[task 2019-05-08T11:13:45.471Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi - stat: 1
[task 2019-05-08T11:13:45.472Z] 11:13:45 INFO - /builds/worker/workspace/build/application/firefox/browser/features/screenshots@mozilla.org.xpi - close: 1
[task 2019-05-08T11:13:45.479Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | Found profile for WebExtensions process -
[task 2019-05-08T11:13:45.480Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/omni.ja
[task 2019-05-08T11:13:45.481Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/omni.ja
[task 2019-05-08T11:13:45.482Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/chrome.manifest
[task 2019-05-08T11:13:45.484Z] 11:13:45 INFO - (NSPRIOInterposer) close - /builds/worker/workspace/build/application/firefox/chrome.manifest
[task 2019-05-08T11:13:45.485Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest
[task 2019-05-08T11:13:45.487Z] 11:13:45 INFO - (NSPRIOInterposer) close - /builds/worker/workspace/build/application/firefox/browser/chrome.manifest
[task 2019-05-08T11:13:45.490Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi
[task 2019-05-08T11:13:45.491Z] 11:13:45 INFO - (NSPRIOInterposer) stat - /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi
[task 2019-05-08T11:13:45.492Z] 11:13:45 INFO - (NSPRIOInterposer) close - /builds/worker/workspace/build/application/firefox/browser/features/screenshots@mozilla.org.xpi
[task 2019-05-08T11:13:45.495Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/omni.ja as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.497Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/omni.ja as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.519Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/chrome.manifest as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.520Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | close on /builds/worker/workspace/build/application/firefox/chrome.manifest as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.523Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/chrome.manifest as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.524Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | close on /builds/worker/workspace/build/application/firefox/browser/chrome.manifest as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.526Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/features/webcompat@mozilla.org.xpi as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.527Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | stat on /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.529Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | close on /builds/worker/workspace/build/application/firefox/browser/features/screenshots@mozilla.org.xpi as many times as expected in WebExtensions process -
[task 2019-05-08T11:13:45.530Z] 11:13:45 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | No unexpected main thread I/O during startup -
[task 2019-05-08T11:13:45.536Z] 11:13:45 INFO - Leaving test bound
[task 2019-05-08T11:13:45.538Z] 11:13:45 INFO - GECKO(5311) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2019-05-08T11:13:45.539Z] 11:13:45 INFO - GECKO(5311) | MEMORY STAT | vsize 3176MB | residentFast 530MB | heapAllocated 305MB
[task 2019-05-08T11:13:45.547Z] 11:13:45 INFO - TEST-OK | browser/base/content/test/performance/browser_startup_content_mainthreadio.js | took 193ms
[task 2019-05-08T11:13:45.549Z] 11:13:45 INFO - checking window state
[task 2019-05-08T11:13:45.550Z] 11:13:45 INFO - TEST-START | browser/base/content/test/performance/browser_startup_content_mainthreadio.js

This seems to be perma fail on windows10-aarch64. It's also perma fail on devedition (already covered by bug 1550769).

And then "browser_startup_content_mainthreadio.js | unused whitelist entry Web Content: /builds/worker/workspace/build/application/firefox/browser/features/formautofill@mozilla.org.xpi" is most of the remaining failures; we I think we should just mark that whitelist entry as ignoreIfUnused.

This patch contains the following changes:

  • upload a startup profile when there are unused mainthread I/O whitelist entries,
  • avoid 'unused whitelist entry' failures in devedition beta builds (where the IOInterposer is ifdef'ed out) while keeping coverage that ensures we are able to produce valid startup profiles,
  • completely disable on Windows Arm64 where the IO interposer is broken,
  • mark as ignoreIfUnused the whitelist entry that caused most intermittent failures.
Assignee: nobody → florian
Pushed by fqueze@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/742a8ae0110d
avoid most failures of the browser_startup_mainthreadio.js and browser_startup_content_mainthreadio.js tests, r=mconley.
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 68

We'll want this on the mozilla-beta tree too, but this is test-only so I'm not requesting approval.

Keywords: checkin-needed
You need to log in before you can comment on or make changes to this bug.