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

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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 -```

Comment 1

[Intermittent Failures Robot]

1 failures in 3966 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• macosx1014-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-02-01&endday=2021-02-07&tree=all

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 3

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

New occurrence: https://treeherder.mozilla.org/logviewer?job_id=335141627&repo=try

Comment 4

[Intermittent Failures Robot]

1 failures in 3125 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• macosx1014-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-03-29&endday=2021-04-04&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 3224 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• macosx1014-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-04-19&endday=2021-04-25&tree=all

Comment 6

[Intermittent Failures Robot]

1 failures in 3706 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• macosx1014-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-04-26&endday=2021-05-02&tree=all

Comment 7

[Intermittent Failures Robot]

5 failures in 3279 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 4
• mozilla-beta: 1

Platform and build breakdown:

• linux1804-64-devedition: 1
  • opt: 1
• macosx1014-64-devedition-qr: 4
  • opt: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-05-03&endday=2021-05-09&tree=all

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 4

Platform and build breakdown:

• linux1804-64-devedition: 1
  • opt: 1
• macosx1014-64-devedition-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-05-17&endday=2021-05-23&tree=all

Comment 9

[Intermittent Failures Robot]

1 failures in 2908 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• macosx1014-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-05-24&endday=2021-05-30&tree=all

Comment 10

[Intermittent Failures Robot]

1 failures in 3065 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• macosx1015-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-05-31&endday=2021-06-06&tree=all

Comment 11

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 2

Platform and build breakdown:

• macosx1015-64-devedition-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-06-07&endday=2021-06-13&tree=all

Comment 12

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 3

Platform and build breakdown:

• macosx1015-64-devedition-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-06-14&endday=2021-06-20&tree=all

Comment 13

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 2

Platform and build breakdown:

• macosx1015-64-devedition-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-06-21&endday=2021-06-27&tree=all

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1

Platform and build breakdown:

• macosx1015-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-06-28&endday=2021-07-04&tree=all

Comment 15

[Intermittent Failures Robot]

5 failures in 2387 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 5

Platform and build breakdown:

• macosx1015-64-devedition-qr: 4
  • opt: 4
• linux1804-64-devedition: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-07-05&endday=2021-07-11&tree=all

Comment 16

[Intermittent Failures Robot]

12 failures in 2224 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 7
• mozilla-beta: 5

Platform and build breakdown:

• macosx1015-64-devedition-qr: 12
  • opt: 12

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-07-12&endday=2021-07-18&tree=all

Comment 17

[Intermittent Failures Robot]

15 failures in 2940 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 6
• mozilla-beta: 9

Platform and build breakdown:

• macosx1015-64-devedition-qr: 14
  • opt: 14
• linux1804-64-devedition: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-07-19&endday=2021-07-25&tree=all

Comment 18

[Intermittent Failures Robot]

18 failures in 3131 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 13
• try: 5

Platform and build breakdown:

• macosx1015-64-devedition-qr: 17
  • opt: 17
• linux1804-64-devedition: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-07-26&endday=2021-08-01&tree=all

Comment 19

[Intermittent Failures Robot]

7 failures in 2829 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 7

Platform and build breakdown:

• macosx1015-64-devedition-qr: 7
  • opt: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-08-02&endday=2021-08-08&tree=all

Comment 20

[Intermittent Failures Robot]

15 failures in 3025 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 4
• mozilla-beta: 11

Platform and build breakdown:

• macosx1015-64-devedition-qr: 15
  • opt: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-08-09&endday=2021-08-15&tree=all

Comment 21

[Intermittent Failures Robot]

26 failures in 2899 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 10
• mozilla-beta: 16

Platform and build breakdown:

• macosx1015-64-devedition-qr: 25
  • opt: 25
• linux1804-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-08-16&endday=2021-08-22&tree=all

Comment 22

[Intermittent Failures Robot]

24 failures in 2580 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 13
• try: 11

Platform and build breakdown:

• macosx1015-64-devedition-qr: 22
  • opt: 22
• linux1804-64-devedition-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-08-23&endday=2021-08-29&tree=all

Comment 23

[Intermittent Failures Robot]

6 failures in 3084 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 6

Platform and build breakdown:

• macosx1015-64-devedition-qr: 6
  • opt: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-08-30&endday=2021-09-05&tree=all

Comment 24

[Intermittent Failures Robot]

19 failures in 3266 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 15
• try: 4

Platform and build breakdown:

• macosx1015-64-devedition-qr: 17
  • opt: 17
• linux1804-64-devedition-qr: 1
  • opt: 1
• windows10-64-2004-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-09-06&endday=2021-09-12&tree=all

Comment 25

[Intermittent Failures Robot]

14 failures in 3375 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 10
• try: 4

Platform and build breakdown:

• macosx1015-64-devedition-qr: 13
  • opt: 13
• linux1804-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-09-13&endday=2021-09-19&tree=all

Comment 26

[Intermittent Failures Robot]

19 failures in 2873 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 5
• mozilla-beta: 14

Platform and build breakdown:

• macosx1015-64-devedition-qr: 18
  • opt: 18
• linux1804-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-09-20&endday=2021-09-26&tree=all

Comment 27

[Intermittent Failures Robot]

6 failures in 3376 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 3
• try: 3

Platform and build breakdown:

• macosx1015-64-devedition-qr: 6
  • opt: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-09-27&endday=2021-10-03&tree=all

Comment 28

[Intermittent Failures Robot]

23 failures in 3626 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 6
• mozilla-beta: 17

Platform and build breakdown:

• linux1804-64-devedition-qr: 2
  • opt: 2
• macosx1015-64-devedition-qr: 21
  • opt: 21

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-10-04&endday=2021-10-10&tree=all

Comment 29

[Intermittent Failures Robot]

30 failures in 3315 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

This is the #45 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• try: 7
• mozilla-beta: 13
• autoland: 6
• mozilla-central: 4

Platform and build breakdown:

• macosx1015-64-devedition-qr: 18
  • opt: 18
• macosx1015-64-qr: 1
  • opt: 1
• windows10-64-2004-devedition-qr: 1
  • opt: 1
• linux1804-64-asan-qr: 2
  • opt: 2
• windows10-64-2004-asan-qr: 4
  • opt: 4
• linux1804-64-shippable-qr: 1
  • opt: 1
• macosx1100-64-shippable-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-10-11&endday=2021-10-17&tree=all

Comment 30

[Mark Banner (:standard8)]

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.

Comment 31

[Mark Banner (:standard8)]

Attachment: Bug 1690731 - Move Places telemetry startup to a scheduled task to ensure it runs after hanlding of user events has started. r?mak!

Comment 32

[Pulsebot]

Pushed by [e-mail]:
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

Comment 33

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/c0a0a871cb91

Comment 34

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 3

Platform and build breakdown:

• macosx1015-64-devedition-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1690731&startday=2021-10-18&endday=2021-10-24&tree=all