1799574 - Intermittent /IndexedDB/keypath-exceptions.htm | single tracking bug

Status: RESOLVED INCOMPLETE

(Core :: Storage: IndexedDB, defect, P5)

Description

[Treeherder Bug Filer]

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

---

INFO - TEST-PASS | /IndexedDB/keypath-exceptions.htm | Key path evaluation: Exceptions from non-enumerable getters on prototype 
[task 2022-11-08T00:05:19.421Z] 00:05:19     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/keypath-exceptions.htm | Key path evaluation: Exceptions from enumerable getters on prototype - Test timed out
[task 2022-11-08T00:05:19.422Z] 00:05:19     INFO - 
[task 2022-11-08T00:05:19.422Z] 00:05:19     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/keypath-exceptions.htm | Array key conversion should not invoke prototype getters - Test timed out
[task 2022-11-08T00:05:19.423Z] 00:05:19     INFO - TEST-UNEXPECTED-TIMEOUT | /IndexedDB/keypath-exceptions.htm | expected OK
[task 2022-11-08T00:05:19.423Z] 00:05:19     INFO - TEST-INFO took 10077ms
[task 2022-11-08T00:05:19.425Z] 00:05:19     INFO - PID 5524 | 1667865919420	Marionette	INFO	Stopped listening on port 49920
[task 2022-11-08T00:05:24.594Z] 00:05:24     INFO - PID 5524 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-08T00:05:24.597Z] 00:05:24     INFO - PID 5524 |           Blocker:  Waiting for ping task
[task 2022-11-08T00:05:24.597Z] 00:05:24     INFO - PID 5524 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-11-08T00:05:24.598Z] 00:05:24     INFO - PID 5524 |           State: (none)
[task 2022-11-08T00:05:24.598Z] 00:05:24     INFO - PID 5524 | 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 2022-11-08T00:05:24.600Z] 00:05:24     INFO - PID 5524 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-08T00:05:24.600Z] 00:05:24     INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-08T00:05:24.601Z] 00:05:24     INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-08T00:05:24.602Z] 00:05:24     INFO - PID 5524 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-08T00:05:24.602Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-08T00:05:24.603Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-08T00:05:24.603Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-08T00:05:24.604Z] 00:05:24     INFO - PID 5524 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:103:5
[task 2022-11-08T00:05:24.604Z] 00:05:24     INFO - PID 5524 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:63:33
[task 2022-11-08T00:05:24.605Z] 00:05:24     INFO - PID 5524 | _submitPingLogic@resource://gre/modules/TelemetryControllerParent.jsm:554:48
[task 2022-11-08T00:05:24.605Z] 00:05:24     INFO - PID 5524 | send@resource://gre/modules/TelemetryControllerParent.jsm:642:24
[task 2022-11-08T00:05:24.606Z] 00:05:24     INFO - PID 5524 | submitExternalPing@resource://gre/modules/TelemetryControllerParent.jsm:182:17
[task 2022-11-08T00:05:24.606Z] 00:05:24     INFO - PID 5524 | sendPing@resource://gre/modules/EventPing.jsm:51:30
[task 2022-11-08T00:05:24.607Z] 00:05:24     INFO - PID 5524 | _submitPing@resource://gre/modules/EventPing.jsm:229:12
[task 2022-11-08T00:05:24.608Z] 00:05:24     INFO - PID 5524 | shutdown@resource://gre/modules/EventPing.jsm:112:10
[task 2022-11-08T00:05:24.608Z] 00:05:24     INFO - PID 5524 | _cleanupOnShutdown@resource://gre/modules/TelemetryControllerParent.jsm:954:31
[task 2022-11-08T00:05:24.609Z] 00:05:24     INFO - PID 5524 | shutdown/<@resource://gre/modules/TelemetryControllerParent.jsm:1024:24
[task 2022-11-08T00:05:24.609Z] 00:05:24     INFO - PID 5524 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-08T00:05:24.643Z] 00:05:24     INFO - PID 5524 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-08T00:05:24.643Z] 00:05:24     INFO - PID 5524 |           Blocker:  Waiting for ping task
[task 2022-11-08T00:05:24.644Z] 00:05:24     INFO - PID 5524 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2022-11-08T00:05:24.645Z] 00:05:24     INFO - PID 5524 |           State: (none)
[task 2022-11-08T00:05:24.645Z] 00:05:24     INFO - PID 5524 | 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 2022-11-08T00:05:24.646Z] 00:05:24     INFO - PID 5524 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-08T00:05:24.647Z] 00:05:24     INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-08T00:05:24.648Z] 00:05:24     INFO - PID 5524 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-08T00:05:24.648Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-08T00:05:24.649Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-08T00:05:24.649Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-08T00:05:24.650Z] 00:05:24     INFO - PID 5524 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:103:5
[task 2022-11-08T00:05:24.650Z] 00:05:24     INFO - PID 5524 | promiseArchivePing@resource://gre/modules/TelemetryArchive.jsm:63:33
[task 2022-11-08T00:05:24.651Z] 00:05:24     INFO - PID 5524 | _submitPingLogic@resource://gre/modules/TelemetryControllerParent.jsm:554:48
[task 2022-11-08T00:05:24.651Z] 00:05:24     INFO - PID 5524 | send@resource://gre/modules/TelemetryControllerParent.jsm:642:24
[task 2022-11-08T00:05:24.652Z] 00:05:24     INFO - PID 5524 | submitExternalPing@resource://gre/modules/TelemetryControllerParent.jsm:182:17
[task 2022-11-08T00:05:24.652Z] 00:05:24     INFO - PID 5524 | saveShutdownPings@resource://gre/modules/TelemetrySession.jsm:982:34
[task 2022-11-08T00:05:24.653Z] 00:05:24     INFO - PID 5524 | shutdownChromeProcess/cleanup/<@resource://gre/modules/TelemetrySession.jsm:1232:20
[task 2022-11-08T00:05:24.654Z] 00:05:24     INFO - PID 5524 | cleanup@resource://gre/modules/TelemetrySession.jsm:1239:9
[task 2022-11-08T00:05:24.654Z] 00:05:24     INFO - PID 5524 | shutdownChromeProcess@resource://gre/modules/TelemetrySession.jsm:1256:14
[task 2022-11-08T00:05:24.655Z] 00:05:24     INFO - PID 5524 | shutdown@resource://gre/modules/TelemetrySession.jsm:247:17
[task 2022-11-08T00:05:24.655Z] 00:05:24     INFO - PID 5524 | _cleanupOnShutdown@resource://gre/modules/TelemetryControllerParent.jsm:973:35
[task 2022-11-08T00:05:24.656Z] 00:05:24     INFO - PID 5524 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-08T00:05:24.656Z] 00:05:24     INFO - PID 5524 | WARNING: A blocker encountered an error while we were waiting.
[task 2022-11-08T00:05:24.657Z] 00:05:24     INFO - PID 5524 |           Blocker:  TelemetryController: shutting down
[task 2022-11-08T00:05:24.657Z] 00:05:24     INFO - PID 5524 |           Phase: profile-before-change-telemetry
[task 2022-11-08T00:05:24.658Z] 00:05:24     INFO - PID 5524 |           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.jsm:703:15
[task 2022-11-08T00:05:24.659Z] 00:05:24     INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-08T00:05:24.659Z] 00:05:24     INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-08T00:05:24.660Z] 00:05:24     INFO - PID 5524 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
[task 2022-11-08T00:05:24.660Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-08T00:05:24.661Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-08T00:05:24.661Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-08T00:05:24.662Z] 00:05:24     INFO - PID 5524 | getShutdownState@resource://gre/modules/TelemetrySend.jsm:1687:7
[task 2022-11-08T00:05:24.662Z] 00:05:24     INFO - PID 5524 | getShutdownState@resource://gre/modules/TelemetrySend.jsm:369:30
[task 2022-11-08T00:05:24.663Z] 00:05:24     INFO - PID 5524 | _getState@resource://gre/modules/TelemetryControllerParent.jsm:1072:38
[task 2022-11-08T00:05:24.663Z] 00:05:24     INFO - PID 5524 | setupTelemetry/<@resource://gre/modules/TelemetryControllerParent.jsm:931:18
[task 2022-11-08T00:05:24.664Z] 00:05:24     INFO - PID 5524 | safeGetState@resource://gre/modules/AsyncShutdown.jsm:242:17
[task 2022-11-08T00:05:24.664Z] 00:05:24     INFO - PID 5524 | Barrier/addBlocker/promise<@resource://gre/modules/AsyncShutdown.jsm:751:20
[task 2022-11-08T00:05:24.665Z] 00:05:24     INFO - PID 5524 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-08T00:05:24.666Z] 00:05:24     INFO - PID 5524 | 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 2022-11-08T00:05:24.666Z] 00:05:24     INFO - PID 5524 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.jsm:703:15
[task 2022-11-08T00:05:24.666Z] 00:05:24     INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:511:26
[task 2022-11-08T00:05:24.667Z] 00:05:24     INFO - PID 5524 | addBlocker@resource://gre/modules/AsyncShutdown.jsm:450:15
[task 2022-11-08T00:05:24.667Z] 00:05:24     INFO - PID 5524 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1563:28
INFO - PID 5524 | @resource://gre/modules/osfile/osfile_async_front.jsm:1583:16
[task 2022-11-08T00:05:24.668Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/osfile.jsm:12:30
[task 2022-11-08T00:05:24.669Z] 00:05:24     INFO - PID 5524 | @resource://gre/modules/TelemetryStorage.jsm:19:28
[task 2022-11-08T00:05:24.669Z] 00:05:24     INFO - PID 5524 | removeAbortedSessionPing@resource://gre/modules/TelemetryControllerParent.jsm:735:5
[task 2022-11-08T00:05:24.670Z] 00:05:24     INFO - PID 5524 | removeAbortedSessionPing@resource://gre/modules/TelemetryControllerParent.jsm:249:17
[task 2022-11-08T00:05:24.671Z] 00:05:24     INFO - PID 5524 | shutdownChromeProcess/cleanup/<@resource://gre/modules/TelemetrySession.jsm:1235:42
[task 2022-11-08T00:05:24.671Z] 00:05:24     INFO - PID 5524 | observe@resource://gre/modules/AsyncShutdown.jsm:560:16
[task 2022-11-08T00:05:25.038Z] 00:05:25     INFO - PID 5524 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-08T00:05:25.041Z] 00:05:25     INFO - PID 5524 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-08T00:05:25.042Z] 00:05:25     INFO - PID 5524 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-08T00:05:25.043Z] 00:05:25     INFO - PID 5524 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-08T00:05:25.044Z] 00:05:25     INFO - PID 5524 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 703: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2022-11-08T00:05:25.103Z] 00:05:25     INFO - Browser exited with return code 0
[task 2022-11-08T00:05:25.106Z] 00:05:25     INFO - Closing logging queue
[task 2022-11-08T00:05:25.107Z] 00:05:25     INFO - queue closed
[task 2022-11-08T00:05:26.266Z] 00:05:26     INFO - Application command: Z:\task_166785934562049\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_166785934562049\AppData\Local\Temp\tmppwb2awd9
[task 2022-11-08T00:05:26.272Z] 00:05:26     INFO - PID 5024 | 1667865474035	Marionette	INFO	Marionette enabled
[task 2022-11-08T00:05:26.273Z] 00:05:26     INFO - PID 5024 | 1667865474066	Marionette	INFO	Listening on port 49921
[task 2022-11-08T00:05:26.274Z] 00:05:26     INFO - PID 5024 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_166785934562049\\AppData\\Local\\Temp\\tmpmigweqdq\\search.json.mozlz4", (void 0)))
[task 2022-11-08T00:05:26.274Z] 00:05:26     INFO - PID 5024 | *** You are running in background task mode. ***
[task 2022-11-08T00:05:26.275Z] 00:05:26     INFO - PID 5024 | *** You are running in headless mode.
[task 2022-11-08T00:05:26.276Z] 00:05:26     INFO - PID 5024 | console.error: "C:\\Users\\task_166785934562049\\AppData\\Local\\Temp\\tmpmigweqdq" "" 0 ".purge.bg_rm"
[task 2022-11-08T00:05:26.276Z] 00:05:26     INFO - Starting runner
[task 2022-11-08T00:05:27.168Z] 00:05:27     INFO - TEST-START | /IndexedDB/keypath-special-identifiers.htm

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 1
  • opt: 1

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

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • opt: 1

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

Comment 3

[BugBot [:suhaib / :marco]]

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

Comment 4

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=423965153&repo=mozilla-release

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 1
  • opt: 1

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

Comment 6

[BugBot [:suhaib / :marco]]

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