1623972 - Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js | Test timed out

Status: RESOLVED DUPLICATE of bug 1624983

(Toolkit :: Blocklist Implementation, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=294054281&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/az-XIBRLQf-64LPB1iwm-Q/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-03-20T13:45:18.400Z] 13:45:18 INFO - TEST-START | toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js
[task 2020-03-20T13:50:18.398Z] 13:50:18 WARNING - TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js | Test timed out
[task 2020-03-20T13:50:18.398Z] 13:50:18 INFO - TEST-INFO took 300000ms
[task 2020-03-20T13:50:18.399Z] 13:50:18 INFO - >>>>>>>
[task 2020-03-20T13:50:18.399Z] 13:50:18 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-03-20T13:50:18.399Z] 13:50:18 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2020-03-20T13:50:18.400Z] 13:50:18 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2020-03-20T13:50:18.400Z] 13:50:18 INFO - running event loop
[task 2020-03-20T13:50:18.401Z] 13:50:18 INFO - toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js | Starting setup
[task 2020-03-20T13:50:18.401Z] 13:50:18 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2020-03-20T13:50:18.402Z] 13:50:18 INFO - PID 8408 | 1584711918599 addons.manager DEBUG Application has been upgraded
[task 2020-03-20T13:50:18.402Z] 13:50:18 INFO - PID 8408 | 1584711918599 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]
[task 2020-03-20T13:50:18.402Z] 13:50:18 INFO - PID 8408 | 1584711918603 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm
[task 2020-03-20T13:50:18.402Z] 13:50:18 INFO - PID 8408 | 1584711918604 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm
[task 2020-03-20T13:50:18.403Z] 13:50:18 INFO - PID 8408 | 1584711918604 addons.manager DEBUG Starting provider: XPIProvider
[task 2020-03-20T13:50:18.403Z] 13:50:18 INFO - PID 8408 | 1584711918604 addons.xpi DEBUG startup
[task 2020-03-20T13:50:18.404Z] 13:50:18 INFO - PID 8408 | 1584711918604 addons.xpi DEBUG List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIXPCComponents_Utils.readUTF8URI]" nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)" location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2394" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2394
[task 2020-03-20T13:50:18.404Z] 13:50:18 INFO - PID 8408 | callProvider()@resource://gre/modules/AddonManager.jsm:215
[task 2020-03-20T13:50:18.405Z] 13:50:18 INFO - PID 8408 | _startProvider()@resource://gre/modules/AddonManager.jsm:587
[task 2020-03-20T13:50:18.405Z] 13:50:18 INFO - PID 8408 | startup()@resource://gre/modules/AddonManager.jsm:811
[task 2020-03-20T13:50:18.405Z] 13:50:18 INFO - PID 8408 | startup()@resource://gre/modules/AddonManager.jsm:3482
[task 2020-03-20T13:50:18.406Z] 13:50:18 INFO - PID 8408 | observe()@resource://gre/modules/addonManager.js:87
[task 2020-03-20T13:50:18.406Z] 13:50:18 INFO - PID 8408 | promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:979
[task 2020-03-20T13:50:18.406Z] 13:50:18 INFO - PID 8408 | setup()@Z:/task_1584710933/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js:144
[task 2020-03-20T13:50:18.407Z] 13:50:18 INFO - PID 8408 | _run_next_test/<()@Z:\task_1584710933\build\tests\xpcshell\head.js:1567
[task 2020-03-20T13:50:18.407Z] 13:50:18 INFO - PID 8408 | _run_next_test()@Z:\task_1584710933\build\tests\xpcshell\head.js:1567
[task 2020-03-20T13:50:18.407Z] 13:50:18 INFO - PID 8408 | run()@Z:\task_1584710933\build\tests\xpcshell\head.js:735
[task 2020-03-20T13:50:18.408Z] 13:50:18 INFO - PID 8408 | _do_main()@Z:\task_1584710933\build\tests\xpcshell\head.js:246
[task 2020-03-20T13:50:18.408Z] 13:50:18 INFO - PID 8408 | _execute_test()@Z:\task_1584710933\build\tests\xpcshell\head.js:573
[task 2020-03-20T13:50:18.409Z] 13:50:18 INFO - PID 8408 | -e:1
[task 2020-03-20T13:50:18.409Z] 13:50:18 INFO - PID 8408 | 1584711918606 addons.xpi INFO SystemAddonLocation directory is missing
[task 2020-03-20T13:50:18.409Z] 13:50:18 INFO - PID 8408 | 1584711918613 addons.xpi INFO Removing all system add-on upgrades.
[task 2020-03-20T13:50:18.410Z] 13:50:18 INFO - PID 8408 | 1584711918613 addons.xpi DEBUG checkForChanges
[task 2020-03-20T13:50:18.410Z] 13:50:18 INFO - PID 8408 | 1584711918613 addons.xpi DEBUG Loaded add-on state: ${}
[task 2020-03-20T13:50:18.410Z] 13:50:18 INFO - PID 8408 | 1584711918614 addons.xpi DEBUG scanForChanges changed: false, state: {}
[task 2020-03-20T13:50:18.411Z] 13:50:18 INFO - PID 8408 | 1584711918614 addons.xpi DEBUG Empty XPI database, setting schema version preference to 32
[task 2020-03-20T13:50:18.411Z] 13:50:18 INFO - PID 8408 | 1584711918614 addons.xpi DEBUG No changes found
[task 2020-03-20T13:50:18.411Z] 13:50:18 INFO - PID 8408 | 1584711918622 addons.xpi-utils DEBUG Error: Synchronously loading the add-ons database(resource://gre/modules/addons/XPIDatabase.jsm:1604:15) JS Stack trace: [e-mail]:1604:15
[task 2020-03-20T13:50:18.412Z] 13:50:18 INFO - PID 8408 | [e-mail]:2448:23
[task 2020-03-20T13:50:18.412Z] 13:50:18 INFO - PID 8408 | [e-mail]:215:31
[task 2020-03-20T13:50:18.412Z] 13:50:18 INFO - PID 8408 | [e-mail]:587:17
[task 2020-03-20T13:50:18.412Z] 13:50:18 INFO - PID 8408 | [e-mail]:811:14
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | [e-mail]:3482:26
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | [e-mail]:87:29
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | [e-mail]:979:34
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | setup@test_pluginBlocklistCtp.js:144:9
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | _run_next_test/<@Z:\task_1584710933\build\tests\xpcshell\head.js:1567:22
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | _run_next_test@Z:\task_1584710933\build\tests\xpcshell\head.js:1567:38
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | run@Z:\task_1584710933\build\tests\xpcshell\head.js:735:9
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | _do_main@Z:\task_1584710933\build\tests\xpcshell\head.js:246:6
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | _execute_test@Z:\task_1584710933\build\tests\xpcshell\head.js:573:5
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | @-e:1:1
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - PID 8408 | 1584711918622 addons.xpi-utils DEBUG Starting async load of XPI database c:\users\task_1584710933\appdata\local\temp\xpc-profile-97fgpk\extensions.json
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918599 addons.manager DEBUG Application has been upgraded"
[task 2020-03-20T13:50:18.413Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918599 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]"
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918603 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm"
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918604 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm"
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918604 addons.manager DEBUG Starting provider: XPIProvider"
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918604 addons.xpi DEBUG startup"
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918604 addons.xpi DEBUG List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIXPCComponents_Utils.readUTF8URI]" nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)" location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2394" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2394
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - callProvider()@resource://gre/modules/AddonManager.jsm:215
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - _startProvider()@resource://gre/modules/AddonManager.jsm:587
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - startup()@resource://gre/modules/AddonManager.jsm:811
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - startup()@resource://gre/modules/AddonManager.jsm:3482
[task 2020-03-20T13:50:18.414Z] 13:50:18 INFO - observe()@resource://gre/modules/addonManager.js:87
[task 2020-03-20T13:50:18.415Z] 13:50:18 INFO - [e-mail]:2448:23
[task 2020-03-20T13:50:18.415Z] 13:50:18 INFO - [e-mail]:215:31
[task 2020-03-20T13:50:18.415Z] 13:50:18 INFO - [e-mail]:587:17
[task 2020-03-20T13:50:18.415Z] 13:50:18 INFO - [e-mail]:811:14
[task 2020-03-20T13:50:18.415Z] 13:50:18 INFO - [e-mail]:3482:26
[task 2020-03-20T13:50:18.415Z] 13:50:18 INFO - [e-mail]:87:29
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - [e-mail]:979:34
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - setup@test_pluginBlocklistCtp.js:144:9
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - _run_next_test/<@Z:\task_1584710933\build\tests\xpcshell\head.js:1567:22
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - _run_next_test@Z:\task_1584710933\build\tests\xpcshell\head.js:1567:38
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - run@Z:\task_1584710933\build\tests\xpcshell\head.js:735:9
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - _do_main@Z:\task_1584710933\build\tests\xpcshell\head.js:246:6
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - _execute_test@Z:\task_1584710933\build\tests\xpcshell\head.js:573:5
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - @-e:1:1"
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918622 addons.xpi-utils DEBUG Starting async load of XPI database c:\users\task_1584710933\appdata\local\temp\xpc-profile-97fgpk\extensions.json"
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - PID 8408 | 1584711918652 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - PID 8408 | 1584711918653 addons.manager DEBUG Registering shutdown blocker for XPIProvider
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - PID 8408 | 1584711918654 addons.manager DEBUG Provider finished startup: XPIProvider
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - PID 8408 | 1584711918654 addons.manager DEBUG Starting provider: PluginProvider
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - PID 8408 | 1584711918654 addons.manager DEBUG Registering shutdown blocker for PluginProvider
[task 2020-03-20T13:50:18.416Z] 13:50:18 INFO - PID 8408 | 1584711918654 addons.manager DEBUG Provider finished startup: PluginProvider
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - PID 8408 | 1584711918656 addons.manager DEBUG Completed startup sequence
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918652 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions"
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918653 addons.manager DEBUG Registering shutdown blocker for XPIProvider"
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918654 addons.manager DEBUG Provider finished startup: XPIProvider"
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918654 addons.manager DEBUG Starting provider: PluginProvider"
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918654 addons.manager DEBUG Registering shutdown blocker for PluginProvider"
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918654 addons.manager DEBUG Provider finished startup: PluginProvider"
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - "CONSOLE_MESSAGE: (info) 1584711918656 addons.manager DEBUG Completed startup sequence"
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - (xpcshell/head.js) | test setup finished (2)
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js | Starting basic
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - (xpcshell/head.js) | test basic pending (2)
[task 2020-03-20T13:50:18.417Z] 13:50:18 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2020-03-20T13:50:18.418Z] 13:50:18 INFO - PID 8408 | *** Blocklist state for Test Plug-in changed from 0 to 0
[task 2020-03-20T13:50:18.418Z] 13:50:18 INFO - PID 8408 | *** Blocklist state for Shockwave Flash changed from 0 to 0
[task 2020-03-20T13:50:18.418Z] 13:50:18 INFO - PID 8408 | *** Blocklist state for Second Test Plug-in changed from 0 to 0
[task 2020-03-20T13:50:18.418Z] 13:50:18 INFO - TEST-PASS | toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js | basic - [basic : 151] 3 == 3

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1

Platform breakdown:

• windows10-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1623972&startday=2020-03-16&endday=2020-03-22&tree=all

Comment 2

[:Gijs (he/him)]

This was a result of bug 1624983 which got backed out.

Comment 3

[Intermittent Failures Robot]

13 failures in 4773 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 13

Platform breakdown:

• macosx1014-64: 2
• windows7-32: 2
• windows10-64-shippable: 2
• windows7-32-shippable: 2
• linux1804-64-shippable-qr: 1
• macosx1014-64-shippable: 2
• linux1804-64-asan: 1
• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1623972&startday=2020-03-23&endday=2020-03-29&tree=all