Closed Bug 1816569 Opened 2 years ago Closed 3 months ago

Intermittent /notifications/getnotifications-across-processes.https.window.html | single tracking bug

Categories

(Core :: DOM: Notifications, defect, P5)

defect

Tracking

()

RESOLVED FIXED
134 Branch
Tracking Status
firefox-esr102 --- unaffected
firefox-esr115 --- wontfix
firefox-esr128 --- wontfix
firefox110 --- unaffected
firefox111 --- unaffected
firefox112 --- wontfix
firefox133 --- wontfix
firefox134 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 obsolete file)

Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=405490441&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KC_BqJG1QZOO18hLd66Xxg/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/KC_BqJG1QZOO18hLd66Xxg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2023-02-13T21:13:56.005Z] 21:13:55     INFO - TEST-PASS | /notifications/getnotifications-across-processes.https.window.html | Service worker test setup 
[task 2023-02-13T21:13:56.005Z] 21:13:56     INFO - TEST-UNEXPECTED-FAIL | /notifications/getnotifications-across-processes.https.window.html | Get notification created from window - assert_equals: There should be one stored notification expected 1 but got 0
[task 2023-02-13T21:13:56.005Z] 21:13:56     INFO - test_notification@https://web-platform.test:8443/notifications/getnotifications-sw.js:14:16
[task 2023-02-13T21:13:56.006Z] 21:13:56     INFO - .
[task 2023-02-13T21:13:56.006Z] 21:13:56     INFO - TEST-OK | /notifications/getnotifications-across-processes.https.window.html | took 482ms

:saschanaz, since you are the author of the regressor, bug 1781588, could you take a look?

For more information, please visit auto_nag documentation.

Flags: needinfo?(krosylight)

Appeared tier 1 here

Summary: Intermittent TVw [tier 2] /notifications/getnotifications-across-processes.https.window.html | single tracking bug → Intermittent /notifications/getnotifications-across-processes.https.window.html | single tracking bug

Set release status flags based on info from the regressing bug 1781588

Will try adding onclose to see what's happening.

Assignee: nobody → krosylight
Flags: needinfo?(krosylight)
Component: Notifications and Alerts → DOM: Notifications
Product: Toolkit → Core
Attachment #9384224 - Attachment is obsolete: true

This happen on m-c and beta/ESR too, so probably not kvstore backend specific. I wonder this is because of some IPC race, the main thread will send Notification:Save and then the service worker will call Notification:GetAll, but somehow the service worker's GetAll reaches earlier and thus it gets 0 instead of 1.

Confirming that would require some logging in NotificationDB and NotificationStorage, which already exists but is based on dump(). We can have a console instance instead. I'll file a bug for that.

Depends on: 1890329
Component: DOM: Push Subscriptions → DOM: Notifications

Comment #65 was correct, PUT/GET signals are in order and then GetAll/Save is happening in reverse. It turns out I incorrectly expected NotificationStorage to be singleton when I wrote this (although it already had the same logic before bug 1781588), but of course it's constructed for each process.

[task 2024-04-13T21:52:37.960Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationStorage: "PUT: https://web-platform.test:8443 {3864f430-afda-4ad6-af95-035f5a1f8f74}: Created from window"
[task 2024-04-13T21:52:37.962Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationStorage: "GET: https://web-platform.test:8443 "
[task 2024-04-13T21:52:37.967Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Received message: Notification:GetAll"
[task 2024-04-13T21:52:37.967Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Queueing task: getall"
[task 2024-04-13T21:52:37.967Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Task queue was not running, starting now..."
[task 2024-04-13T21:52:37.968Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Task, getting all"
[task 2024-04-13T21:52:37.968Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Finishing task: getall"
[task 2024-04-13T21:52:37.969Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "No more tasks to run, queue depleted"
[task 2024-04-13T21:52:37.969Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Received message: Notification:Save"
[task 2024-04-13T21:52:37.970Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Queueing task: save"
[task 2024-04-13T21:52:37.971Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Task queue was not running, starting now..."
[task 2024-04-13T21:52:37.972Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Task, saving"
[task 2024-04-13T21:52:37.986Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Finishing task: save"
[task 2024-04-13T21:52:37.987Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationStorage: "GET: https://web-platform.test:8443 "
[task 2024-04-13T21:52:37.987Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "No more tasks to run, queue depleted"
[task 2024-04-13T21:52:37.990Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Received message: Notification:GetAll"
[task 2024-04-13T21:52:37.990Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Queueing task: getall"
[task 2024-04-13T21:52:37.991Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Task queue was not running, starting now..."
[task 2024-04-13T21:52:37.992Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Task, getting all"
[task 2024-04-13T21:52:37.993Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "Finishing task: getall"
[task 2024-04-13T21:52:37.993Z] 21:52:37     INFO - PID 19216 | console.debug: NotificationDB: "No more tasks to run, queue depleted"

So my suggested work item is, maybe resolve showNotification only after actually putting into the DB?

Depends on: 1891705

This shouldn't happen in m-c after bug 1928702. Let's close this for now and see if the bot reopens it.

Status: NEW → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: