| | | Another location This place" == "Another location This place"
06:04:03 INFO - TEST-PASS | xpcshell-libical.ini:calendar/test/unit/test_ltninvitationutils.js | compareInvitationOverlay_test - [compareInvitationOverlay_test : 534] (test #2): imipHtml-summary-content - "My new invitation My invitationMy new invitation My invitation>>>>>>
06:04:17 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
06:04:17 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
06:04:17 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
06:04:17 INFO - running event loop
06:04:17 INFO - xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | Starting test_reloading_a_temp_addon
06:04:17 INFO - (xpcshell/head.js) | test test_reloading_a_temp_addon pending (2)
06:04:17 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
06:04:17 INFO - PID 15467 | 1489496656611 addons.manager DEBUG Application has been upgraded
06:04:17 INFO - PID 15467 | 1489496656701 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider"]
06:04:17 INFO - PID 15467 | 1489496656708 addons.manager DEBUG Loaded provider scope for resource://gre/modules/LightweightThemeManager.jsm: ["LightweightThemeManager"]
06:04:17 INFO - PID 15467 | 1489496656718 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm
06:04:17 INFO - PID 15467 | 1489496656723 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm
06:04:17 INFO - PID 15467 | 1489496656724 addons.manager DEBUG Starting provider: XPIProvider
06:04:17 INFO - PID 15467 | 1489496656726 addons.xpi DEBUG startup
06:04:17 INFO - PID 15467 | 1489496656727 addons.xpi INFO SystemAddonInstallLocation directory is missing
06:04:17 INFO - PID 15467 | 1489496656729 addons.xpi DEBUG Skipping unavailable install location app-system-defaults
06:04:17 INFO - PID 15467 | 1489496656732 addons.xpi DEBUG checkForChanges
06:04:17 INFO - PID 15467 | 1489496656733 addons.xpi INFO SystemAddonInstallLocation directory is missing
06:04:17 INFO - PID 15467 | 1489496656736 addons.xpi DEBUG Loaded add-on state from prefs: {}
06:04:17 INFO - PID 15467 | 1489496656739 addons.xpi DEBUG getInstallState changed: false, state: {}
06:04:17 INFO - PID 15467 | 1489496656741 addons.xpi DEBUG Empty XPI database, setting schema version preference to 19
06:04:17 INFO - PID 15467 | 1489496656743 addons.xpi DEBUG No changes found
06:04:17 INFO - PID 15467 | 1489496656771 addons.manager DEBUG Registering shutdown blocker for XPIProvider
06:04:17 INFO - PID 15467 | 1489496656773 addons.manager DEBUG Provider finished startup: XPIProvider
06:04:17 INFO - PID 15467 | 1489496656774 addons.manager DEBUG Starting provider: LightweightThemeManager
06:04:17 INFO - PID 15467 | 1489496656775 addons.manager DEBUG Registering shutdown blocker for LightweightThemeManager
06:04:17 INFO - PID 15467 | 1489496656776 addons.manager DEBUG Provider finished startup: LightweightThemeManager
06:04:17 INFO - PID 15467 | 1489496656779 addons.manager DEBUG Starting provider: GMPProvider
06:04:17 INFO - PID 15467 | 1489496656788 addons.manager DEBUG Registering shutdown blocker for GMPProvider
06:04:17 INFO - PID 15467 | 1489496656789 addons.manager DEBUG Provider finished startup: GMPProvider
06:04:17 INFO - PID 15467 | 1489496656790 addons.manager DEBUG Starting provider: PluginProvider
06:04:17 INFO - PID 15467 | 1489496656790 addons.manager DEBUG Registering shutdown blocker for PluginProvider
06:04:17 INFO - PID 15467 | 1489496656791 addons.manager DEBUG Provider finished startup: PluginProvider
06:04:17 INFO - PID 15467 | 1489496656798 addons.manager DEBUG Completed startup sequence
06:04:17 INFO - "CONSOLE_MESSAGE: (info) 1489496656611 addons.manager DEBUG Application has been upgraded"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656701 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider"]"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656708 addons.manager DEBUG Loaded provider scope for resource://gre/modules/LightweightThemeManager.jsm: ["LightweightThemeManager"]"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656718 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656723 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656724 addons.manager DEBUG Starting provider: XPIProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656726 addons.xpi DEBUG startup"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656727 addons.xpi INFO SystemAddonInstallLocation directory is missing"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656729 addons.xpi DEBUG Skipping unavailable install location app-system-defaults"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656732 addons.xpi DEBUG checkForChanges"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656733 addons.xpi INFO SystemAddonInstallLocation directory is missing"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656736 addons.xpi DEBUG Loaded add-on state from prefs: {}"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656739 addons.xpi DEBUG getInstallState changed: false, state: {}"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656741 addons.xpi DEBUG Empty XPI database, setting schema version preference to 19"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656743 addons.xpi DEBUG No changes found"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656771 addons.manager DEBUG Registering shutdown blocker for XPIProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656773 addons.manager DEBUG Provider finished startup: XPIProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656774 addons.manager DEBUG Starting provider: LightweightThemeManager"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656775 addons.manager DEBUG Registering shutdown blocker for LightweightThemeManager"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656776 addons.manager DEBUG Provider finished startup: LightweightThemeManager"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656779 addons.manager DEBUG Starting provider: GMPProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656788 addons.manager DEBUG Registering shutdown blocker for GMPProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656789 addons.manager DEBUG Provider finished startup: GMPProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656790 addons.manager DEBUG Starting provider: PluginProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656790 addons.manager DEBUG Registering shutdown blocker for PluginProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656791 addons.manager DEBUG Provider finished startup: PluginProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496656798 addons.manager DEBUG Completed startup sequence"
06:04:18 INFO - PID 15467 | 1489496657005 addons.xpi-utils DEBUG Starting async load of XPI database /tmp/xpc-profile-a845GQ/extensions.json
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657005 addons.xpi-utils DEBUG Starting async load of XPI database /tmp/xpc-profile-a845GQ/extensions.json"
06:04:18 INFO - PID 15467 | 1489496657012 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions
06:04:18 INFO - PID 15467 | 1489496657013 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:18 INFO - PID 15467 | 1489496657016 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:18 INFO - PID 15467 | 1489496657022 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - PID 15467 | 1489496657023 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed.
06:04:18 INFO - PID 15467 | 1489496657026 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible
06:04:18 INFO - PID 15467 | 1489496657041 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657041 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657042 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657043 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657044 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:18 INFO - PID 15467 | 1489496657047 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{9de1fe34-163d-4452-980a-266ed30095b2}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","installDate":1489496657013,"applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}
06:04:18 INFO - PID 15467 | 1489496657051 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org
06:04:18 INFO - PID 15467 | 1489496657052 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657052 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657052 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657053 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657054 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - PID 15467 | 1489496657071 DeferredSave.extensions.json DEBUG Starting timer
06:04:18 INFO - PID 15467 | 1489496657088 addons.xpi DEBUG reloading add-on webextension1@tests.mozilla.org
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657012 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657013 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657016 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657022 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657023 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657026 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657041 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657041 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657042 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657043 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657044 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657047 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{9de1fe34-163d-4452-980a-266ed30095b2}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","installDate":1489496657013,"applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657051 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657052 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657052 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657052 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657053 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657054 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657071 DeferredSave.extensions.json DEBUG Starting timer"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657088 addons.xpi DEBUG reloading add-on webextension1@tests.mozilla.org"
06:04:18 INFO - PID 15467 | 1489496657145 addons.xpi WARN Addon with ID webextension1@tests.mozilla.org already installed, older version will be disabled
06:04:18 INFO - PID 15467 | 1489496657146 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - PID 15467 | JavaScript strict warning: resource://gre/modules/ExtensionManagement.jsm, line 179: ReferenceError: reference to undefined property "aps"
06:04:18 INFO - PID 15467 | 1489496657152 addons.xpi WARN Exception running bootstrap method shutdown on webextension1@tests.mozilla.org: TypeError: this.aps is undefined (resource://gre/modules/ExtensionManagement.jsm:179:5) JS Stack trace: shutdownExtension@ExtensionManagement.jsm:179:5 < shutdown@Extension.jsm:956:7 < shutdown@WebExtensionBootstrap.js:33:3 < callBootstrapMethod@XPIProvider.jsm:4953:11 < this.XPIProvider.installAddonFromLocation<@XPIProvider.jsm:4092:11 < installTemporaryAddon@XPIProvider.jsm:4006:12 < installTemporaryAddon@AddonManager.jsm:2300:12 < installTemporaryAddon@AddonManager.jsm:3624:12 < reload/<@XPIProvider.jsm:7709:17 < Promise@Promise-backend.js:390:5 < reload@XPIProvider.jsm:7696:12 < test_reloading_a_temp_addon@test_reload.js:84:5 < TaskImpl_run@Task.jsm:319:42 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < onError@osfile_native.jsm:66:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1
06:04:18 INFO - PID 15467 | 1489496657170 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - PID 15467 | 1489496657171 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:18 INFO - PID 15467 | 1489496657176 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:18 INFO - PID 15467 | 1489496657184 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - PID 15467 | 1489496657184 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed.
06:04:18 INFO - PID 15467 | 1489496657185 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible
06:04:18 INFO - PID 15467 | 1489496657185 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657186 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657192 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657192 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657192 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:18 INFO - PID 15467 | 1489496657193 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{baa6b67d-aa33-4d44-a74e-47bc05951b28}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}
06:04:18 INFO - PID 15467 | 1489496657193 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org
06:04:18 INFO - PID 15467 | 1489496657194 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657195 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657199 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:18 INFO - PID 15467 | 1489496657199 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - TEST-PASS | xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 70] "webextension1@tests.mozilla.org" == "webextension1@tests.mozilla.org"
06:04:18 INFO - PID 15467 | 1489496657231 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - TEST-PASS | xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 74] "webextension1@tests.mozilla.org" == "webextension1@tests.mozilla.org"
06:04:18 INFO - PID 15467 | 1489496657242 DeferredSave.extensions.json DEBUG Starting write
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657145 addons.xpi WARN Addon with ID webextension1@tests.mozilla.org already installed, older version will be disabled"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657146 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "aps"" {file: "resource://gre/modules/ExtensionManagement.jsm" line: 179}]"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657152 addons.xpi WARN Exception running bootstrap method shutdown on webextension1@tests.mozilla.org: TypeError: this.aps is undefined (resource://gre/modules/ExtensionManagement.jsm:179:5) JS Stack trace: shutdownExtension@ExtensionManagement.jsm:179:5 < shutdown@Extension.jsm:956:7 < shutdown@WebExtensionBootstrap.js:33:3 < callBootstrapMethod@XPIProvider.jsm:4953:11 < this.XPIProvider.installAddonFromLocation<@XPIProvider.jsm:4092:11 < installTemporaryAddon@XPIProvider.jsm:4006:12 < installTemporaryAddon@AddonManager.jsm:2300:12 < installTemporaryAddon@AddonManager.jsm:3624:12 < reload/<@XPIProvider.jsm:7709:17 < Promise@Promise-backend.js:390:5 < reload@XPIProvider.jsm:7696:12 < test_reloading_a_temp_addon@test_reload.js:84:5 < TaskImpl_run@Task.jsm:319:42 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < onError@osfile_native.jsm:66:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657170 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657171 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657176 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657184 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657184 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657185 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657185 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657186 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657192 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657192 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657192 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657193 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{baa6b67d-aa33-4d44-a74e-47bc05951b28}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657193 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657194 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657195 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657199 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657199 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657231 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657242 DeferredSave.extensions.json DEBUG Starting write"
06:04:18 INFO - PID 15467 | 1489496657275 DeferredSave.extensions.json DEBUG Write succeeded
06:04:18 INFO - PID 15467 | 1489496657275 addons.xpi-utils DEBUG XPI Database saved, setting schema version preference to 19
06:04:18 INFO - PID 15467 | Extension error: A mutation operation was attempted on a database that did not allow mutations. resource://gre/modules/IndexedDB.jsm:294 :: transaction@resource://gre/modules/IndexedDB.jsm:294:39
06:04:18 INFO - PID 15467 | objectStore@resource://gre/modules/IndexedDB.jsm:322:23
06:04:18 INFO - PID 15467 | get@resource://gre/modules/ExtensionUtils.jsm:158:7
06:04:18 INFO - PID 15467 | _do_main@/builds/slave/test/build/tests/xpcshell/head.js:211:5
06:04:18 INFO - PID 15467 | _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:546:5
06:04:18 INFO - PID 15467 | @-e:1:1
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657275 DeferredSave.extensions.json DEBUG Write succeeded"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657275 addons.xpi-utils DEBUG XPI Database saved, setting schema version preference to 19"
06:04:18 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "InvalidStateError: A mutation operation was attempted on a database that did not allow mutations."]
06:04:18 INFO - transaction@resource://gre/modules/IndexedDB.jsm:294:39
06:04:18 INFO - objectStore@resource://gre/modules/IndexedDB.jsm:322:23
06:04:18 INFO - get@resource://gre/modules/ExtensionUtils.jsm:158:7
06:04:18 INFO - _do_main@/builds/slave/test/build/tests/xpcshell/head.js:211:5
06:04:18 INFO - _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:546:5
06:04:18 INFO - @-e:1:1
06:04:18 INFO - "
06:04:18 INFO - TEST-PASS | xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 90] reload should not trigger onUninstalled - false == false
06:04:18 INFO - TEST-PASS | xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 91] reload should not trigger onUninstalling - false == false
06:04:18 INFO - TEST-PASS | xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 94] reload should trigger onInstalling - true == true
06:04:18 INFO - TEST-PASS | xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 95] reload should trigger onInstalled - true == true
06:04:18 INFO - PID 15467 | 1489496657634 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - PID 15467 | 1489496657638 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0
06:04:18 INFO - PID 15467 | 1489496657640 DeferredSave.extensions.json DEBUG Save changes
06:04:18 INFO - PID 15467 | 1489496657641 addons.xpi DEBUG Removing XPIState for app-temporary:webextension1@tests.mozilla.org
06:04:18 INFO - PID 15467 | 1489496657649 addons.manager WARN AddonListener threw exception when calling onUninstalled: TypeError: Services.domStorageManager.getStorage(...) is null (resource://gre/modules/Extension.jsm:202:7) JS Stack trace: onUninstalled@Extension.jsm:202:7 < callAddonListeners@AddonManager.jsm:1693:11 < callAddonListeners@AddonManager.jsm:3160:5 < uninstallAddon@XPIProvider.jsm:5258:7 < uninstall@XPIProvider.jsm:7617:5 < tearDownAddon@test_reload.js:42:3 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < listener@test_reload.js:29:7 < runSafeSyncWithoutClone@ExtensionUtils.jsm:189:14 < emit/promises<@ExtensionUtils.jsm:509:55 < emit@ExtensionUtils.jsm:508:20 < startup/<@Extension.jsm:906:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1
06:04:18 INFO - PID 15467 | 1489496657659 DeferredSave.extensions.json DEBUG Starting timer
06:04:18 INFO - PID 15467 | 1489496657664 addons.manager DEBUG shutdown
06:04:18 INFO - PID 15467 | 1489496657665 addons.manager DEBUG Calling shutdown blocker for XPIProvider
06:04:18 INFO - PID 15467 | 1489496657666 addons.xpi DEBUG shutdown
06:04:18 INFO - PID 15467 | 1489496657667 addons.xpi-utils DEBUG shutdown
06:04:18 INFO - PID 15467 | 1489496657667 DeferredSave.extensions.json DEBUG Flush called while data is dirty
06:04:18 INFO - PID 15467 | 1489496657669 addons.manager DEBUG Calling shutdown blocker for LightweightThemeManager
06:04:18 INFO - PID 15467 | 1489496657670 addons.manager DEBUG Calling shutdown blocker for GMPProvider
06:04:18 INFO - PID 15467 | 1489496657676 addons.manager DEBUG Calling shutdown blocker for PluginProvider
06:04:18 INFO - PID 15467 | 1489496657678 DeferredSave.extensions.json DEBUG Starting write
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657634 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657638 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657640 DeferredSave.extensions.json DEBUG Save changes"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657641 addons.xpi DEBUG Removing XPIState for app-temporary:webextension1@tests.mozilla.org"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657649 addons.manager WARN AddonListener threw exception when calling onUninstalled: TypeError: Services.domStorageManager.getStorage(...) is null (resource://gre/modules/Extension.jsm:202:7) JS Stack trace: onUninstalled@Extension.jsm:202:7 < callAddonListeners@AddonManager.jsm:1693:11 < callAddonListeners@AddonManager.jsm:3160:5 < uninstallAddon@XPIProvider.jsm:5258:7 < uninstall@XPIProvider.jsm:7617:5 < tearDownAddon@test_reload.js:42:3 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < listener@test_reload.js:29:7 < runSafeSyncWithoutClone@ExtensionUtils.jsm:189:14 < emit/promises<@ExtensionUtils.jsm:509:55 < emit@ExtensionUtils.jsm:508:20 < startup/<@Extension.jsm:906:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657659 DeferredSave.extensions.json DEBUG Starting timer"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657664 addons.manager DEBUG shutdown"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657665 addons.manager DEBUG Calling shutdown blocker for XPIProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657666 addons.xpi DEBUG shutdown"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657667 addons.xpi-utils DEBUG shutdown"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657667 DeferredSave.extensions.json DEBUG Flush called while data is dirty"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657669 addons.manager DEBUG Calling shutdown blocker for LightweightThemeManager"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657670 addons.manager DEBUG Calling shutdown blocker for GMPProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657676 addons.manager DEBUG Calling shutdown blocker for PluginProvider"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657678 DeferredSave.extensions.json DEBUG Starting write"
06:04:18 INFO - PID 15467 | 1489496657730 DeferredSave.extensions.json DEBUG Write succeeded
06:04:18 INFO - PID 15467 | 1489496657740 addons.xpi DEBUG Notifying XPI shutdown observers
06:04:18 INFO - PID 15467 | 1489496657747 addons.manager DEBUG Async provider shutdown done
06:04:18 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
06:04:18 INFO - (xpcshell/head.js) | test test_reloading_a_temp_addon finished (2)
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657730 DeferredSave.extensions.json DEBUG Write succeeded"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657740 addons.xpi DEBUG Notifying XPI shutdown observers"
06:04:18 INFO - "CONSOLE_MESSAGE: (info) 1489496657747 addons.manager DEBUG Async provider shutdown done"
06:04:18 WARNING - TEST-UNEXPECTED-FAIL | xpcshell-unpack.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 224] A promise chain failed to handle a rejection: A mutation operation was attempted on a database that did not allow mutations. - rejection date: Tue Mar 14 2017 06:04:17 GMT-0700 (PDT) - stack: _do_main@/builds/slave/test/build/tests/xpcshell/head.js:211:5
06:04:18 INFO - _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:546:5
06:04:18 INFO - @-e:1:1
06:04:18 INFO - - false == true
06:04:18 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:224
06:04:18 INFO - /builds/slave/test/build/tests/xpcshell/head.js:_run_next_test:1533
06:04:18 INFO - /builds/slave/test/build/tests/xpcshell/head.js:run:703
06:04:18 INFO - /builds/slave/test/build/tests/xpcshell/head.js:_do_main:211
06:04:18 INFO - /builds/slave/test/build/tests/xpcshell/head.js:_execute_test:546
06:04:18 INFO - -e:null:1
06:04:18 INFO - exiting test
06:04:18 INFO - (xpcshell/head.js) | test run_next_test 1 finished (1)
06:04:18 INFO - exiting test
06:04:18 INFO - <<<<<<<
06:04:18 INFO - TEST-START | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js
06:04:20 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | xpcshell return code: 0
06:04:20 INFO - TEST-INFO took 2036ms
06:04:20 INFO - >>>>>>>
06:04:20 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
06:04:20 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
06:04:20 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
06:04:20 INFO - running event loop
06:04:20 INFO - xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | Starting test_reloading_a_temp_addon
06:04:20 INFO - (xpcshell/head.js) | test test_reloading_a_temp_addon pending (2)
06:04:20 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
06:04:20 INFO - PID 15496 | 1489496658836 addons.manager DEBUG Application has been upgraded
06:04:20 INFO - PID 15496 | 1489496658934 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider"]
06:04:20 INFO - PID 15496 | 1489496658941 addons.manager DEBUG Loaded provider scope for resource://gre/modules/LightweightThemeManager.jsm: ["LightweightThemeManager"]
06:04:20 INFO - PID 15496 | 1489496658953 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm
06:04:20 INFO - PID 15496 | 1489496658959 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm
06:04:20 INFO - PID 15496 | 1489496658961 addons.manager DEBUG Starting provider: XPIProvider
06:04:20 INFO - PID 15496 | 1489496658962 addons.xpi DEBUG startup
06:04:20 INFO - PID 15496 | 1489496658964 addons.xpi INFO SystemAddonInstallLocation directory is missing
06:04:20 INFO - PID 15496 | 1489496658966 addons.xpi DEBUG Skipping unavailable install location app-system-defaults
06:04:20 INFO - PID 15496 | 1489496658968 addons.xpi DEBUG checkForChanges
06:04:20 INFO - PID 15496 | 1489496658970 addons.xpi INFO SystemAddonInstallLocation directory is missing
06:04:20 INFO - PID 15496 | 1489496658973 addons.xpi DEBUG Loaded add-on state from prefs: {}
06:04:20 INFO - PID 15496 | 1489496658977 addons.xpi DEBUG getInstallState changed: false, state: {}
06:04:20 INFO - PID 15496 | 1489496658979 addons.xpi DEBUG Empty XPI database, setting schema version preference to 19
06:04:20 INFO - PID 15496 | 1489496658981 addons.xpi DEBUG No changes found
06:04:20 INFO - PID 15496 | 1489496659012 addons.manager DEBUG Registering shutdown blocker for XPIProvider
06:04:20 INFO - PID 15496 | 1489496659014 addons.manager DEBUG Provider finished startup: XPIProvider
06:04:20 INFO - PID 15496 | 1489496659015 addons.manager DEBUG Starting provider: LightweightThemeManager
06:04:20 INFO - PID 15496 | 1489496659016 addons.manager DEBUG Registering shutdown blocker for LightweightThemeManager
06:04:20 INFO - PID 15496 | 1489496659017 addons.manager DEBUG Provider finished startup: LightweightThemeManager
06:04:20 INFO - PID 15496 | 1489496659020 addons.manager DEBUG Starting provider: GMPProvider
06:04:20 INFO - PID 15496 | 1489496659031 addons.manager DEBUG Registering shutdown blocker for GMPProvider
06:04:20 INFO - PID 15496 | 1489496659032 addons.manager DEBUG Provider finished startup: GMPProvider
06:04:20 INFO - PID 15496 | 1489496659032 addons.manager DEBUG Starting provider: PluginProvider
06:04:20 INFO - PID 15496 | 1489496659032 addons.manager DEBUG Registering shutdown blocker for PluginProvider
06:04:20 INFO - PID 15496 | 1489496659033 addons.manager DEBUG Provider finished startup: PluginProvider
06:04:20 INFO - PID 15496 | 1489496659042 addons.manager DEBUG Completed startup sequence
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658836 addons.manager DEBUG Application has been upgraded"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658934 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider"]"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658941 addons.manager DEBUG Loaded provider scope for resource://gre/modules/LightweightThemeManager.jsm: ["LightweightThemeManager"]"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658953 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658959 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658961 addons.manager DEBUG Starting provider: XPIProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658962 addons.xpi DEBUG startup"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658964 addons.xpi INFO SystemAddonInstallLocation directory is missing"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658966 addons.xpi DEBUG Skipping unavailable install location app-system-defaults"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658968 addons.xpi DEBUG checkForChanges"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658970 addons.xpi INFO SystemAddonInstallLocation directory is missing"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658973 addons.xpi DEBUG Loaded add-on state from prefs: {}"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658977 addons.xpi DEBUG getInstallState changed: false, state: {}"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658979 addons.xpi DEBUG Empty XPI database, setting schema version preference to 19"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496658981 addons.xpi DEBUG No changes found"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659012 addons.manager DEBUG Registering shutdown blocker for XPIProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659014 addons.manager DEBUG Provider finished startup: XPIProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659015 addons.manager DEBUG Starting provider: LightweightThemeManager"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659016 addons.manager DEBUG Registering shutdown blocker for LightweightThemeManager"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659017 addons.manager DEBUG Provider finished startup: LightweightThemeManager"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659020 addons.manager DEBUG Starting provider: GMPProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659031 addons.manager DEBUG Registering shutdown blocker for GMPProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659032 addons.manager DEBUG Provider finished startup: GMPProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659032 addons.manager DEBUG Starting provider: PluginProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659032 addons.manager DEBUG Registering shutdown blocker for PluginProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659033 addons.manager DEBUG Provider finished startup: PluginProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659042 addons.manager DEBUG Completed startup sequence"
06:04:20 INFO - PID 15496 | 1489496659246 addons.xpi-utils DEBUG Starting async load of XPI database /tmp/xpc-profile-BGNgC0/extensions.json
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659246 addons.xpi-utils DEBUG Starting async load of XPI database /tmp/xpc-profile-BGNgC0/extensions.json"
06:04:20 INFO - PID 15496 | 1489496659252 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions
06:04:20 INFO - PID 15496 | 1489496659254 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:20 INFO - PID 15496 | 1489496659257 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:20 INFO - PID 15496 | 1489496659263 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - PID 15496 | 1489496659264 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed.
06:04:20 INFO - PID 15496 | 1489496659268 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible
06:04:20 INFO - PID 15496 | 1489496659282 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659283 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659284 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659285 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659285 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:20 INFO - PID 15496 | 1489496659289 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{d8a0c801-5978-48f6-9c72-703fb1fc52c4}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","installDate":1489496659254,"applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}
06:04:20 INFO - PID 15496 | 1489496659295 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org
06:04:20 INFO - PID 15496 | 1489496659296 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659296 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659297 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659297 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659299 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - PID 15496 | 1489496659313 DeferredSave.extensions.json DEBUG Starting timer
06:04:20 INFO - PID 15496 | 1489496659329 addons.xpi DEBUG reloading add-on webextension1@tests.mozilla.org
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659252 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659254 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659257 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659263 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659264 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659268 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659282 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659283 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659284 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659285 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659285 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659289 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{d8a0c801-5978-48f6-9c72-703fb1fc52c4}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","installDate":1489496659254,"applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659295 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659296 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659296 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659297 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659297 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659299 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659313 DeferredSave.extensions.json DEBUG Starting timer"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659329 addons.xpi DEBUG reloading add-on webextension1@tests.mozilla.org"
06:04:20 INFO - PID 15496 | 1489496659383 addons.xpi WARN Addon with ID webextension1@tests.mozilla.org already installed, older version will be disabled
06:04:20 INFO - PID 15496 | 1489496659392 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - PID 15496 | JavaScript strict warning: resource://gre/modules/ExtensionManagement.jsm, line 179: ReferenceError: reference to undefined property "aps"
06:04:20 INFO - PID 15496 | 1489496659394 addons.xpi WARN Exception running bootstrap method shutdown on webextension1@tests.mozilla.org: TypeError: this.aps is undefined (resource://gre/modules/ExtensionManagement.jsm:179:5) JS Stack trace: shutdownExtension@ExtensionManagement.jsm:179:5 < shutdown@Extension.jsm:956:7 < shutdown@WebExtensionBootstrap.js:33:3 < callBootstrapMethod@XPIProvider.jsm:4953:11 < this.XPIProvider.installAddonFromLocation<@XPIProvider.jsm:4092:11 < installTemporaryAddon@XPIProvider.jsm:4006:12 < installTemporaryAddon@AddonManager.jsm:2300:12 < installTemporaryAddon@AddonManager.jsm:3624:12 < reload/<@XPIProvider.jsm:7709:17 < Promise@Promise-backend.js:390:5 < reload@XPIProvider.jsm:7696:12 < test_reloading_a_temp_addon@test_reload.js:84:5 < TaskImpl_run@Task.jsm:319:42 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < onError@osfile_native.jsm:66:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1
06:04:20 INFO - PID 15496 | 1489496659407 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - PID 15496 | 1489496659416 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:20 INFO - PID 15496 | 1489496659417 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:20 INFO - PID 15496 | 1489496659428 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - PID 15496 | 1489496659428 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed.
06:04:20 INFO - PID 15496 | 1489496659429 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible
06:04:20 INFO - PID 15496 | 1489496659429 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659430 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659431 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659432 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659432 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi
06:04:20 INFO - PID 15496 | 1489496659433 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{c5f8ea3f-4f6d-4bf6-a84a-006f0361738d}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}
06:04:20 INFO - PID 15496 | 1489496659433 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org
06:04:20 INFO - PID 15496 | 1489496659434 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659435 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659439 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout.
06:04:20 INFO - PID 15496 | 1489496659439 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 70] "webextension1@tests.mozilla.org" == "webextension1@tests.mozilla.org"
06:04:20 INFO - PID 15496 | 1489496659473 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 74] "webextension1@tests.mozilla.org" == "webextension1@tests.mozilla.org"
06:04:20 INFO - PID 15496 | 1489496659483 DeferredSave.extensions.json DEBUG Starting write
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659383 addons.xpi WARN Addon with ID webextension1@tests.mozilla.org already installed, older version will be disabled"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659392 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "aps"" {file: "resource://gre/modules/ExtensionManagement.jsm" line: 179}]"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659394 addons.xpi WARN Exception running bootstrap method shutdown on webextension1@tests.mozilla.org: TypeError: this.aps is undefined (resource://gre/modules/ExtensionManagement.jsm:179:5) JS Stack trace: shutdownExtension@ExtensionManagement.jsm:179:5 < shutdown@Extension.jsm:956:7 < shutdown@WebExtensionBootstrap.js:33:3 < callBootstrapMethod@XPIProvider.jsm:4953:11 < this.XPIProvider.installAddonFromLocation<@XPIProvider.jsm:4092:11 < installTemporaryAddon@XPIProvider.jsm:4006:12 < installTemporaryAddon@AddonManager.jsm:2300:12 < installTemporaryAddon@AddonManager.jsm:3624:12 < reload/<@XPIProvider.jsm:7709:17 < Promise@Promise-backend.js:390:5 < reload@XPIProvider.jsm:7696:12 < test_reloading_a_temp_addon@test_reload.js:84:5 < TaskImpl_run@Task.jsm:319:42 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < onError@osfile_native.jsm:66:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659407 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659416 addons.xpi INFO Mapping webextension1@tests.mozilla.org to /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659417 addons.xpi DEBUG Loading bootstrap scope from /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659428 addons.xpi DEBUG Calling bootstrap method install on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659428 addons.xpi DEBUG Install of temporary addon in /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi completed."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659429 addons.xpi-utils DEBUG Make addon app-temporary:webextension1@tests.mozilla.org visible"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659429 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659430 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659431 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659432 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659432 addons.xpi DEBUG XPIStates adding add-on webextension1@tests.mozilla.org in app-temporary: /builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659433 addons.xpi DEBUG Updating XPIState for {"id":"webextension1@tests.mozilla.org","syncGUID":"{c5f8ea3f-4f6d-4bf6-a84a-006f0361738d}","location":"app-temporary","version":"1.0","type":"webextension","internalName":null,"updateURL":null,"updateKey":null,"optionsURL":null,"optionsType":null,"aboutURL":null,"icons":{"48":"icon48.png","64":"icon64.png"},"iconURL":null,"icon64URL":null,"defaultLocale":{"name":"Web Extension Name","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"descriptor":"/builds/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/addons/webextension_1.xpi","applyBackgroundUpdates":1,"bootstrap":true,"skinnable":false,"size":254,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"hasBinaryComponents":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"multiprocessCompatible":true,"seen":true,"dependencies":[],"hasEmbeddedWebExtension":false,"userPermissions":{"hosts":[],"apis":[],"permissions":[]}}"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659433 addons.xpi DEBUG getModTime: Recursive scan of webextension1@tests.mozilla.org"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659434 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659435 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659439 addons.xpi DEBUG Add-on webextension1@tests.mozilla.org blocks e10s rollout."
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659439 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659473 addons.xpi DEBUG Calling bootstrap method startup on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659483 DeferredSave.extensions.json DEBUG Starting write"
06:04:20 INFO - PID 15496 | 1489496659515 DeferredSave.extensions.json DEBUG Write succeeded
06:04:20 INFO - PID 15496 | 1489496659515 addons.xpi-utils DEBUG XPI Database saved, setting schema version preference to 19
06:04:20 INFO - PID 15496 | Extension error: A mutation operation was attempted on a database that did not allow mutations. resource://gre/modules/IndexedDB.jsm:294 :: transaction@resource://gre/modules/IndexedDB.jsm:294:39
06:04:20 INFO - PID 15496 | objectStore@resource://gre/modules/IndexedDB.jsm:322:23
06:04:20 INFO - PID 15496 | get@resource://gre/modules/ExtensionUtils.jsm:158:7
06:04:20 INFO - PID 15496 | _do_main@/builds/slave/test/build/tests/xpcshell/head.js:211:5
06:04:20 INFO - PID 15496 | _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:546:5
06:04:20 INFO - PID 15496 | @-e:1:1
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659515 DeferredSave.extensions.json DEBUG Write succeeded"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659515 addons.xpi-utils DEBUG XPI Database saved, setting schema version preference to 19"
06:04:20 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "InvalidStateError: A mutation operation was attempted on a database that did not allow mutations."]
06:04:20 INFO - transaction@resource://gre/modules/IndexedDB.jsm:294:39
06:04:20 INFO - objectStore@resource://gre/modules/IndexedDB.jsm:322:23
06:04:20 INFO - get@resource://gre/modules/ExtensionUtils.jsm:158:7
06:04:20 INFO - _do_main@/builds/slave/test/build/tests/xpcshell/head.js:211:5
06:04:20 INFO - _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:546:5
06:04:20 INFO - @-e:1:1
06:04:20 INFO - "
06:04:20 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 90] reload should not trigger onUninstalled - false == false
06:04:20 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 91] reload should not trigger onUninstalling - false == false
06:04:20 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 94] reload should trigger onInstalling - true == true
06:04:20 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 95] reload should trigger onInstalled - true == true
06:04:20 INFO - PID 15496 | 1489496659839 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - PID 15496 | 1489496659842 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0
06:04:20 INFO - PID 15496 | 1489496659845 DeferredSave.extensions.json DEBUG Save changes
06:04:20 INFO - PID 15496 | 1489496659845 addons.xpi DEBUG Removing XPIState for app-temporary:webextension1@tests.mozilla.org
06:04:20 INFO - PID 15496 | 1489496659853 addons.manager WARN AddonListener threw exception when calling onUninstalled: TypeError: Services.domStorageManager.getStorage(...) is null (resource://gre/modules/Extension.jsm:202:7) JS Stack trace: onUninstalled@Extension.jsm:202:7 < callAddonListeners@AddonManager.jsm:1693:11 < callAddonListeners@AddonManager.jsm:3160:5 < uninstallAddon@XPIProvider.jsm:5258:7 < uninstall@XPIProvider.jsm:7617:5 < tearDownAddon@test_reload.js:42:3 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < listener@test_reload.js:29:7 < runSafeSyncWithoutClone@ExtensionUtils.jsm:189:14 < emit/promises<@ExtensionUtils.jsm:509:55 < emit@ExtensionUtils.jsm:508:20 < startup/<@Extension.jsm:906:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1
06:04:20 INFO - PID 15496 | 1489496659863 DeferredSave.extensions.json DEBUG Starting timer
06:04:20 INFO - PID 15496 | 1489496659868 addons.manager DEBUG shutdown
06:04:20 INFO - PID 15496 | 1489496659869 addons.manager DEBUG Calling shutdown blocker for XPIProvider
06:04:20 INFO - PID 15496 | 1489496659870 addons.xpi DEBUG shutdown
06:04:20 INFO - PID 15496 | 1489496659870 addons.xpi-utils DEBUG shutdown
06:04:20 INFO - PID 15496 | 1489496659871 DeferredSave.extensions.json DEBUG Flush called while data is dirty
06:04:20 INFO - PID 15496 | 1489496659872 addons.manager DEBUG Calling shutdown blocker for LightweightThemeManager
06:04:20 INFO - PID 15496 | 1489496659873 addons.manager DEBUG Calling shutdown blocker for GMPProvider
06:04:20 INFO - PID 15496 | 1489496659878 addons.manager DEBUG Calling shutdown blocker for PluginProvider
06:04:20 INFO - PID 15496 | 1489496659881 DeferredSave.extensions.json DEBUG Starting write
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659839 addons.xpi DEBUG Calling bootstrap method shutdown on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659842 addons.xpi DEBUG Calling bootstrap method uninstall on webextension1@tests.mozilla.org version 1.0"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659845 DeferredSave.extensions.json DEBUG Save changes"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659845 addons.xpi DEBUG Removing XPIState for app-temporary:webextension1@tests.mozilla.org"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659853 addons.manager WARN AddonListener threw exception when calling onUninstalled: TypeError: Services.domStorageManager.getStorage(...) is null (resource://gre/modules/Extension.jsm:202:7) JS Stack trace: onUninstalled@Extension.jsm:202:7 < callAddonListeners@AddonManager.jsm:1693:11 < callAddonListeners@AddonManager.jsm:3160:5 < uninstallAddon@XPIProvider.jsm:5258:7 < uninstall@XPIProvider.jsm:7617:5 < tearDownAddon@test_reload.js:42:3 < process@Promise-backend.js:922:23 < walkerLoop@Promise-backend.js:806:7 < Promise*scheduleWalkerLoop@Promise-backend.js:739:11 < schedulePromise@Promise-backend.js:770:7 < completePromise@Promise-backend.js:707:7 < listener@test_reload.js:29:7 < runSafeSyncWithoutClone@ExtensionUtils.jsm:189:14 < emit/promises<@ExtensionUtils.jsm:509:55 < emit@ExtensionUtils.jsm:508:20 < startup/<@Extension.jsm:906:7 < _do_main@head.js:211:5 < _execute_test@head.js:546:5 < @-e:1:1"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659863 DeferredSave.extensions.json DEBUG Starting timer"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659868 addons.manager DEBUG shutdown"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659869 addons.manager DEBUG Calling shutdown blocker for XPIProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659870 addons.xpi DEBUG shutdown"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659870 addons.xpi-utils DEBUG shutdown"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659871 DeferredSave.extensions.json DEBUG Flush called while data is dirty"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659872 addons.manager DEBUG Calling shutdown blocker for LightweightThemeManager"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659873 addons.manager DEBUG Calling shutdown blocker for GMPProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659878 addons.manager DEBUG Calling shutdown blocker for PluginProvider"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659881 DeferredSave.extensions.json DEBUG Starting write"
06:04:20 INFO - PID 15496 | 1489496659937 DeferredSave.extensions.json DEBUG Write succeeded
06:04:20 INFO - PID 15496 | 1489496659945 addons.xpi DEBUG Notifying XPI shutdown observers
06:04:20 INFO - PID 15496 | 1489496659952 addons.manager DEBUG Async provider shutdown done
06:04:20 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
06:04:20 INFO - (xpcshell/head.js) | test test_reloading_a_temp_addon finished (2)
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659937 DeferredSave.extensions.json DEBUG Write succeeded"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659945 addons.xpi DEBUG Notifying XPI shutdown observers"
06:04:20 INFO - "CONSOLE_MESSAGE: (info) 1489496659952 addons.manager DEBUG Async provider shutdown done"
06:04:20 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_reload.js | test_reloading_a_temp_addon - [test_reloading_a_temp_addon : 224] A promise chain failed to handle a rejection: A mutation operation was attempted on a database that did not allow mutations. - rejection date: Tue Mar 14 2017 06:04:19 GMT-0700 (PDT) - stack: _do_main@/builds/slave/test/build/tests/xpcshell/head.js:211:5
06:04:20 INFO - _execute_test@/builds/slave/test/build/tests/xpcshell/head.js:546:5
06:04:20 INFO - @-e:1:1
06:04:20 INFO - - false == true
06:04:20 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:224
06:04:20 INFO - /builds/slave/test/build/tests/xpcshell/head.js:_run_next_test:1533
06:04:20 INFO - /builds/slave/test/build/tests/xpcshell/head.js:run:703
06:04:20 INFO - /builds/slave/test/build/tests/xpcshell/head.js:_do_main:211
06:04:20 INFO - /builds/slave/test/build/tests/xpcshell/head.js:_execute_test:546
06:04:20 INFO - -e:null:1
06:04:20 INFO - exiting test
06:04:20 INFO - (xpcshell/head.js) | test run_next_test 1 finished (1)
06:04:20 INFO - exiting test
06:04:20 INFO - <<<<<<<
06:04:20 INFO - Node moz-http2 server shutting down ...
06:04:20 INFO - INFO | Result summary:
06:04:20 INFO - INFO | Passed: 3252
06:04:20 WARNING - INFO | Failed: 4
06:04:20 WARNING - One or more unittests failed.
06:04:20 INFO - INFO | Todo: 4
06:04:20 INFO - INFO | Retried: 6
06:04:20 INFO - SUITE-END | took 5980s
06:04:20 ERROR - Return code: 1
06:04:20 INFO - TinderboxPrint: xpcshell-xpcshell 3252/4
06:04:20 WARNING - # TBPL FAILURE #
06:04:20 WARNING - setting return code to 2
06:04:20 WARNING - The xpcshell suite: xpcshell ran with return status: FAILURE
06:04:20 INFO - Running post-action listener: _package_coverage_data
06:04:20 INFO - Running post-action listener: _resource_record_post_action
06:04:20 INFO - [mozharness: 2017-03-14 13:04:20.607238Z] Finished run-tests step (success)
06:04:20 INFO - Running post-run listener: _resource_record_post_run
06:04:21 INFO - Validating Perfherder data against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json
06:04:21 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 98.76357582820039}, {"name": "io_write_bytes", "value": 7903588352}, {"name": "io.read_bytes", "value": 89149440}, {"name": "io_write_time", "value": 1126456}, {"name": "io_read_time", "value": 24116}], "extraOptions": ["buildbot-m1.medium"], "name": "xpcshell.xpcshell.overall"}, {"subtests": [{"name": "time", "value": 27.827461004257202}, {"name": "cpu_percent", "value": 100.0}], "name": "xpcshell.xpcshell.install"}, {"subtests": [{"name": "time", "value": 0.18009400367736816}], "name": "xpcshell.xpcshell.stage-files"}, {"subtests": [{"name": "time", "value": 5985.320573091507}, {"name": "cpu_percent", "value": 98.75778558287334}], "name": "xpcshell.xpcshell.run-tests"}]}
06:04:21 INFO - Total resource usage - Wall time: 6013s; CPU: 99.0%; Read bytes: 89149440; Write bytes: 7903588352; Read time: 24116; Write time: 1126456
06:04:21 INFO - TinderboxPrint: CPU usage 98.8%
06:04:21 INFO - TinderboxPrint: I/O read bytes / time 89,149,440 / 24,116
06:04:21 INFO - TinderboxPrint: I/O write bytes / time 7,903,588,352 / 1,126,456
06:04:21 INFO - TinderboxPrint: CPU idle 73.8 (1.2%)
06:04:21 INFO - TinderboxPrint: CPU system 2,572.8 (42.8%)
06:04:21 INFO - TinderboxPrint: CPU user 3,357.6 (55.8%)
06:04:21 INFO - TinderboxPrint: Swap in / out 0 / 0
06:04:21 INFO - install - Wall time: 28s; CPU: 100.0%; Read bytes: 4096; Write bytes: 105345024; Read time: 8; Write time: 87980
06:04:21 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
06:04:21 INFO - run-tests - Wall time: 5985s; CPU: 99.0%; Read bytes: 89145344; Write bytes: 7767334912; Read time: 24108; Write time: 1006604
06:04:23 INFO - Running post-run listener: _upload_blobber_files
06:04:23 INFO - Blob upload gear active.
06:04:23 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir.
06:04:23 INFO - Files from /builds/slave/test/build/blobber_upload_dir are to be uploaded with branch at the following location(s): https://blobupload.elasticbeanstalk.com
06:04:23 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/test/oauth.txt', '-b', 'comm-central', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json']
06:04:23 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/test/oauth.txt -b comm-central -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json
06:04:23 INFO - (blobuploader) - INFO - Open directory for files ...
06:04:23 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/xpcshell_raw.log ...
06:04:24 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
06:04:24 INFO - (blobuploader) - INFO - Uploading, attempt #1.
06:04:25 INFO - (blobuploader) - INFO - TinderboxPrint: xpcshell_raw.log: uploaded
06:04:25 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded!
06:04:25 INFO - (blobuploader) - INFO - Done attempting.
06:04:25 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ...
06:04:25 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
06:04:25 INFO - (blobuploader) - INFO - Uploading, attempt #1.
06:04:31 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded
06:04:31 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded!
06:04:31 INFO - (blobuploader) - INFO - Done attempting.
06:04:31 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/xpcshell_errorsummary.log ...
06:04:31 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
06:04:31 INFO - (blobuploader) - INFO - Uploading, attempt #1.
06:04:32 INFO - (blobuploader) - INFO - TinderboxPrint: xpcshell_errorsummary.log: uploaded
06:04:32 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded!
06:04:32 INFO - (blobuploader) - INFO - Done attempting.
06:04:32 INFO - (blobuploader) - INFO - Iteration through files over.
06:04:32 INFO - Return code: 0
06:04:32 INFO - rmtree: /builds/slave/test/build/uploaded_files.json
06:04:32 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1
06:04:32 INFO - Setting buildbot property blobber_files to {"xpcshell_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/370f51e714d3ddc85cfc78881ef49493b16560a271d473add9786020ace640ec4117800bdd4254e81a79270b66328d439aeb2cc88d8f703cb37449fbc839ac7b", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/927f3b0d096b8ac967d84da766e998964dc37c205f195b8fc91d77ea17bd9c230563f779b67428a8407fe07539d182cab01c5a004125321e4cf921a56cead5f6", "xpcshell_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/2aef6f1ea96e5dc3c64502a0a01722d849c75fcd8ca09e6ca20a0ca01873c987148e685a60e334b2ad924dead482d9ac2f4fe2c3cd3188f93798c44e4493b59d"}
06:04:32 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files
06:04:32 INFO - Writing to file /builds/slave/test/properties/blobber_files
06:04:32 INFO - Contents:
06:04:32 INFO - blobber_files:{"xpcshell_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/370f51e714d3ddc85cfc78881ef49493b16560a271d473add9786020ace640ec4117800bdd4254e81a79270b66328d439aeb2cc88d8f703cb37449fbc839ac7b", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/927f3b0d096b8ac967d84da766e998964dc37c205f195b8fc91d77ea17bd9c230563f779b67428a8407fe07539d182cab01c5a004125321e4cf921a56cead5f6", "xpcshell_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/2aef6f1ea96e5dc3c64502a0a01722d849c75fcd8ca09e6ca20a0ca01873c987148e685a60e334b2ad924dead482d9ac2f4fe2c3cd3188f93798c44e4493b59d"}
06:04:32 INFO - Running post-run listener: copy_logs_to_upload_dir
06:04:32 INFO - Copying logs to upload dir...
06:04:32 INFO - mkdir: /builds/slave/test/build/upload/logs
06:04:32 INFO - Copying logs to upload dir...
06:04:32 WARNING - returning nonzero exit status 2
program finished with exit code 2
elapsedTime=6119.163841
========= master_lag: 0.16 =========
========= Finished '/tools/buildbot/bin/python scripts/scripts/desktop_unittest.py ...' failed (results: 2, elapsed: 1 hrs, 41 mins, 59 secs) (at 2017-03-14 06:04:33.064471) =========
========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-03-14 06:04:33.068131) =========
bash -c 'for file in `ls -1`; do cat $file; done'
in dir /builds/slave/test/properties (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done']
environment:
HOME=/home/cltbld
LANG=en_US.UTF-8
LOGNAME=cltbld
MAIL=/var/mail/cltbld
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test/properties
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=5a152710dd62cc268aad214e000002d8-1489490167.206586-732217359
_=/tools/buildbot/bin/python
using PTY: False
blobber_files:{"xpcshell_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/370f51e714d3ddc85cfc78881ef49493b16560a271d473add9786020ace640ec4117800bdd4254e81a79270b66328d439aeb2cc88d8f703cb37449fbc839ac7b", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/927f3b0d096b8ac967d84da766e998964dc37c205f195b8fc91d77ea17bd9c230563f779b67428a8407fe07539d182cab01c5a004125321e4cf921a56cead5f6", "xpcshell_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/2aef6f1ea96e5dc3c64502a0a01722d849c75fcd8ca09e6ca20a0ca01873c987148e685a60e334b2ad924dead482d9ac2f4fe2c3cd3188f93798c44e4493b59d"}
build_url:https://archive.mozilla.org/pub/thunderbird/tinderbox-builds/comm-central-linux/1489485733/thunderbird-55.0a1.en-US.linux-i686.tar.bz2
program finished with exit code 0
elapsedTime=0.032993
build_url: 'https://archive.mozilla.org/pub/thunderbird/tinderbox-builds/comm-central-linux/1489485733/thunderbird-55.0a1.en-US.linux-i686.tar.bz2'
blobber_files: '{"xpcshell_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/370f51e714d3ddc85cfc78881ef49493b16560a271d473add9786020ace640ec4117800bdd4254e81a79270b66328d439aeb2cc88d8f703cb37449fbc839ac7b", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/927f3b0d096b8ac967d84da766e998964dc37c205f195b8fc91d77ea17bd9c230563f779b67428a8407fe07539d182cab01c5a004125321e4cf921a56cead5f6", "xpcshell_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/comm-central/sha512/2aef6f1ea96e5dc3c64502a0a01722d849c75fcd8ca09e6ca20a0ca01873c987148e685a60e334b2ad924dead482d9ac2f4fe2c3cd3188f93798c44e4493b59d"}'
========= master_lag: 0.04 =========
========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-03-14 06:04:33.145360) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-03-14 06:04:33.145690) =========
rm -f oauth.txt
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-f', 'oauth.txt']
environment:
HOME=/home/cltbld
LANG=en_US.UTF-8
LOGNAME=cltbld
MAIL=/var/mail/cltbld
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=5a152710dd62cc268aad214e000002d8-1489490167.206586-732217359
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.016747
========= master_lag: 0.08 =========
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-03-14 06:04:33.243733) =========
========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-03-14 06:04:33.244041) =========
========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-03-14 06:04:33.244282) =========
========= Total master_lag: 0.35 =========
|