1464743 - Addons randomly stops working

Status: RESOLVED DUPLICATE of bug 1464938

(WebExtensions :: Untriaged, defect)

Description

[nanaya]

Attachment: firefox-addons-ublock-debug.png

User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0
Build ID: 20180516032328

Steps to reproduce:

1. browses for a while (measured in days, sometimes connected through remote desktop)



Actual results:

addons randomly disabled (most notably tampermonkey and ublock origin).

Trying to debug the extension from about:debugging results in this in browser console in addition to screenshot attached:
Error: Extension not found: [e-mail]
Stack trace:
getExtensionProcessBrowser@resource://gre/modules/ExtensionParent.jsm:1124:13
connect@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/webextension-parent.js:162:27
connect@resource://devtools/shared/base-loader.js -> resource://devtools/server/actors/webextension-parent.js:90:30
handler@resource://devtools/shared/base-loader.js -> resource://devtools/shared/protocol.js:1106:19
onPacket@resource://devtools/shared/base-loader.js -> resource://devtools/server/main.js:1769:15
_onJSONObjectReady/<@resource://devtools/shared/base-loader.js -> resource://devtools/shared/transport/transport.js:482:11
exports.makeInfallible/<@resource://devtools/shared/base-loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:14
exports.makeInfallible/<@resource://devtools/shared/base-loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:14



Trying to open options page from addons page results in this in browser console in addition to screenshot attached:
NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIWebNavigation.loadURIWithOptions]


Expected results:

working addons

Comment 1

[nanaya]

Attachment: firefox-addons-ublock-options.png

Comment 2

[nanaya]

For reference, disabling and then enabling the addon doesn't do anything. From what I can tell it will only work again after restarting the browser.

Comment 4

[Andrew Swan [:aswan]]

Could you be a little more specific about the symptoms you see?  From your screenshot, the ublock origin browser action is still present, but you cannot connect to it with the addon debugger and the options page does not load.  Can you open the ublock origin popup?  Is it blocking the content loads it is supposed to block?

Needless to say, I don't think we'll be able to reproduce this locally.  Can you attach the contents of the browser console from a session where this happened?  As well as a copy of about:support.

Comment 5

[nanaya]

