Closed
Bug 1633363
Opened 5 years ago
Closed 5 years ago
Intermittent xpcshell/test_StorageSyncService.js | test_storage_sync_service - [test_storage_sync_service : 265] A promise chain failed to handle a rejection: `webext_storage::teardown` didn't run on the background thread - stack: handleError@ExtensionSto
Categories
(WebExtensions :: Storage, defect, P5)
WebExtensions
Storage
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1633943
People
(Reporter: intermittent-bug-filer, Assigned: lina)
Details
(Keywords: intermittent-failure)
Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=299530902&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Ao_UVLqLRxaz-GKNiR-BfA/runs/0/artifacts/public/logs/live_backing.log
[task 2020-04-27T09:36:33.779Z] 09:36:33 INFO - TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_socks.js
[task 2020-04-27T09:36:33.779Z] 09:36:33 INFO - TEST-SKIP | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_socks.js | took 0ms
[task 2020-04-27T09:36:33.787Z] 09:36:33 INFO - TEST-START | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_upgrade.js
[task 2020-04-27T09:36:34.521Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_upgrade.js | took 734ms
[task 2020-04-27T09:36:34.525Z] 09:36:34 INFO - Retrying tests that failed when run in parallel.
[task 2020-04-27T09:36:34.532Z] 09:36:34 INFO - TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js
[task 2020-04-27T09:36:34.660Z] 09:36:34 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | xpcshell return code: 0
[task 2020-04-27T09:36:34.661Z] 09:36:34 INFO - TEST-INFO took 128ms
[task 2020-04-27T09:36:34.662Z] 09:36:34 INFO - >>>>>>>
[task 2020-04-27T09:36:34.662Z] 09:36:34 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-04-27T09:36:34.662Z] 09:36:34 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - running event loop
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | Starting check_remote
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - (xpcshell/head.js) | test check_remote pending (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | check_remote - [check_remote : 1] useRemoteWebExtensions matches - false == false
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | check_remote - [check_remote : 1] testing from extension process - true == true
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - (xpcshell/head.js) | test check_remote finished (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | Starting test_storage_sync_service
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - (xpcshell/head.js) | test test_storage_sync_service pending (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2020-04-27T09:36:34.663Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | test_storage_sync_service - [test_storage_sync_service : 46] `set` should notify listeners about changes - [{"bye":{"newValue":"\\"adiós\\""},"hi":{"newValue":"\\"hello! 💖\\""}}] deepEqual [{"hi":{"newValue":"\\"hello! 💖\\""},"bye":{"newValue":"\\"adiós\\""}}]
[task 2020-04-27T09:36:34.665Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | test_storage_sync_service - [test_storage_sync_service : 60] `set` should not return a value - true == true
[task 2020-04-27T09:36:34.666Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | test_storage_sync_service - [test_storage_sync_service : 69] `get` should not notify listeners - [] deepEqual []
[task 2020-04-27T09:36:34.667Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | test_storage_sync_service - [test_storage_sync_service : 70] `get` with key should return value - {"hi":"hello! 💖"} deepEqual {"hi":"hello! 💖"}
[task 2020-04-27T09:36:34.667Z] 09:36:34 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | test_storage_sync_service - [test_storage_sync_service : 79] `get` without a key should return all values - {"bye":"adiós","hi":"hello! 💖"} deepEqual {"hi":"hello! 💖","bye":"adiós"}
[task 2020-04-27T09:36:34.668Z] 09:36:34 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2020-04-27T09:36:34.668Z] 09:36:34 INFO - (xpcshell/head.js) | test test_storage_sync_service finished (2)
[task 2020-04-27T09:36:34.668Z] 09:36:34 INFO - (xpcshell/head.js) | test run_next_test 2 finished (1)
[task 2020-04-27T09:36:34.668Z] 09:36:34 INFO - exiting test
[task 2020-04-27T09:36:34.668Z] 09:36:34 INFO - PID 23687 | WARNING: A blocker encountered an error while we were waiting.
[task 2020-04-27T09:36:34.669Z] 09:36:34 INFO - PID 23687 | Blocker: StorageSyncService: shutdown
[task 2020-04-27T09:36:34.669Z] 09:36:34 INFO - PID 23687 | Phase: profile-change-teardown
[task 2020-04-27T09:36:34.669Z] 09:36:34 INFO - PID 23687 | State: (none)
[task 2020-04-27T09:36:34.669Z] 09:36:34 INFO - PID 23687 | WARNING: [Exception... "`webext_storage::teardown` didn't run on the background thread" nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: resource://gre/modules/ExtensionStorageComponents.jsm :: handleError :: line 106" data: no]
[task 2020-04-27T09:36:34.669Z] 09:36:34 INFO - PID 23687 | WARNING: handleError@resource://gre/modules/ExtensionStorageComponents.jsm:106:31
[task 2020-04-27T09:36:34.669Z] 09:36:34 INFO - PID 23687 | observe@resource://gre/modules/AsyncShutdown.jsm:554:16
[task 2020-04-27T09:36:34.669Z] 09:36:34 INFO - PID 23687 | _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:655:19
[task 2020-04-27T09:36:34.670Z] 09:36:34 INFO - PID 23687 | @-e:1:1
[task 2020-04-27T09:36:34.670Z] 09:36:34 INFO - PID 23687 | JavaScript error: resource://gre/modules/ExtensionStorageComponents.jsm, line 106: NS_ERROR_UNEXPECTED: `webext_storage::teardown` didn't run on the background thread
[task 2020-04-27T09:36:34.674Z] 09:36:34 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_StorageSyncService.js | test_storage_sync_service - [test_storage_sync_service : 265] A promise chain failed to handle a rejection: `webext_storage::teardown` didn't run on the background thread - stack: handleError@resource://gre/modules/ExtensionStorageComponents.jsm:106:31
[task 2020-04-27T09:36:34.674Z] 09:36:34 INFO - observe@resource://gre/modules/AsyncShutdown.jsm:554:16
[task 2020-04-27T09:36:34.675Z] 09:36:34 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:655:19
[task 2020-04-27T09:36:34.675Z] 09:36:34 INFO - @-e:1:1
[task 2020-04-27T09:36:34.676Z] 09:36:34 INFO - Rejection date: Mon Apr 27 2020 09:36:34 GMT+0000 (Coordinated Universal Time) - false == true
[task 2020-04-27T09:36:34.677Z] 09:36:34 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:265
[task 2020-04-27T09:36:34.678Z] 09:36:34 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:664
[task 2020-04-27T09:36:34.678Z] 09:36:34 INFO - -e:null:1
[task 2020-04-27T09:36:34.678Z] 09:36:34 INFO - exiting test
[task 2020-04-27T09:36:34.678Z] 09:36:34 INFO - PID 23687 | JavaScript error: /builds/worker/workspace/build/tests/xpcshell/head.js, line 787: NS_ERROR_ABORT:
[task 2020-04-27T09:36:34.679Z] 09:36:34 INFO - <<<<<<<
[task 2020-04-27T09:36:34.679Z] 09:36:34 INFO - INFO | Result summary:
[task 2020-04-27T09:36:34.679Z] 09:36:34 INFO - INFO | Passed: 1141
[task 2020-04-27T09:36:34.680Z] 09:36:34 WARNING - INFO | Failed: 1
[task 2020-04-27T09:36:34.680Z] 09:36:34 WARNING - One or more unittests failed.
[task 2020-04-27T09:36:34.680Z] 09:36:34 INFO - INFO | Todo: 4
[task 2020-04-27T09:36:34.681Z] 09:36:34 INFO - INFO | Retried: 1
[task 2020-04-27T09:36:34.681Z] 09:36:34 INFO - SUITE-END | took 482s
[task 2020-04-27T09:36:34.681Z] 09:36:34 INFO - Node moz-http2 server shutting down ...
[task 2020-04-27T09:36:34.685Z] 09:36:34 INFO - Process stdout
[task 2020-04-27T09:36:34.685Z] 09:36:34 INFO - forked process without handler sent: [object Object]
[task 2020-04-27T09:36:34.686Z] 09:36:34 INFO - Process stderr
[task 2020-04-27T09:36:34.686Z] 09:36:34 INFO - (node:1131) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2020-04-27T09:36:34.687Z] 09:36:34 INFO - (node:1131) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2020-04-27T09:36:34.687Z] 09:36:34 INFO - (node:1131) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2020-04-27T09:36:34.688Z] 09:36:34 INFO - (node:1131) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2020-04-27T09:36:34.688Z] 09:36:34 INFO - http3Server server shutting down ...
[task 2020-04-27T09:36:34.845Z] 09:36:34 ERROR - Return code: 1
[task 2020-04-27T09:36:34.846Z] 09:36:34 INFO - TinderboxPrint: xpcshell-xpcshell<br/>1141/<em class="testfail">1</em>/4
[task 2020-04-27T09:36:34.846Z] 09:36:34 WARNING - # TBPL FAILURE #
[task 2020-04-27T09:36:34.846Z] 09:36:34 WARNING - setting return code to 2
[task 2020-04-27T09:36:34.846Z] 09:36:34 WARNING - The xpcshell suite: xpcshell ran with return status: FAILURE
[task 2020-04-27T09:36:34.846Z] 09:36:34 INFO - Running post-action listener: _package_coverage_data
[task 2020-04-27T09:36:34.847Z] 09:36:34 INFO - Running post-action listener: _resource_record_post_action
[task 2020-04-27T09:36:34.847Z] 09:36:34 INFO - Running post-action listener: process_java_coverage_data
[task 2020-04-27T09:36:34.847Z] 09:36:34 INFO - [mozharness: 2020-04-27 09:36:34.847702Z] Finished run-tests step (success)
[task 2020-04-27T09:36:34.848Z] 09:36:34 INFO - Running post-run listener: _resource_record_post_run
[task 2020-04-27T09:36:34.909Z] 09:36:34 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2020-04-27T09:36:34.913Z] 09:36:34 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 93.21042510121457}, {"name": "io_write_bytes", "value": 13699842048}, {"name": "io.read_bytes", "value": 109850624}, {"name": "io_write_time", "value": 858916}, {"name": "io_read_time", "value": 1172}], "extraOptions": ["e10s", "taskcluster-m5.large"], "name": "xpcshell.xpcshell.overall"}, {"subtests": [{"name": "time", "value": 0.028561830520629883}], "name": "xpcshell.xpcshell.start-pulseaudio"}, {"subtests": [{"name": "time", "value": 10.36299180984497}, {"name": "cpu_percent", "value": 50.44444444444444}], "name": "xpcshell.xpcshell.install"}, {"subtests": [{"name": "time", "value": 0.016371965408325195}], "name": "xpcshell.xpcshell.stage-files"}, {"subtests": [{"name": "time", "value": 484.6385622024536}, {"name": "cpu_percent", "value": 94.19989648033128}], "name": "xpcshell.xpcshell.run-tests"}]}
[task 2020-04-27T09:36:34.914Z] 09:36:34 INFO - Total resource usage - Wall time: 495s; CPU: 94.0%; Read bytes: 109850624; Write bytes: 13699842048; Read time: 1172; Write time: 858916
[task 2020-04-27T09:36:34.915Z] 09:36:34 INFO - TinderboxPrint: CPU usage<br/>94.2%
[task 2020-04-27T09:36:34.915Z] 09:36:34 INFO - TinderboxPrint: I/O read bytes / time<br/>109,850,624 / 1,172
[task 2020-04-27T09:36:34.916Z] 09:36:34 INFO - TinderboxPrint: I/O write bytes / time<br/>13,699,842,048 / 858,916
[task 2020-04-27T09:36:34.916Z] 09:36:34 INFO - TinderboxPrint: CPU idle<br/>63.1 (6.4%)
[task 2020-04-27T09:36:34.916Z] 09:36:34 INFO - TinderboxPrint: CPU system<br/>197.9 (20.0%)
[task 2020-04-27T09:36:34.917Z] 09:36:34 INFO - TinderboxPrint: CPU user<br/>719.0 (72.8%)
[task 2020-04-27T09:36:34.917Z] 09:36:34 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2020-04-27T09:36:34.918Z] 09:36:34 INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-04-27T09:36:34.918Z] 09:36:34 INFO - install - Wall time: 10s; CPU: 50.0%; Read bytes: 2330624; Write bytes: 18919424; Read time: 28; Write time: 12936
[task 2020-04-27T09:36:34.918Z] 09:36:34 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-04-27T09:36:34.920Z] 09:36:34 INFO - run-tests - Wall time: 485s; CPU: 94.0%; Read bytes: 55001088; Write bytes: 13673349120; Read time: 656; Write time: 840860
[task 2020-04-27T09:36:34.987Z] 09:36:34 WARNING - returning nonzero exit status 2
Assignee | ||
Updated•5 years ago
|
Assignee: nobody → lina
Status: NEW → ASSIGNED
Component: General → Storage
Assignee | ||
Comment 1•5 years ago
|
||
I think this was fixed by bug 1633943, which got rid of the extra Arc::clone
call in teardown
! \o/
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → DUPLICATE
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
You need to log in
before you can comment on or make changes to this bug.
Description
•