Closed Bug 1690731 Opened 10 months ago Closed 1 month ago

Intermittent browser/base/content/test/performance/browser_startup.js | resource://gre/modules/BookmarkHTMLUtils.jsm is not allowed before handling user events -

Categories

(Firefox :: Bookmarks & History, defect, P5)

defect

Tracking

()

RESOLVED FIXED
95 Branch
Tracking Status
firefox95 --- fixed

People

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

Details

(Keywords: intermittent-failure, Whiteboard: [fxperf])

Attachments

(1 file)

Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=328774689&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/RTJtn-lGSDqGRu1C_vB6vw/runs/0/artifacts/public/logs/live_backing.log


[task 2021-02-04T00:00:33.010Z] 00:00:33     INFO - TEST-PASS | browser/base/content/test/performance/browser_startup.js | nsPlacesExpiration.js is not allowed before handling user events - 
[task 2021-02-04T00:00:33.012Z] 00:00:33     INFO - TEST-PASS | browser/base/content/test/performance/browser_startup.js | resource://gre/modules/Blocklist.jsm is not allowed before handling user events - 
[task 2021-02-04T00:00:33.012Z] 00:00:33     INFO - TEST-INFO | started process screencapture
[task 2021-02-04T00:00:33.148Z] 00:00:33     INFO - TEST-INFO | screencapture: exit 0
[task 2021-02-04T00:00:33.148Z] 00:00:33     INFO - Buffered messages logged at 00:00:32
[task 2021-02-04T00:00:33.148Z] 00:00:33     INFO - Entering test bound 
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - Buffered messages finished
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_startup.js | resource://gre/modules/BookmarkHTMLUtils.jsm is not allowed before handling user events - 
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - Stack trace:
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - 0 BG__initPlaces/<() ["resource:///modules/BrowserGlue.jsm":3053:14]
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - 1 InterpretGeneratorResume() ["self-hosted":1484:33]
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - 2 AsyncFunctionNext() ["self-hosted":690:26]
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-04T00:00:33.149Z] 00:00:33     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_startup.js | resource://gre/modules/Bookmarks.jsm is not allowed before handling user events -```
Status: NEW → RESOLVED
Closed: 9 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Component: General → Bookmarks & History

I think I've figured this one out. The logs show we're loading 4 jsms: BookmarkHTMLUtils.jsm, Bookmarks.jsm, PlacesBackups.jsm, PlacesSyncUtils.jsm and the service: mozilla.org/browser/nav-bookmarks-service;1.

Here's what I think is happening:

  • The telemetry gathering is wrapped in an Services.tm.idleDispatchToMainThread call which is triggered from _onFirstWindowLoaded (browser-delayed-startup-finished)
  • The test fails if this runs before sessionstore-windows-restored
  • On profiles I've seen recently, there's a reasonable gap between the browser-delayed-startup-finished and session-windows-restored notifications.
  • Whilst the CPU is normally reasonably busy during this time, I think there's a possibility depending on hardware & timing, that idle could kick in. When it does kick in:
    • Calling PlacesDBUtils.temetry() will initialise the database connection
    • This will also fire places-init-complete
    • Which will then start the migration of the database and load BookmarkHTMLUtils.jsm.

With bug 1649599, I think this is less likely to happen, since that reduces the time between browser-delayed-startup-finished and session-windows-restored.

However, I think we should move this idle dispatch to be one of the idle tasks on startup anyway - that puts it with the rest of the idle tasks, and removes the checks needed to make sure it only runs once.

Assignee: nobody → standard8
Whiteboard: [fxperf]
Pushed by mbanner@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c0a0a871cb91
Move Places telemetry startup to a scheduled task to ensure it runs after hanlding of user events has started. r=mak
Status: REOPENED → RESOLVED
Closed: 9 months ago1 month ago
Resolution: --- → FIXED
Target Milestone: --- → 95 Branch
You need to log in before you can comment on or make changes to this bug.