Closed Bug 1543156 Opened 6 years ago Closed 5 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | devtools/server/tests/unit/test_addon_events.js | Test timed out

Categories

(DevTools :: General, defect, P5)

defect

Tracking

(firefox-esr68 fixed, firefox70 wontfix, firefox71 wontfix, firefox72 fixed)

RESOLVED FIXED
Firefox 72
Tracking Status
firefox-esr68 --- fixed
firefox70 --- wontfix
firefox71 --- wontfix
firefox72 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jdescottes)

References

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disabled][stockwell needswork:owner])

Attachments

(3 files)

#[markdown(off)]
Filed by: csabou [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=239086565&repo=autoland

https://queue.taskcluster.net/v1/task/BrIQdi0jSjyiYW-1d9o3MA/runs/0/artifacts/public/logs/live_backing.log

[task 2019-04-09T15:08:59.045Z] 15:08:59 INFO - TEST-PASS | devtools/server/tests/unit/test_objectgrips-17.js | took 10434ms
[task 2019-04-09T15:13:09.448Z] 15:13:09 INFO - TEST-TIMEOUT | devtools/server/tests/unit/test_addon_events.js | took 299999ms
[task 2019-04-09T15:13:09.448Z] 15:13:09 INFO - xpcshell return code: None
[task 2019-04-09T15:13:09.449Z] 15:13:09 INFO - devtools/server/tests/unit/test_addon_events.js | Process still running after test!
[task 2019-04-09T15:13:09.457Z] 15:13:09 INFO - devtools/server/tests/unit/test_addon_events.js failed or timed out, will retry.
[task 2019-04-09T15:13:09.461Z] 15:13:09 INFO - Retrying tests that failed when run in parallel.
[task 2019-04-09T15:13:09.469Z] 15:13:09 INFO - TEST-START | devtools/server/tests/unit/test_addon_events.js
[task 2019-04-09T15:18:09.481Z] 15:18:09 WARNING - TEST-UNEXPECTED-TIMEOUT | devtools/server/tests/unit/test_addon_events.js | Test timed out
[task 2019-04-09T15:18:09.482Z] 15:18:09 INFO - TEST-INFO took 300000ms
[task 2019-04-09T15:18:09.483Z] 15:18:09 INFO - >>>>>>>
[task 2019-04-09T15:18:09.484Z] 15:18:09 INFO - PID 13474 | 1554822789666 addons.xpi WARN 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 2243" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2243
[task 2019-04-09T15:18:09.484Z] 15:18:09 INFO - PID 13474 | callProvider()@resource://gre/modules/AddonManager.jsm:200
[task 2019-04-09T15:18:09.485Z] 15:18:09 INFO - PID 13474 | _startProvider()@resource://gre/modules/AddonManager.jsm:651
[task 2019-04-09T15:18:09.486Z] 15:18:09 INFO - PID 13474 | startup()@resource://gre/modules/AddonManager.jsm:807
[task 2019-04-09T15:18:09.486Z] 15:18:09 INFO - PID 13474 | startup()@resource://gre/modules/AddonManager.jsm:2801
[task 2019-04-09T15:18:09.487Z] 15:18:09 INFO - PID 13474 | observe()@resource://gre/modules/addonManager.js:65
[task 2019-04-09T15:18:09.488Z] 15:18:09 INFO - PID 13474 | startupAddonsManager()@/builds/worker/workspace/build/tests/xpcshell/tests/devtools/server/tests/unit/head_dbg.js:60
[task 2019-04-09T15:18:09.488Z] 15:18:09 INFO - PID 13474 | /builds/worker/workspace/build/tests/xpcshell/tests/devtools/server/tests/unit/test_addon_events.js:9
[task 2019-04-09T15:18:09.489Z] 15:18:09 INFO - PID 13474 | load_file()@/builds/worker/workspace/build/tests/xpcshell/head.js:637
[task 2019-04-09T15:18:09.489Z] 15:18:09 INFO - PID 13474 | _load_files()@/builds/worker/workspace/build/tests/xpcshell/head.js:649
[task 2019-04-09T15:18:09.490Z] 15:18:09 INFO - PID 13474 | _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:503
[task 2019-04-09T15:18:09.491Z] 15:18:09 INFO - PID 13474 | -e:1
[task 2019-04-09T15:18:09.492Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (info) 1554822789666 addons.xpi WARN 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 2243" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2243
[task 2019-04-09T15:18:09.494Z] 15:18:09 INFO - callProvider()@resource://gre/modules/AddonManager.jsm:200
[task 2019-04-09T15:18:09.496Z] 15:18:09 INFO - _startProvider()@resource://gre/modules/AddonManager.jsm:651
[task 2019-04-09T15:18:09.496Z] 15:18:09 INFO - startup()@resource://gre/modules/AddonManager.jsm:807
[task 2019-04-09T15:18:09.496Z] 15:18:09 INFO - startup()@resource://gre/modules/AddonManager.jsm:2801
[task 2019-04-09T15:18:09.498Z] 15:18:09 INFO - observe()@resource://gre/modules/addonManager.js:65
[task 2019-04-09T15:18:09.498Z] 15:18:09 INFO - startupAddonsManager()@/builds/worker/workspace/build/tests/xpcshell/tests/devtools/server/tests/unit/head_dbg.js:60
[task 2019-04-09T15:18:09.499Z] 15:18:09 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/devtools/server/tests/unit/test_addon_events.js:9
[task 2019-04-09T15:18:09.500Z] 15:18:09 INFO - load_file()@/builds/worker/workspace/build/tests/xpcshell/head.js:637
[task 2019-04-09T15:18:09.500Z] 15:18:09 INFO - _load_files()@/builds/worker/workspace/build/tests/xpcshell/head.js:649
[task 2019-04-09T15:18:09.501Z] 15:18:09 INFO - _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:503
[task 2019-04-09T15:18:09.503Z] 15:18:09 INFO - -e:1"
[task 2019-04-09T15:18:09.503Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: 1554822789666 addons.xpi WARN 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 2243" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2243
[task 2019-04-09T15:18:09.507Z] 15:18:09 INFO - PID 13474 | callProvider()@resource://gre/modules/AddonManager.jsm:200
[task 2019-04-09T15:18:09.507Z] 15:18:09 INFO - PID 13474 | _startProvider()@resource://gre/modules/AddonManager.jsm:651
[task 2019-04-09T15:18:09.508Z] 15:18:09 INFO - PID 13474 | startup()@resource://gre/modules/AddonManager.jsm:807
[task 2019-04-09T15:18:09.510Z] 15:18:09 INFO - PID 13474 | startup()@resource://gre/modules/AddonManager.jsm:2801
[task 2019-04-09T15:18:09.510Z] 15:18:09 INFO - PID 13474 | observe()@resource://gre/modules/addonManager.js:65
[task 2019-04-09T15:18:09.511Z] 15:18:09 INFO - PID 13474 | startupAddonsManager()@/builds/worker/workspace/build/tests/xpcshell/tests/devtools/server/tests/unit/head_dbg.js:60
[task 2019-04-09T15:18:09.512Z] 15:18:09 INFO - PID 13474 | /builds/worker/workspace/build/tests/xpcshell/tests/devtools/server/tests/unit/test_addon_events.js:9
[task 2019-04-09T15:18:09.512Z] 15:18:09 INFO - PID 13474 | load_file()@/builds/worker/workspace/build/tests/xpcshell/head.js:637
[task 2019-04-09T15:18:09.512Z] 15:18:09 INFO - PID 13474 | _load_files()@/builds/worker/workspace/build/tests/xpcshell/head.js:649
[task 2019-04-09T15:18:09.513Z] 15:18:09 INFO - PID 13474 | _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:503
[task 2019-04-09T15:18:09.514Z] 15:18:09 INFO - PID 13474 | -e:1
[task 2019-04-09T15:18:09.514Z] 15:18:09 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-04-09T15:18:09.515Z] 15:18:09 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2019-04-09T15:18:09.515Z] 15:18:09 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2019-04-09T15:18:09.517Z] 15:18:09 INFO - running event loop
[task 2019-04-09T15:18:09.517Z] 15:18:09 INFO - devtools/server/tests/unit/test_addon_events.js | Starting testReloadExitedAddon
[task 2019-04-09T15:18:09.518Z] 15:18:09 INFO - (xpcshell/head.js) | test testReloadExitedAddon pending (2)
[task 2019-04-09T15:18:09.518Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Packet 0 sent from "root"
[task 2019-04-09T15:18:09.519Z] 15:18:09 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2019-04-09T15:18:09.519Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Received packet 0: {
[task 2019-04-09T15:18:09.519Z] 15:18:09 INFO - PID 13474 | "from": "root",
[task 2019-04-09T15:18:09.521Z] 15:18:09 INFO - PID 13474 | "applicationType": "browser",
[task 2019-04-09T15:18:09.522Z] 15:18:09 INFO - PID 13474 | "testConnectionPrefix": "server1.conn0.",
[task 2019-04-09T15:18:09.522Z] 15:18:09 INFO - PID 13474 | "traits": {
[task 2019-04-09T15:18:09.522Z] 15:18:09 INFO - PID 13474 | "sources": true,
[task 2019-04-09T15:18:09.523Z] 15:18:09 INFO - PID 13474 | "networkMonitor": true,
[task 2019-04-09T15:18:09.523Z] 15:18:09 INFO - PID 13474 | "storageInspector": true,
[task 2019-04-09T15:18:09.523Z] 15:18:09 INFO - PID 13474 | "storageInspectorReadOnly": true,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "wasmBinarySource": true,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "bulk": true,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "directorScripts": true,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "noBlackBoxing": false,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "noPrettyPrinting": true,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "breakpointWhileRunning": true,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "memoryActorAllocations": true,
[task 2019-04-09T15:18:09.525Z] 15:18:09 INFO - PID 13474 | "webConsoleCommands": true,
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "allowChromeProcess": false,
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "profilerDataFilterable": true,
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "heapSnapshots": true,
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "documentLoadingMarkers": true,
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "webExtensionAddonConnect": true,
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "perfActorVersion": 1,
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "nativeLogpoints": true
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://devtools/shared/client/debugger-client.js, line 620: ReferenceError: reference to undefined property "type"
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Packet 1 sent to "root"
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "type"" {file: "resource://devtools/shared/client/debugger-client.js" line: 620}]"
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://devtools/shared/client/debugger-client.js:620: strict error: ReferenceError: reference to undefined property "type"
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "type"
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Received packet 1: {
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "type": "listAddons",
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "to": "root"
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Packet 2 sent from "root"
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Received packet 2: {
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "from": "root",
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "addons": [
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | {
[task 2019-04-09T15:18:09.526Z] 15:18:09 INFO - PID 13474 | "actor": "server1.conn0.webExtension1",
[task 2019-04-09T15:18:09.527Z] 15:18:09 INFO - PID 13474 | "id": "gmp-gmpopenh264",
[task 2019-04-09T15:18:09.527Z] 15:18:09 INFO - PID 13474 | "name": "OpenH264 Video Codec provided by Cisco Systems, Inc.",
[task 2019-04-09T15:18:09.528Z] 15:18:09 INFO - PID 13474 | "type": "plugin",
[task 2019-04-09T15:18:09.537Z] 15:18:09 INFO - PID 13474 | "manifestURL": null,
[task 2019-04-09T15:18:09.538Z] 15:18:09 INFO - PID 13474 | "warnings": []
[task 2019-04-09T15:18:09.539Z] 15:18:09 INFO - PID 13474 | },
[task 2019-04-09T15:18:09.539Z] 15:18:09 INFO - PID 13474 | {
[task 2019-04-09T15:18:09.540Z] 15:18:09 INFO - PID 13474 | "actor": "server1.conn0.webExtension2",
[task 2019-04-09T15:18:09.541Z] 15:18:09 INFO - PID 13474 | "id": "Shockwave FlashFlash plug-in for testing purposes.",
[task 2019-04-09T15:18:09.542Z] 15:18:09 INFO - PID 13474 | "name": "Shockwave Flash",
[task 2019-04-09T15:18:09.543Z] 15:18:09 INFO - PID 13474 | "type": "plugin",
[task 2019-04-09T15:18:09.544Z] 15:18:09 INFO - PID 13474 | "manifestURL": null,
[task 2019-04-09T15:18:09.544Z] 15:18:09 INFO - PID 13474 | "warnings": []
[task 2019-04-09T15:18:09.544Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.545Z] 15:18:09 INFO - PID 13474 | ]
[task 2019-04-09T15:18:09.545Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.546Z] 15:18:09 INFO - "Install the addon"
[task 2019-04-09T15:18:09.546Z] 15:18:09 INFO - PID 13474 | (xpcshell:13474): Gtk-CRITICAL **: gtk_settings_get_for_screen: assertion 'GDK_IS_SCREEN (screen)' failed
[task 2019-04-09T15:18:09.547Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://gre/modules/addons/XPIInstall.jsm, line 475: ReferenceError: reference to undefined property "description"
[task 2019-04-09T15:18:09.547Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "description"" {file: "resource://gre/modules/addons/XPIInstall.jsm" line: 475}]"
[task 2019-04-09T15:18:09.548Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://gre/modules/addons/XPIInstall.jsm:475: strict error: ReferenceError: reference to undefined property "description"
[task 2019-04-09T15:18:09.548Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "description"
[task 2019-04-09T15:18:09.548Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://gre/modules/addons/XPIProvider.jsm, line 574: ReferenceError: reference to undefined property "version"
[task 2019-04-09T15:18:09.549Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://gre/modules/addons/XPIProvider.jsm, line 470: ReferenceError: reference to undefined property "currentModifiedTime"
[task 2019-04-09T15:18:09.549Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "version"" {file: "resource://gre/modules/addons/XPIProvider.jsm" line: 574}]"
[task 2019-04-09T15:18:09.550Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://gre/modules/addons/XPIProvider.jsm:574: strict error: ReferenceError: reference to undefined property "version"
[task 2019-04-09T15:18:09.550Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "version"
[task 2019-04-09T15:18:09.550Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "currentModifiedTime"" {file: "resource://gre/modules/addons/XPIProvider.jsm" line: 470}]"
[task 2019-04-09T15:18:09.551Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://gre/modules/addons/XPIProvider.jsm:470: strict error: ReferenceError: reference to undefined property "currentModifiedTime"
[task 2019-04-09T15:18:09.551Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "currentModifiedTime"
[task 2019-04-09T15:18:09.551Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://gre/modules/Extension.jsm, line 1932: ReferenceError: reference to undefined property "incognito"
[task 2019-04-09T15:18:09.552Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://gre/modules/Extension.jsm, line 1632: ReferenceError: reference to undefined property "content_security_policy"
[task 2019-04-09T15:18:09.552Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://gre/modules/Extension.jsm, line 1641: ReferenceError: reference to undefined property "optional_permissions"
[task 2019-04-09T15:18:09.554Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "incognito"" {file: "resource://gre/modules/Extension.jsm" line: 1932}]"
[task 2019-04-09T15:18:09.554Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://gre/modules/Extension.jsm:1932: strict error: ReferenceError: reference to undefined property "incognito"
[task 2019-04-09T15:18:09.554Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "incognito"
[task 2019-04-09T15:18:09.555Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "content_security_policy"" {file: "resource://gre/modules/Extension.jsm" line: 1632}]"
[task 2019-04-09T15:18:09.555Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://gre/modules/Extension.jsm:1632: strict error: ReferenceError: reference to undefined property "content_security_policy"
[task 2019-04-09T15:18:09.556Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "content_security_policy"
[task 2019-04-09T15:18:09.556Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "optional_permissions"" {file: "resource://gre/modules/Extension.jsm" line: 1641}]"
[task 2019-04-09T15:18:09.558Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://gre/modules/Extension.jsm:1641: strict error: ReferenceError: reference to undefined property "optional_permissions"
[task 2019-04-09T15:18:09.558Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "optional_permissions"
[task 2019-04-09T15:18:09.558Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Packet 3 sent from "root"
[task 2019-04-09T15:18:09.559Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Received packet 3: {
[task 2019-04-09T15:18:09.560Z] 15:18:09 INFO - PID 13474 | "from": "root",
[task 2019-04-09T15:18:09.560Z] 15:18:09 INFO - PID 13474 | "type": "addonListChanged"
[task 2019-04-09T15:18:09.560Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.561Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Packet 4 sent to "root"
[task 2019-04-09T15:18:09.561Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Received packet 4: {
[task 2019-04-09T15:18:09.562Z] 15:18:09 INFO - PID 13474 | "type": "listAddons",
[task 2019-04-09T15:18:09.562Z] 15:18:09 INFO - PID 13474 | "to": "root"
[task 2019-04-09T15:18:09.563Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.563Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Packet 5 sent from "root"
[task 2019-04-09T15:18:09.564Z] 15:18:09 INFO - PID 13474 | JavaScript strict warning: resource://devtools/shared/protocol.js, line 826: ReferenceError: reference to undefined property "actorID"
[task 2019-04-09T15:18:09.564Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Packet 6 sent from "root"
[task 2019-04-09T15:18:09.564Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Received packet 5: {
[task 2019-04-09T15:18:09.565Z] 15:18:09 INFO - PID 13474 | "from": "root",
[task 2019-04-09T15:18:09.566Z] 15:18:09 INFO - PID 13474 | "type": "addonListChanged"
[task 2019-04-09T15:18:09.567Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.577Z] 15:18:09 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "actorID"" {file: "resource://devtools/shared/protocol.js" line: 826}]"
[task 2019-04-09T15:18:09.577Z] 15:18:09 INFO - PID 13474 | DBG-TEST: resource://devtools/shared/protocol.js:826: strict error: ReferenceError: reference to undefined property "actorID"
[task 2019-04-09T15:18:09.577Z] 15:18:09 INFO - PID 13474 | DBG-TEST: head_dbg.js observed a console message: ReferenceError: reference to undefined property "actorID"
[task 2019-04-09T15:18:09.578Z] 15:18:09 INFO - PID 13474 | DBG-SERVER: Received packet 6: {
[task 2019-04-09T15:18:09.579Z] 15:18:09 INFO - PID 13474 | "from": "root",
[task 2019-04-09T15:18:09.580Z] 15:18:09 INFO - PID 13474 | "addons": [
[task 2019-04-09T15:18:09.581Z] 15:18:09 INFO - PID 13474 | {
[task 2019-04-09T15:18:09.582Z] 15:18:09 INFO - PID 13474 | "actor": "server1.conn0.webExtension1",
[task 2019-04-09T15:18:09.583Z] 15:18:09 INFO - PID 13474 | "id": "gmp-gmpopenh264",
[task 2019-04-09T15:18:09.583Z] 15:18:09 INFO - PID 13474 | "name": "OpenH264 Video Codec provided by Cisco Systems, Inc.",
[task 2019-04-09T15:18:09.583Z] 15:18:09 INFO - PID 13474 | "type": "plugin",
[task 2019-04-09T15:18:09.583Z] 15:18:09 INFO - PID 13474 | "manifestURL": null,
[task 2019-04-09T15:18:09.583Z] 15:18:09 INFO - PID 13474 | "warnings": []
[task 2019-04-09T15:18:09.583Z] 15:18:09 INFO - PID 13474 | },
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | {
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "actor": "server1.conn0.webExtension2",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "id": "Shockwave FlashFlash plug-in for testing purposes.",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "name": "Shockwave Flash",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "type": "plugin",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "manifestURL": null,
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "warnings": []
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | },
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | {
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "actor": "server1.conn0.webExtension3",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "id": "default-theme@mozilla.org",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "name": "Default",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "iconURL": "resource://gre/modules/themes/default/icon.svg",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "isSystem": false,
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "debuggable": true,
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "temporarilyInstalled": false,
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "type": "theme",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "isWebExtension": true,
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "manifestURL": "moz-extension://f3f7fc2b-e7e8-45dc-afe6-0d0549046be0/manifest.json",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "warnings": []
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | },
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | {
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "actor": "server1.conn0.webExtension4",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "id": "test-addons-actor@mozilla.org",
[task 2019-04-09T15:18:09.584Z] 15:18:09 INFO - PID 13474 | "name": "Test Addons Actor",
[task 2019-04-09T15:18:09.585Z] 15:18:09 INFO - PID 13474 | "url": "file:///builds/worker/workspace/build/tests/xpcshell/tests/devtools/server/tests/unit/addons/web-extension/",
[task 2019-04-09T15:18:09.585Z] 15:18:09 INFO - PID 13474 | "iconURL": null,
[task 2019-04-09T15:18:09.585Z] 15:18:09 INFO - PID 13474 | "isSystem": false,
[task 2019-04-09T15:18:09.585Z] 15:18:09 INFO - PID 13474 | "debuggable": true,
[task 2019-04-09T15:18:09.593Z] 15:18:09 INFO - PID 13474 | "temporarilyInstalled": true,
[task 2019-04-09T15:18:09.593Z] 15:18:09 INFO - PID 13474 | "type": "extension",
[task 2019-04-09T15:18:09.594Z] 15:18:09 INFO - PID 13474 | "isWebExtension": true,
[task 2019-04-09T15:18:09.595Z] 15:18:09 INFO - PID 13474 | "manifestURL": "moz-extension://804848b8-fe2d-4ebc-9c32-a1e75b3d69c8/manifest.json",
[task 2019-04-09T15:18:09.596Z] 15:18:09 INFO - PID 13474 | "warnings": []
[task 2019-04-09T15:18:09.597Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.598Z] 15:18:09 INFO - PID 13474 | ]
[task 2019-04-09T15:18:09.599Z] 15:18:09 INFO - PID 13474 | }
[task 2019-04-09T15:18:09.600Z] 15:18:09 INFO - TEST-PASS | devtools/server/tests/unit/test_addon_events.js | testReloadExitedAddon - [testReloadExitedAddon : 30] Received onAddonListChanged when installing addon - true == true

Pushed by rmaries@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/b739e8708f02 Disabled test_addon_events.js on Windows 7 x32. r=jmaher
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]

Reverted

Flags: needinfo?(pbrosset)
Whiteboard: [stockwell disabled] → [stockwell disabled][stockwell needswork:owner]

Julian, could you please take a look at this?

Flags: needinfo?(pbrosset) → needinfo?(jdescottes)

In the logs I can see that when this fails, we also have an AddonManager error:

[task 2019-10-23T21:44:30.637Z] 21:44:30     INFO -  PID 2956 | DBG-TEST: head_dbg.js observed a console message: 1571866770873	addons.xpi	WARN	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 2362"  data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2362
[task 2019-10-23T21:44:30.639Z] 21:44:30     INFO -  PID 2956 | callProvider()@resource://gre/modules/AddonManager.jsm:215
[task 2019-10-23T21:44:30.640Z] 21:44:30     INFO -  PID 2956 | _startProvider()@resource://gre/modules/AddonManager.jsm:651
[task 2019-10-23T21:44:30.641Z] 21:44:30     INFO -  PID 2956 | startup()@resource://gre/modules/AddonManager.jsm:875
[task 2019-10-23T21:44:30.643Z] 21:44:30     INFO -  PID 2956 | startup()@resource://gre/modules/AddonManager.jsm:3534
[task 2019-10-23T21:44:30.643Z] 21:44:30     INFO -  PID 2956 | observe()@resource://gre/modules/addonManager.js:87
[task 2019-10-23T21:44:30.645Z] 21:44:30     INFO -  PID 2956 | startupAddonsManager()@C:/tasks/task_1571864992/build/tests/xpcshell/tests/devtools/server/tests/unit/head_dbg.js:72
[task 2019-10-23T21:44:30.647Z] 21:44:30     INFO -  PID 2956 | C:/tasks/task_1571864992/build/tests/xpcshell/tests/devtools/server/tests/unit/test_addon_events.js:9
[task 2019-10-23T21:44:30.648Z] 21:44:30     INFO -  PID 2956 | load_file()@C:\\tasks\\task_1571864992\\build\\tests\\xpcshell\\head.js:682
[task 2019-10-23T21:44:30.650Z] 21:44:30     INFO -  PID 2956 | _load_files()@C:\\tasks\\task_1571864992\\build\\tests\\xpcshell\\head.js:694
[task 2019-10-23T21:44:30.651Z] 21:44:30     INFO -  PID 2956 | _execute_test()@C:\\tasks\\task_1571864992\\build\\tests\\xpcshell\\head.js:545

And locally this seems to intermittently occur when you try running both test_addon_events.js and test_addon_reload.js. It seems that running the tests with run-sequentially helps here. Let's check on try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=a0daa114df021c8b85cb1c2c9cd511677af3c871

Assignee: nobody → jdescottes
Status: NEW → ASSIGNED
Flags: needinfo?(jdescottes)

Still failing on try even with run-sequentially. Needs more investigation.

I think I found a solution. The AddonManager doesn't seem to be properly initialized when we start the tests. Using a simplified version of https://searchfox.org/mozilla-central/rev/6566d92dd46417a2f57e75c515135ebe84c9cef5/toolkit/mozapps/extensions/internal/AddonTestUtils.jsm#937-1006 seems to address the problem.

New try at https://treeherder.mozilla.org/#/jobs?repo=try&revision=992325ded7ec247c6589d9b7d86096e7dc795c4f

Pushed by jdescottes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/4d4982e04e4d Wait for the addon manager to start in DevTools addons xpcshell tests r=ochameau
Pushed by jdescottes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/7db3af2ab404 Wait for the addon manager to start in DevTools addons xpcshell tests r=ochameau
Flags: needinfo?(jdescottes)
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Keywords: leave-open
Resolution: --- → FIXED
Target Milestone: --- → Firefox 72

(In reply to Daniel Varga [:dvarga] from comment #20)

https://hg.mozilla.org/mozilla-central/rev/b739e8708f02

Did you want to revert this too? ^

Flags: needinfo?(jdescottes)
Pushed by archaeopteryx@coole-files.de: https://hg.mozilla.org/integration/autoland/rev/c20073d8b687 Enable devtools/server/tests/unit/test_addon_events.js on Windows 32-bit. a=try DONTBUILD
Whiteboard: [stockwell disabled][stockwell needswork:owner] → [stockwell disabled][stockwell needswork:owner][checkin-needed-release]
Whiteboard: [stockwell disabled][stockwell needswork:owner][checkin-needed-release] → [stockwell disabled][stockwell needswork:owner]
Flags: needinfo?(jdescottes)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: