1810816 - Intermittent /resource-timing/resource_timing.worker.html | single tracking bug

Status: RESOLVED FIXED

(Core :: DOM: Workers, defect, P2)

Description

[Treeherder Bug Filer]

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

---

[task 2023-01-17T18:05:49.928Z] 18:05:49     INFO - TEST-START | /resource-timing/resource_timing.worker.html
[task 2023-01-17T18:05:49.945Z] 18:05:49     INFO - Closing window 61a5d3d6-7262-4876-bc30-c0181013e9fc
[task 2023-01-17T18:05:50.223Z] 18:05:50     INFO - PID 5140 | JavaScript error: , line 0: uncaught exception: Object
[task 2023-01-17T18:06:00.167Z] 18:06:00     INFO - 
[task 2023-01-17T18:06:00.167Z] 18:06:00     INFO - TEST-UNEXPECTED-TIMEOUT | /resource-timing/resource_timing.worker.html | Performance Resource Entries in workers - Test timed out
[task 2023-01-17T18:06:00.168Z] 18:06:00     INFO - TEST-UNEXPECTED-TIMEOUT | /resource-timing/resource_timing.worker.html | expected OK
[task 2023-01-17T18:06:00.168Z] 18:06:00     INFO - TEST-INFO took 10240ms
[task 2023-01-17T18:06:00.169Z] 18:06:00     INFO - PID 5140 | 1673978760167	Marionette	INFO	Stopped listening on port 40253
[task 2023-01-17T18:06:00.422Z] 18:06:00     INFO - PID 5140 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-01-17T18:06:00.423Z] 18:06:00     INFO - PID 5140 |           Blocker:  Waiting for ping task
[task 2023-01-17T18:06:00.423Z] 18:06:00     INFO - PID 5140 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-01-17T18:06:00.424Z] 18:06:00     INFO - PID 5140 |           State: (none)
[task 2023-01-17T18:06:00.429Z] 18:06:00     INFO - PID 5140 | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.429Z] 18:06:00     INFO - PID 5140 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-17T18:06:00.430Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-17T18:06:00.430Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-17T18:06:00.431Z] 18:06:00     INFO - PID 5140 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-17T18:06:00.431Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-17T18:06:00.431Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-17T18:06:00.431Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-17T18:06:00.431Z] 18:06:00     INFO - PID 5140 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-17T18:06:00.431Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-17T18:06:00.432Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-17T18:06:00.432Z] 18:06:00     INFO - PID 5140 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-17T18:06:00.433Z] 18:06:00     INFO - PID 5140 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-17T18:06:00.438Z] 18:06:00     INFO - PID 5140 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-01-17T18:06:00.439Z] 18:06:00     INFO - PID 5140 |           Blocker:  Waiting for ping task
[task 2023-01-17T18:06:00.440Z] 18:06:00     INFO - PID 5140 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-01-17T18:06:00.441Z] 18:06:00     INFO - PID 5140 |           State: (none)
[task 2023-01-17T18:06:00.442Z] 18:06:00     INFO - PID 5140 | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.444Z] 18:06:00     INFO - PID 5140 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-17T18:06:00.445Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-17T18:06:00.448Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-17T18:06:00.449Z] 18:06:00     INFO - PID 5140 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-17T18:06:00.450Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-17T18:06:00.450Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-17T18:06:00.450Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-17T18:06:00.452Z] 18:06:00     INFO - PID 5140 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-17T18:06:00.452Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-17T18:06:00.452Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-17T18:06:00.452Z] 18:06:00     INFO - PID 5140 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-17T18:06:00.453Z] 18:06:00     INFO - PID 5140 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-17T18:06:00.454Z] 18:06:00     INFO - PID 5140 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-01-17T18:06:00.455Z] 18:06:00     INFO - PID 5140 |           Blocker:  TelemetryController: shutting down
[task 2023-01-17T18:06:00.456Z] 18:06:00     INFO - PID 5140 |           Phase: profile-before-change-telemetry
[task 2023-01-17T18:06:00.457Z] 18:06:00     INFO - PID 5140 |           State: Error getting state: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange" at addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-17T18:06:00.458Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-17T18:06:00.459Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-17T18:06:00.459Z] 18:06:00     INFO - PID 5140 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-17T18:06:00.460Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-17T18:06:00.460Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-17T18:06:00.461Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-17T18:06:00.461Z] 18:06:00     INFO - PID 5140 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-17T18:06:00.462Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-17T18:06:00.462Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-17T18:06:00.463Z] 18:06:00     INFO - PID 5140 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-17T18:06:00.464Z] 18:06:00     INFO - PID 5140 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-17T18:06:00.464Z] 18:06:00     INFO - PID 5140 | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.465Z] 18:06:00     INFO - PID 5140 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-01-17T18:06:00.466Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-01-17T18:06:00.466Z] 18:06:00     INFO - PID 5140 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-01-17T18:06:00.467Z] 18:06:00     INFO - PID 5140 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-01-17T18:06:00.467Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-01-17T18:06:00.468Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-01-17T18:06:00.468Z] 18:06:00     INFO - PID 5140 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-01-17T18:06:00.469Z] 18:06:00     INFO - PID 5140 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-01-17T18:06:00.470Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-01-17T18:06:00.470Z] 18:06:00     INFO - PID 5140 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-01-17T18:06:00.471Z] 18:06:00     INFO - PID 5140 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:829:36
[task 2023-01-17T18:06:00.471Z] 18:06:00     INFO - PID 5140 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-01-17T18:06:00.472Z] 18:06:00     INFO - PID 5140 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.473Z] 18:06:00     INFO - PID 5140 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.473Z] 18:06:00     INFO - PID 5140 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.474Z] 18:06:00     INFO - PID 5140 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.475Z] 18:06:00     INFO - PID 5140 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-01-17T18:06:00.666Z] 18:06:00     INFO - Browser exited with return code 0
[task 2023-01-17T18:06:00.669Z] 18:06:00     INFO - Closing logging queue
[task 2023-01-17T18:06:00.670Z] 18:06:00     INFO - queue closed
[task 2023-01-17T18:06:00.712Z] 18:06:00     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmp3_hw6pwt
[task 2023-01-17T18:06:00.732Z] 18:06:00     INFO - PID 9466 | 1673978670735	Marionette	INFO	Marionette enabled
[task 2023-01-17T18:06:00.733Z] 18:06:00     INFO - PID 9466 | 1673978670738	Marionette	INFO	Listening on port 53425
[task 2023-01-17T18:06:00.733Z] 18:06:00     INFO - PID 9466 | console.error: ({})
[task 2023-01-17T18:06:00.734Z] 18:06:00     INFO - PID 9466 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpqp513z2i/search.json.mozlz4", (void 0)))
[task 2023-01-17T18:06:00.734Z] 18:06:00     INFO - PID 9466 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-17T18:06:00.735Z] 18:06:00     INFO - PID 9466 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-17T18:06:00.740Z] 18:06:00     INFO - PID 9466 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-17T18:06:00.741Z] 18:06:00     INFO - PID 9466 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-01-17T18:06:00.741Z] 18:06:00     INFO - PID 9466 | ALSA lib seq_hw.c:466:(snd_seq_hw_open) open /dev/snd/seq failed: No such file or directory
[task 2023-01-17T18:06:00.741Z] 18:06:00     INFO - Starting runner
[task 2023-01-17T18:06:01.524Z] 18:06:01     INFO - TEST-START | /resource-timing/resource_timing_content_length.html