(In reply to Andrew Swan [:aswan] from comment #4)
> Could you be a little more specific about the symptoms you see?  From your
> screenshot, the ublock origin browser action is still present, but you
> cannot connect to it with the addon debugger and the options page does not
> load.  Can you open the ublock origin popup?  Is it blocking the content
> loads it is supposed to block?
> 

- toolbar icon is gone
- context menu entry is gone
- nothing is blocked (or in case of violentmonkey*, scripts don't run)

> Needless to say, I don't think we'll be able to reproduce this locally.  Can
> you attach the contents of the browser console from a session where this
> happened?  As well as a copy of about:support.

Attached about:support. I'll record full browser console next time this happens.
I'll also keep the browser running when it happens in case you need me to check anything in it.


*I wrote tampermonkey before but it's actually violentmonkey.

Comment 6

[nanaya]

Attachment: about-support.txt

Comment 7

[Kris Maglione [:kmag]]

Attachment: Bug 1464743: Restore extension child shutdown timeout.

Review commit: https://reviewboard.mozilla.org/r/249766/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/249766/

Comment 8

[Kris Maglione [:kmag]]

Comment on attachment 8983917 [details]
Bug 1464743: Restore extension child shutdown timeout.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/249766/diff/1-2/

Comment 9

[Andrew Swan [:aswan]]

Comment on attachment 8983917 [details]
Bug 1464743: Restore extension child shutdown timeout.

https://reviewboard.mozilla.org/r/249766/#review256326

Comment 10

[Kris Maglione [:kmag]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/705c8b40f4c1c51bd4f9c46a5d854ec439454ff2
Bug 1464743: Restore extension child shutdown timeout. r=aswan

Comment 11

[Andrei Ciure[:aciure]]

https://hg.mozilla.org/mozilla-central/rev/705c8b40f4c1

Comment 13

[Ryan VanderMeulen [:RyanVM]]

Given the dupes we've already seen, it sounds like this is something we should consider backporting?

Comment 14

[Kris Maglione [:kmag]]

Hm. No, older versions weren't affected by the problem I fixed. If it's happening there, too, it's probably because we're never finishing extension *startup* because of a frozen content process, which would probably affect shutdown as a side-effect.

Comment 15

[Ryan VanderMeulen [:RyanVM]]

I'm confused because this bug was filed against Fx60 in the first place. Why are we fixing a Nightly-only problem here then?

Comment 16

[Marcia Knous [:marcia]]

During nightly crash triage I noticed there are still crashes in signatures like this in Build ID20180609220554 - one example is https://bit.ly/2LGXZ83. Should we reopen this bug?

Comment 17

[Ryan VanderMeulen [:RyanVM]]

Too late to do anything for 61 at this point. Would be nice if we could clarify the status of this bug, though (per the recent comments).

Comment 18

[nanaya]

Happened again to me few days ago. I think it was on 61?

Comment 19

[David Durst [:ddurst]]

I don't think anyone's looking to do anything with this bug because of that confusion cited in #c15.

Because it was filed against 60 and has reports of 61, I'd say that we should re-open it.

But since Kris fixed the issue from 62 on, if you say 61 has sailed and is wontfix, though, then this stays closed.

Comment 20

[Ryan VanderMeulen [:RyanVM]]

Still seeing a heck of a lot of reports in current builds:
https://crash-stats.mozilla.com/signature/?product=Firefox&release_channel=nightly&platform=Windows&signature=AsyncShutdownTimeout%20%7C%20profile-change-teardown%20%7C%20Extension%20shutdown%3A%20%40testpilot-addon&date=%3E%3D2018-06-20T10%3A27%3A54.000Z&date=%3C2018-07-20T10%3A27%3A54.000Z&_columns=date&_columns=product&_columns=version&_columns=build_id&_columns=platform&_columns=reason&_columns=address&_columns=install_time&_sort=-date&page=1

Comment 21

[David Durst [:ddurst]]

Why is this a dupe of 1467653? Given that that's crashing and this is not, and with the scant info in that bug, we're asserting that that signature is also still this bug (and so, Kris' patch is not a fix). So before we dig into this, I'd like to understand what's going on.

Comment 22

[David Durst [:ddurst]]

Nevermind. Kris educated me.

Comment 23

[nanaya]

I'm getting the problem again now. This time it's rikaichamp ( https://addons.mozilla.org/en-US/firefox/addon/rikaichamp/ ).

More or less same problems as I described in opening except this one I can open options page except it's missing all the options it should have. Only the basic addon info (description, screenshot, rating, etc), automatic updates toggle, and disable and remove buttons. All of the addon specific options are missing.

Debugging the addon through about:debugging only shows window with textbox containing this:

Connecting to localhost:60296, ws: false
Start protocol client for connection
Get root form for toolbox
Create toolbox target: {
  "0": {
    "form": {
      "actor": "server3.conn0.webExtensionAddon16",
      "id": "{59812185-ea92-4cca-8ab7-cfcacee81281}",
      "name": "Rikaichamp",
      "url": "https://addons.cdn.mozilla.net/user-media/addons/865744/rikaichamp-0.0.19-an+fx-windows.xpi?filehash=sha256%3Aa7ec53e9b9a763357a6e00cabf7bdc300b0abeb58a87de56fd74141423b2380b",
      "iconURL": "jar:file:///C:/Users/Edho/AppData/Roaming/Mozilla/Firefox/Profiles/0qfnnze0.default/extensions/%7B59812185-ea92-4cca-8ab7-cfcacee81281%7D.xpi!/images/rikaichamp-blue.svg",
      "debuggable": true,
      "temporarilyInstalled": false,
      "type": "extension",
      "isWebExtension": true,
      "manifestURL": "moz-extension://0537e7d9-5c5b-4077-a0b8-12bd3a844307/manifest.json",
      "warnings": []
    },
    "chrome": true,
    "isTabActor": true
  }
}
[object Object]



Browser console says this:
 [Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist.
background.js:55
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
<anonymous>
moz-extension://a4a2acc2-dbb2-465b-b88e-b604407c3361/assets/javascripts/chrome/background.js:55:3
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist.
background.js:55
<anonymous>
moz-extension://a4a2acc2-dbb2-465b-b88e-b604407c3361/assets/javascripts/chrome/background.js:55:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
[SW] on message <unavailable>
js/lib/push_worker.js:85:3

Version:
Name: Firefox
Version: 61.0.1
Build ID: 20180704003137
Update Channel: release
User Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:61.0) Gecko/20100101 Firefox/61.0
OS: Windows_NT 6.3
Multiprocess Windows: 5/5 (Enabled by default)
Web Content Processes: 5/4
Enterprise Policies: Inactive
Google Key: Found
Mozilla Location Service Key: Found
Safe Mode: false


Just tell me if there's anything else I can do to help. I'll have this rather-broken-state browser running for a while.

Comment 24

[nanaya]

So it looks like the errors in console are from clockwork ( https://addons.mozilla.org/en-US/firefox/addon/clockwork-dev-tools/ ). Disabling it doesn't help reviving rikaichamp though (even toggling disable/enable).

Around the time I disable clockwork, browser console looks like this:
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
[Show/hide message details.] Unchecked lastError value: Error: Could not establish connection. Receiving end does not exist. background.js:55
<anonymous>
moz-extension://a4a2acc2-dbb2-465b-b88e-b604407c3361/assets/javascripts/chrome/background.js:55:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
CustomizableUI: unable to normalize widget
CustomizableUI.jsm:2243
[Show/hide message details.] aId is undefined
CustomizableUI.jsm:1340
isSpecialWidget
resource:///modules/CustomizableUI.jsm:1340:5
getWidgetProvider
resource:///modules/CustomizableUI.jsm:947:9
wrapWidget
resource:///modules/CustomizableUI.jsm:565:20
createWidget
resource:///modules/CustomizableUI.jsm:3382:12
build
chrome://browser/content/parent/ext-browserAction.js:141:18
onManifestEntry
chrome://browser/content/parent/ext-browserAction.js:121:5
InterpretGeneratorResume self-hosted:1264:8 next self-hosted:1219:9
TypeError: this.chromeShell is null[Learn More]
ExtensionParent.jsm:1090:34
TypeError: aId is undefined[Learn More]
CustomizableUI.jsm:1340:5
TypeError: this.chromeShell is null[Learn More]
ExtensionParent.jsm:1090:34
NS_ERROR_ILLEGAL_VALUE: 
ExtensionChild.jsm:994
[Show/hide message details.] Promise rejected after context unloaded: Could not establish connection. Receiving end does not exist.
rikaichamp-content.js:1410
./src/content.ts
moz-extension://0537e7d9-5c5b-4077-a0b8-12bd3a844307/rikaichamp-content.js:1410:1
TypeError: aId is undefined[Learn More]
CustomizableUI.jsm:1340:5
[Show/hide message details.] Promise rejected after context unloaded: Could not establish connection. Receiving end does not exist.
rikaichamp-content.js:1410
./src/content.ts
moz-extension://0537e7d9-5c5b-4077-a0b8-12bd3a844307/rikaichamp-content.js:1410:1
TypeError: Argument 1 of PrecompiledScript.executeInGlobal is not an object.
ExtensionContent.jsm:489:18
NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIWebNavigation.loadURIWithOptions] browser-child.js:352
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[Show/hide message details.] aId is undefined CustomizableUI.jsm:1340
isSpecialWidget
resource:///modules/CustomizableUI.jsm:1340:5
getWidgetProvider
resource:///modules/CustomizableUI.jsm:947:9
wrapWidget
resource:///modules/CustomizableUI.jsm:565:20
createWidget
resource:///modules/CustomizableUI.jsm:3382:12
build
chrome://browser/content/parent/ext-browserAction.js:141:18
onManifestEntry
chrome://browser/content/parent/ext-browserAction.js:121:5
InterpretGeneratorResume self-hosted:1264:8 next self-hosted:1219:9
NS_ERROR_ILLEGAL_VALUE: ExtensionChild.jsm:994
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
Loading failed for the <script> with source “https://yads.c.yimg.jp/js/yads.js”. mystatus:97
Loading failed for the <script> with source “https://yads.c.yimg.jp/js/yads.js”. mystatus:3132
Loading failed for the <script> with source “https://yads.c.yimg.jp/js/yads.js”. mystatus:3186
Loading failed for the <script> with source “https://yads.c.yimg.jp/js/yads.js”. mystatus:3203
Loading failed for the <script> with source “https://s.yjtag.jp/tag.js#site=GBd7Bvs”. mystatus:1
[Show/hide message details.] No WebExtension found with ID {59812185-ea92-4cca-8ab7-cfcacee81281} ExtensionParent.jsm:854
createProxyContext
resource://gre/modules/ExtensionParent.jsm:854:13
receiveMessage
resource://gre/modules/ExtensionParent.jsm:822:11
[SW] on message <unavailable> js/lib/push_worker.js:85:3
TypeError: this.chromeShell is null[Learn More]
ExtensionParent.jsm:1090:34
[SW] on message <unavailable> js/lib/push_worker.js:85:3
Error: "Extension not found: {59812185-ea92-4cca-8ab7-cfcacee81281}"
getExtensionProcessBrowserresource://gre/modules/ExtensionParent.jsm:1272:13connectresource://devtools/server/actors/webextension-parent.js:162:27connectresource://devtools/server/actors/webextension-parent.js:90:30handlerresource://devtools/shared/protocol.js:1141:19onPacketresource://devtools/server/main.js:1761:15_onJSONObjectReadyresource://devtools/shared/transport/transport.js:472:11makeInfallibleresource://devtools/shared/ThreadSafeDevToolsUtils.js:109:14makeInfallibleresource://devtools/shared/ThreadSafeDevToolsUtils.js:109:14 protocol.js:1003:5
writeError
resource://devtools/shared/protocol.js:1003:5
handler/</<
resource://devtools/shared/protocol.js:1174:25
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
Content Security Policy: Ignoring ‘x-frame-options’ because of ‘frame-ancestors’ directive.
Loading failed for the <script> with source “https://cdn.optimizely.com/js/8585475915.js”. traced_errors:46
Loading failed for the <script> with source “https://rpm.newrelic.com/assets/optimizely.js?3a6076a”. traced_errors:291
[Show/hide message details.] ReferenceError: Experiment is not defined traced_errors:293:9
Loading failed for the <script> with source “https://js-agent.newrelic.com/nr-spa-1071.min.js”. traced_errors:1
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://api.segment.io/v1/i. (Reason: CORS request did not succeed).
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://api.segment.io/v1/g. (Reason: CORS request did not succeed).
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://api.segment.io/v1/p. (Reason: CORS request did not succeed).
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://api.segment.io/v1/t. (Reason: CORS request did not succeed).
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
TypeError: this.chromeShell is null[Learn More]
ExtensionParent.jsm:1090:34
[SW] on message <unavailable> js/lib/push_worker.js:85:3
TypeError: this.chromeShell is null[Learn More]
ExtensionParent.jsm:1090:34
Key event not available on some keyboard layouts: key=“i” modifiers=“accel,alt,shift” id=“key_browserToolbox” browser.xul
[Show/hide message details.] client is undefined clients.js:237
[SW] on message <unavailable> js/lib/push_worker.js:85:3
Content Security Policy: Directive ‘child-src’ has been deprecated. Please use directive ‘worker-src’ to control workers, or directive ‘frame-src’ to control frames respectively.
[SW] on message <unavailable> js/lib/push_worker.js:85:3
Content Security Policy: Directive ‘child-src’ has been deprecated. Please use directive ‘worker-src’ to control workers, or directive ‘frame-src’ to control frames respectively.
Content Security Policy: The page’s settings blocked the loading of a resource at self (“style-src”). Source: height:0. clockwork-dev-tools
Content Security Policy: The page’s settings blocked the loading of a resource at self (“style-src”). clockwork-dev-tools
Content Security Policy: The page’s settings blocked the loading of a resource at self (“style-src”).
clockwork-dev-tools:1
Content Security Policy: The page’s settings blocked the loading of a resource at self (“style-src”). clockwork-dev-tools
[SW] on message <unavailable> js/lib/push_worker.js:85:3
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://api.segment.io/v1/m. (Reason: CORS request did not succeed).
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[SW] on message <unavailable> js/lib/push_worker.js:85:3
[SW] on message <unavailable>
js/lib/push_worker.js:85:3
[SW] on message <unavailable>
js/lib/push_worker.js:85:3

Comment 25

[Ryan VanderMeulen [:RyanVM]]

Per IRC discussion with ddurst, reopening this bug to track remaining issues with frozen content processes leading to WebExtension bustage.

Comment 26

[David Durst [:ddurst]]

Nanaya -- this was filed on 60 release. a) what version and channel are c23 and c24 from? b) (if relevant) is this reproducible with those extensions on Nightly 63?

Comment 27

[nanaya]

(In reply to David Durst [:ddurst] (REO for 63) from comment #26)
> Nanaya -- this was filed on 60 release. a) what version and channel are c23
> and c24 from? b) (if relevant) is this reproducible with those extensions on
> Nightly 63?

a) 61.0.1/release
b) no idea, I don't use nightly. Slightly more difficult to run it together with release and different privacy policy on it don't really make me want to install it