Closed
Bug 1741556
Opened 4 years ago
Closed 3 years ago
Intermittent services/sync/tests/unit/test_addons_store.js | cleanup - [cleanup : 271] A promise chain failed to handle a rejection: Unable to arm timer, the object has been finalized. - stack: arm@resource://gre/modules/DeferredTask.jsm:225:13
Categories
(Firefox :: Sync, defect, P5)
Firefox
Sync
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=358292203&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/TzfHt63NRKieXZm1kN9_CQ/runs/0/artifacts/public/logs/live_backing.log
[task 2021-11-17T06:50:50.096Z] 06:50:50 INFO - TEST-PASS | services/sync/tests/unit/test_addons_store.js | test_incoming_reconciled_but_not_cached - [test_incoming_reconciled_but_not_cached : 720] {} != null
[task 2021-11-17T06:50:50.096Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849587 addons.xpi-utils DEBUG Make addon app-profile:addon1@tests.mozilla.org visible"
[task 2021-11-17T06:50:50.097Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849587 addons.xpi DEBUG XPIStates adding add-on addon1@tests.mozilla.org in {"addons":{},"staged":{},"path":"C:\\\\Users\\\\task_163712940396299\\\\AppData\\\\Local\\\\Temp\\\\xpc-profile-86hdxqre\\\\extensions"}: C:\\Users\\task_163712940396299\\AppData\\Local\\Temp\\xpc-profile-86hdxqre\\extensions\\addon1@tests.mozilla.org.xpi"
[task 2021-11-17T06:50:50.098Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849587 addons.xpi DEBUG Updating XPIState for {"id":"addon1@tests.mozilla.org","syncGUID":"MHqJ8yME4rKZ","version":"1.0","type":"extension","loader":null,"updateURL":"http://example.com/data/test_install.json","optionsURL":null,"optionsType":null,"optionsBrowserStyle":true,"aboutURL":null,"defaultLocale":{"name":"Generated extension","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"embedderDisabled":false,"installDate":1637131849580,"updateDate":1637131849580,"applyBackgroundUpdates":1,"path":"C:\\\\Users\\\\task_163712940396299\\\\AppData\\\\Local\\\\Temp\\\\xpc-profile-86hdxqre\\\\extensions\\\\addon1@tests.mozilla.org.xpi","skinnable":false,"sourceURI":"http://localhost:8888/addon1.xpi","releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"signedState":4,"signedDate":null,"seen":true,"dependencies":[],"incognito":"spanning","userPermissions":{"permissions":[],"origins":[]},"optionalPermissions":{"permissions":[],"origins":[]},"icons":{},"iconURL":null,"blocklistState":0,"blocklistURL":null,"startupData":null,"hidden":false,"installTelemetryInfo":{"source":"sync"},"recommendationState":null,"rootURI":"jar:file:///C:/Users/task_163712940396299/AppData/Local/Temp/xpc-profile-86hdxqre/extensions/addon1@tests.mozilla.org.xpi!/","location":"app-profile"}"
[task 2021-11-17T06:50:50.099Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849587 addons.xpi DEBUG Install of http://localhost:8888/addon1.xpi completed."
[task 2021-11-17T06:50:50.099Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849587 addons.xpi DEBUG Loading bootstrap scope from jar:file:///C:/Users/task_163712940396299/AppData/Local/Temp/xpc-profile-86hdxqre/extensions/addon1@tests.mozilla.org.xpi!/"
[task 2021-11-17T06:50:50.099Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849587 addons.xpi DEBUG Calling bootstrap method install on addon1@tests.mozilla.org version 1.0"
[task 2021-11-17T06:50:50.100Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849588 addons.xpi DEBUG Calling bootstrap method startup on addon1@tests.mozilla.org version 1.0"
[task 2021-11-17T06:50:50.100Z] 06:50:50 INFO - (xpcshell/head.js) | test run_next_test 20 pending (2)
[task 2021-11-17T06:50:50.100Z] 06:50:50 INFO - (xpcshell/head.js) | test test_incoming_reconciled_but_not_cached finished (2)
[task 2021-11-17T06:50:50.100Z] 06:50:50 INFO - services/sync/tests/unit/test_addons_store.js | Starting cleanup
[task 2021-11-17T06:50:50.100Z] 06:50:50 INFO - (xpcshell/head.js) | test cleanup pending (2)
[task 2021-11-17T06:50:50.101Z] 06:50:50 INFO - PID 14220 | 1637131849589 Sync.AddonsReconciler DEBUG Stopping listening and removing AddonManager listener.
[task 2021-11-17T06:50:50.101Z] 06:50:50 INFO - (xpcshell/head.js) | test run_next_test 20 finished (2)
[task 2021-11-17T06:50:50.101Z] 06:50:50 INFO - (xpcshell/head.js) | test run_next_test 21 pending (2)
[task 2021-11-17T06:50:50.101Z] 06:50:50 INFO - (xpcshell/head.js) | test cleanup finished (2)
[task 2021-11-17T06:50:50.102Z] 06:50:50 INFO - (xpcshell/head.js) | test run_next_test 21 finished (1)
[task 2021-11-17T06:50:50.102Z] 06:50:50 INFO - exiting test
[task 2021-11-17T06:50:50.102Z] 06:50:50 INFO - Error: Found unexpected files in temporary directory: tmp-ze7.xpi at resource://testing-common/AddonTestUtils.jsm:416
[task 2021-11-17T06:50:50.102Z] 06:50:50 INFO - init/<@resource://testing-common/AddonTestUtils.jsm:416:15
[task 2021-11-17T06:50:50.102Z] 06:50:50 INFO - _execute_test/<@Z:\task_163712940396299\build\tests\xpcshell\head.js:667:28
[task 2021-11-17T06:50:50.104Z] 06:50:50 INFO - _execute_test@Z:\task_163712940396299\build\tests\xpcshell\head.js:679:16
[task 2021-11-17T06:50:50.104Z] 06:50:50 INFO - @-e:1:1
[task 2021-11-17T06:50:50.104Z] 06:50:50 INFO - PID 14220 | 1637131849599 addons.xpi DEBUG removeTemporaryFile: http://localhost:8888/addon1.xpi removing temp file C:\Users\task_163712940396299\AppData\Local\Temp\xpc-profile-86hdxqre\temp\tmp-ze7.xpi
[task 2021-11-17T06:50:50.104Z] 06:50:50 INFO - PID 14220 | 1637131849600 Sync.SyncScheduler TRACE Handling network:offline-status-changed
[task 2021-11-17T06:50:50.104Z] 06:50:50 INFO - PID 14220 | 1637131849600 Sync.SyncScheduler TRACE Network offline status change: offline
[task 2021-11-17T06:50:50.104Z] 06:50:50 INFO - PID 14220 | 1637131849600 Sync.SyncScheduler TRACE _checkSync returned "Sync is not configured".
[task 2021-11-17T06:50:50.104Z] 06:50:50 INFO - PID 14220 | 1637131849600 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score.
[task 2021-11-17T06:50:50.105Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849599 addons.xpi DEBUG removeTemporaryFile: http://localhost:8888/addon1.xpi removing temp file C:\\Users\\task_163712940396299\\AppData\\Local\\Temp\\xpc-profile-86hdxqre\\temp\\tmp-ze7.xpi"
[task 2021-11-17T06:50:50.105Z] 06:50:50 INFO - PID 14220 | 1637131849604 Sync.Engine.Prefs.Tracker TRACE stop().
[task 2021-11-17T06:50:50.105Z] 06:50:50 INFO - PID 14220 | JavaScript error: resource://gre/modules/DeferredTask.jsm, line 225: Error: Unable to arm timer, the object has been finalized.
[task 2021-11-17T06:50:50.105Z] 06:50:50 INFO - PID 14220 | JavaScript error: resource://gre/modules/DeferredTask.jsm, line 225: Error: Unable to arm timer, the object has been finalized.
[task 2021-11-17T06:50:50.106Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: Unable to arm timer, the object has been finalized." {file: "resource://gre/modules/DeferredTask.jsm" line: 225}]"
[task 2021-11-17T06:50:50.106Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: Unable to arm timer, the object has been finalized." {file: "resource://gre/modules/DeferredTask.jsm" line: 225}]"
[task 2021-11-17T06:50:50.106Z] 06:50:50 INFO - PID 14220 | 1637131849608 addons.xpi-utils WARN Failed to save XPI database: AbortError: IOUtils: Shutting down and refusing additional I/O tasks Stack trace: _saveNow()@resource://gre/modules/addons/XPIDatabase.jsm:1587
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - PID 14220 | saveChanges/this._saveTask<()@resource://gre/modules/addons/XPIDatabase.jsm:1632
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - PID 14220 | _runTask()@resource://gre/modules/DeferredTask.jsm:344
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - PID 14220 | _timerCallback/<()@resource://gre/modules/DeferredTask.jsm:315
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - PID 14220 | _timerCallback()@resource://gre/modules/DeferredTask.jsm:334
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - PID 14220 | _startTimer/callback/<()@resource://gre/modules/DeferredTask.jsm:189
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - PID 14220 | _execute_test()@Z:\task_163712940396299\build\tests\xpcshell\head.js:713
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - PID 14220 | -e:1
[task 2021-11-17T06:50:50.108Z] 06:50:50 INFO - "CONSOLE_MESSAGE: (info) 1637131849608 addons.xpi-utils WARN Failed to save XPI database: AbortError: IOUtils: Shutting down and refusing additional I/O tasks Stack trace: _saveNow()@resource://gre/modules/addons/XPIDatabase.jsm:1587
[task 2021-11-17T06:50:50.109Z] 06:50:50 INFO - saveChanges/this._saveTask<()@resource://gre/modules/addons/XPIDatabase.jsm:1632
[task 2021-11-17T06:50:50.109Z] 06:50:50 INFO - _runTask()@resource://gre/modules/DeferredTask.jsm:344
[task 2021-11-17T06:50:50.109Z] 06:50:50 INFO - _timerCallback/<()@resource://gre/modules/DeferredTask.jsm:315
[task 2021-11-17T06:50:50.110Z] 06:50:50 INFO - _timerCallback()@resource://gre/modules/DeferredTask.jsm:334
[task 2021-11-17T06:50:50.110Z] 06:50:50 INFO - _startTimer/callback/<()@resource://gre/modules/DeferredTask.jsm:189
[task 2021-11-17T06:50:50.110Z] 06:50:50 INFO - _execute_test()@Z:\\task_163712940396299\\build\\tests\\xpcshell\\head.js:713
[task 2021-11-17T06:50:50.110Z] 06:50:50 INFO - -e:1"
[task 2021-11-17T06:50:50.111Z] 06:50:50 WARNING - TEST-UNEXPECTED-FAIL | services/sync/tests/unit/test_addons_store.js | cleanup - [cleanup : 271] A promise chain failed to handle a rejection: Unable to arm timer, the object has been finalized. - stack: arm@resource://gre/modules/DeferredTask.jsm:225:13
[task 2021-11-17T06:50:50.111Z] 06:50:50 INFO - save@resource://gre/modules/ExtensionParent.jsm:1847:27
[task 2021-11-17T06:50:50.112Z] 06:50:50 INFO - set@resource://gre/modules/ExtensionParent.jsm:1955:18
[task 2021-11-17T06:50:50.112Z] 06:50:50 INFO - observe@resource://gre/modules/AsyncShutdown.jsm:575:16
[task 2021-11-17T06:50:50.112Z] 06:50:50 INFO - _execute_test@Z:\\task_163712940396299\\build\\tests\\xpcshell\\head.js:710:23
[task 2021-11-17T06:50:50.112Z] 06:50:50 INFO - @-e:1:1
[task 2021-11-17T06:50:50.113Z] 06:50:50 INFO - Rejection date: Wed Nov 17 2021 06:50:49 GMT+0000 (Greenwich Mean Time) - false == true
[task 2021-11-17T06:50:50.113Z] 06:50:50 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:271
[task 2021-11-17T06:50:50.113Z] 06:50:50 INFO - Z:\task_163712940396299\build\tests\xpcshell\head.js:_execute_test:722
[task 2021-11-17T06:50:50.113Z] 06:50:50 INFO - -e:null:1
[task 2021-11-17T06:50:50.114Z] 06:50:50 INFO - exiting test
[task 2021-11-17T06:50:50.114Z] 06:50:50 INFO - PID 14220 | JavaScript error: Z:\task_163712940396299\build\tests\xpcshell\head.js, line 874: NS_ERROR_ABORT:
[task 2021-11-17T06:50:50.114Z] 06:50:50 INFO - <<<<<<<
[task 2021-11-17T06:50:50.144Z] 06:50:50 INFO - TEST-START | services/sync/tests/unit/test_clients_engine.js
|
||
Updated•4 years ago
|
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•4 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
|
Reporter | |
Comment 3•3 years ago
|
||
| treeherder | ||
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=368343700&repo=mozilla-central
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 5•3 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: REOPENED → RESOLVED
Closed: 4 years ago → 3 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•