Comment 1

[Cosmin Sabou [:CosminS]]

Context here: https://bugzilla.mozilla.org/show_bug.cgi?id=1351231#c28.

Comment 2

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

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

:edenchuang, since you are the author of the regressor, bug 1351231, could you take a look?

For more information, please visit auto_nag documentation.

Comment 3

[Intermittent Failures Robot]

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

** 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:

• autoland: 24
• mozilla-central: 9

Platform and build breakdown:

• linux1804-64-qr: 19
  • debug: 11
  • opt: 8
• windows10-64-2004-qr: 3
  • opt: 1
  • debug: 2
• linux1804-64-shippable-qr: 5
  • opt: 5
• linux1804-64-asan-qr: 4
  • opt: 4
• windows10-32-2004-shippable-qr: 1
  • opt: 1
• linux1804-64-ccov-qr: 1
  • opt: 1

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

Comment 4

[Eden Chuang[:edenchuang]]

After PFetch is enabled. ResourceTiming saving point is different from without PFetch.

Initially, Saving ResourceTiming is triggered by HttpChannelChild::OnStopRequest, then eventually, WorkerFetchResolver::OnResponseEnd is called to complete the resource fetching. There is a time difference between these two methods, so ResourceTiming would be ready when response.text() or response.blob() is called.

When PFetch is enabled, there is no actual channel in the content process. ResourceTiming saving point is moved to FetchChild::RecvOnResponseEnd(), which means there would be no time difference anymore between these methods. And the race appears between response.text()/response.blob() and ResourceTiming saving. And this is why we meet this intermittent failure.

I am working on a patch to resolve the race.

Comment 5

[Eden Chuang[:edenchuang]]

Attachment: Bug 1810816 - P1 Remove ResponseTiming from ResponseEndArgs. r=#dom-worker-reviewers

Comment 6

[Eden Chuang[:edenchuang]]

Attachment: Bug 1810816 - P2 Add new interface OnReportPerformanceTiming on FetchDriverObserver. r=#dom-worker-reviewers

Depends on D167936

Comment 7

[Eden Chuang[:edenchuang]]

Attachment: Bug 1810816 - P3 Report response timing for PFetch. r=#dom-worker-reviewers

Depends on D167937

Comment 8

[Eden Chuang[:edenchuang]]

Attachment: Bug 1810816 - P4 Report the preload response timing for ServiceWorker NavigationPreload. r=#dom-worker-reviewers

Depends on D167938

Comment 9

[Intermittent Failures Robot]

63 failures in 3914 pushes (0.016 failures/push) were associated with this bug in the last 7 days.

This is the #14 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:

• mozilla-central: 23
• autoland: 40

Platform and build breakdown:

• linux1804-64-qr: 40
  • debug: 21
  • opt: 19
• windows10-32-2004-shippable-qr: 1
  • opt: 1
• linux1804-64-shippable-qr: 13
  • opt: 13
• linux1804-64-ccov-qr: 1
  • opt: 1
• linux1804-64-asan-qr: 5
  • opt: 5
• windows10-64-2004-qr: 1
  • opt: 1
• linux1804-32-shippable-qr: 1
  • opt: 1
• linux1804-64-tsan-qr: 1
  • opt: 1

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

Comment 10

[Intermittent Failures Robot]

21 failures in 822 pushes (0.026 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 7
• autoland: 14

Platform and build breakdown:

• linux1804-64-qr: 11
  • debug: 8
  • opt: 3
• linux1804-64-shippable-qr: 5
  • opt: 5
• windows10-32-2004-qr: 1
  • opt: 1
• windows10-64-2004-qr: 1
  • debug: 1
• linux1804-64-asan-qr: 2
  • opt: 2
• linux1804-32-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810816&startday=2023-01-31&endday=2023-01-31&tree=all

Comment 12

[Intermittent Failures Robot]

64 failures in 3606 pushes (0.018 failures/push) were associated with this bug in the last 7 days.

This is the #12 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 42
• mozilla-central: 19
• try: 3

Platform and build breakdown:

• linux1804-64-qr: 33
  • debug: 23
  • opt: 10
• linux1804-64-ccov-qr: 2
  • opt: 2
• linux1804-64-asan-qr: 6
  • opt: 6
• macosx1015-64-qr: 1
  • debug: 1
• linux1804-64-shippable-qr: 11
  • opt: 11
• windows10-64-2004-qr: 2
  • debug: 2
• windows10-32-2004-qr: 7
  • opt: 6
  • debug: 1
• linux1804-32-shippable-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1810816&startday=2023-01-30&endday=2023-02-05&tree=all

Comment 13

[Serban Stanca [:SerbanS]]

There have been 61 total failures in the last 7 days.
Affected platforms are:

• 1 failure on linux1804-32-shippable-qr
• 6 failures on ```linux1804-64-asan-qr``
• 2 failures on linux1804-64-ccov-qr
• 31 failures on linux1804-64-qr
• 11 failures on linux1804-64-shippable-qr
• 1 failure on macosx1015-64-qr
• 9 failures on windows10-32-2004-qr

Recent failure log.

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 4

Platform and build breakdown:

• windows10-32-2004-qr: 1
  • debug: 1
• linux1804-64-qr: 3
  • debug: 3

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

Comment 15

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 4
• mozilla-central: 4

Platform and build breakdown:

• windows10-32-2004-qr: 3
  • opt: 2
  • debug: 1
• linux1804-64-qr: 4
  • debug: 4
• windows10-32-2004-shippable-qr: 1
  • opt: 1

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

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/0aea172f9dd3
P1 Remove ResponseTiming from ResponseEndArgs. r=dom-worker-reviewers,asuth
https://hg.mozilla.org/integration/autoland/rev/b52649243851
P2 Add new interface OnReportPerformanceTiming on FetchDriverObserver. r=dom-worker-reviewers,asuth
https://hg.mozilla.org/integration/autoland/rev/e5eacedc370d
P3 Report response timing for PFetch. r=dom-worker-reviewers,asuth
https://hg.mozilla.org/integration/autoland/rev/2479dc798994
P4 Report the preload response timing for ServiceWorker NavigationPreload. r=dom-worker-reviewers,asuth

Comment 17

[Natalia Csoregi [:nataliaCs]]

Backed out for causing high failure rate on /service-workers/service-worker/navigation-headers.https.html (based on failures per number of runs)

• backout: https://hg.mozilla.org/integration/autoland/rev/5fddaccf933d89f1b36bde8fba6873d0dc88a9f8
• push: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&revision=2479dc7989945cd526a3c4c6ef7d6210d437eeb1
• failure log: https://treeherder.mozilla.org/logviewer?job_id=406560900&repo=autoland&lineNumber=30906
• failure snippet:

[task 2023-02-22T19:34:13.524Z] 19:34:13     INFO - TEST-PASS | /service-workers/service-worker/navigation-headers.https.html | POST Navigation, same-origin with fallback service worker sets correct origin and referer headers. 
[task 2023-02-22T19:34:13.524Z] 19:34:13     INFO - TEST-UNEXPECTED-TIMEOUT | /service-workers/service-worker/navigation-headers.https.html | GET Navigation, same-origin with navpreload service worker sets correct origin and referer headers. - Test timed out
[task 2023-02-22T19:34:13.524Z] 19:34:13     INFO - 
[task 2023-02-22T19:34:13.524Z] 19:34:13     INFO - TEST-UNEXPECTED-NOTRUN | /service-workers/service-worker/navigation-headers.https.html | GET Navigation, same-origin with service worker that changes the request sets correct origin and referer headers. - expected PASS
[task 2023-02-22T19:34:13.524Z] 19:34:13     INFO - 
[task 2023-02-22T19:34:13.524Z] 19:34:13     INFO - TEST-UNEXPECTED-NOTRUN | /service-workers/service-worker/navigation-headers.https.html | POST Navigation, same-origin with service worker that changes the request sets correct origin and referer headers. - expected PASS
[task 2023-02-22T19:34:13.524Z] 19:34:13     INFO - 
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - TEST-UNEXPECTED-NOTRUN | /service-workers/service-worker/navigation-headers.https.html | GET Navigation, same-site with no service worker sets correct origin and referer headers. - expected PASS
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - 
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - TEST-UNEXPECTED-NOTRUN | /service-workers/service-worker/navigation-headers.https.html | POST Navigation, same-site with no service worker sets correct origin and referer headers. - expected PASS
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - 
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - TEST-UNEXPECTED-NOTRUN | /service-workers/service-worker/navigation-headers.https.html | GET Navigation, same-site with passthrough service worker sets correct origin and referer headers. - expected PASS
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - 
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - TEST-UNEXPECTED-NOTRUN | /service-workers/service-worker/navigation-headers.https.html | POST Navigation, same-site with passthrough service worker sets correct origin and referer headers. - expected FAIL
[task 2023-02-22T19:34:13.525Z] 19:34:13     INFO - TEST-INFO | expected FAIL

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/1f5e8fd35737
P1 Remove ResponseTiming from ResponseEndArgs. r=dom-worker-reviewers,asuth
https://hg.mozilla.org/integration/autoland/rev/2051ecee5fb9
P2 Add new interface OnReportPerformanceTiming on FetchDriverObserver. r=dom-worker-reviewers,asuth
https://hg.mozilla.org/integration/autoland/rev/819715a61b4b
P3 Report response timing for PFetch. r=dom-worker-reviewers,asuth
https://hg.mozilla.org/integration/autoland/rev/84da76cce01c
P4 Report the preload response timing for ServiceWorker NavigationPreload. r=dom-worker-reviewers,asuth

Comment 19

[Cristina Horotan [:chorotan]]

https://hg.mozilla.org/mozilla-central/rev/1f5e8fd35737
https://hg.mozilla.org/mozilla-central/rev/2051ecee5fb9
https://hg.mozilla.org/mozilla-central/rev/819715a61b4b
https://hg.mozilla.org/mozilla-central/rev/84da76cce01c

Comment 20

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 3

Platform and build breakdown:

• linux1804-64-qr: 1
  • debug: 1
• windows10-64-2004-qr: 2
  • debug: 1
  • opt: 1

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