Closed Bug 650965 Opened 13 years ago Closed 13 years ago

permaorange: browser_addons.js | Addon element removed during uninstall

Categories

(Firefox for Android Graveyard :: General, defect)

defect
Not set
normal

Tracking

(Not tracked)

VERIFIED FIXED

People

(Reporter: philor, Assigned: wesj)

References

Details

Attachments

(6 files, 5 obsolete files)

Wasn't visible on Android until after bug 650578 let it get that far, but apparently has been happening all along on the hidden Maemo runs. During test 1, a restartless addon that's supposed to just get removed from the list instantly when it's uninstalled,

http://tinderbox.mozilla.org/showlog.cgi?log=Mobile/1303160034.1303160756.16951.gz#err0

TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/mobile/chrome/browser_addons.js | Addon element removed during uninstall
Attached patch Potential Fix (obsolete) — Splinter Review
I'm not sure what the issue could be. Either list.removeChild(elt) is not blocking, or we are finding the item somewhere else in the list.

This just wraps in a setTimeout in case this is a race problem, but also adds some checks for the addon property on the element, which should not be present if it is in the search section (also added some logging so I can know if that is happening).
Attachment #527803 - Flags: review?(mark.finkle)
Comment on attachment 527803 [details] [diff] [review]
Potential Fix

> +                      close_manager(run_next_test);
> +                    }, 0)

Add a semicolon

Looks safe enough to try.
Attachment #527803 - Flags: review?(mark.finkle) → review+
http://hg.mozilla.org/mozilla-central/rev/9b17b766116d
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Sadly, that had no effect on it.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attached patch Potential Fix 2 (obsolete) — Splinter Review
We can try this. I'm also bumping the default max time we will wait in WaitFor and WaitForAndContinue because I'm suspicious that is our problem. Not a good solution by any means.
Attachment #527803 - Attachment is obsolete: true
Attachment #528354 - Flags: review?
Comment on attachment 528354 [details] [diff] [review]
Potential Fix 2


>                     ExtensionsView.uninstall(elt);
>                     setTimeout(function() {
>                       elt = get_addon_element(aAddon.id);
>-                      ok(!elt || !elt.addon, "Addon element removed during uninstall");
>-                      if (elt && !elt.addon)
>-                        info("Element is still visible in search area");
>-                      Browser.closeTab(gCurrentTab);
>-                      close_manager(run_next_test);
>+                      waitForAndContinue(function() {
>+                        ok(!elt, "Addon element removed during uninstall");
>+                        Browser.closeTab(gCurrentTab);
>+                        close_manager(run_next_test);
>+                      }, function() { return !elt; });
>                     }, 0);

I think you can remove the setTimeout now

r+ with that change
Attachment #528354 - Flags: review? → review+
Attached patch Fix v2 for checkin (obsolete) — Splinter Review
Whoops. Found another problem in this as well. We need to make sure we're querying for a new element each time in the waitFor test and callback.
Attachment #528354 - Attachment is obsolete: true
Attachment #528370 - Flags: review+
Pushed: http://hg.mozilla.org/mozilla-central/rev/19555867d9eb

I'll hold off on marking this again until we see results.
Perhaps the extension logging can enlighten us a little.
Attachment #528947 - Flags: review?(mbrubeck) → review+
Comment on attachment 528984 [details] [diff] [review]
Permaorange, logging for Fennec's extension manager

Just to make sure its said, AddonLogging.jsm is already being pulled in by the ExtensionManager. But we should probably back this stuff out when done.
Attachment #528984 - Flags: review?(wjohnston) → review+
Why not keep it? It won't be spammy by default and it could help us debug future issues.
(In reply to comment #15)
> Why not keep it? It won't be spammy by default and it could help us debug
> future issues.

I'd rather back it out too.
Attached patch Another attempt (obsolete) — Splinter Review
Talked briefly to mfinkle about using "DOMNodeRemoved" events on IRC. This does that, but also has to include another setTimeout. The element is removed in the uninstall function, which in this case then calls our eventListener, who starts the next test before the uninstall function can finish, leading to a weird state. I'm not a fan of adding even more timeouts here, but we can try it...
Attachment #528370 - Attachment is obsolete: true
Whoops. Left some crud in there.
Attachment #529017 - Attachment is obsolete: true
Comment on attachment 529018 [details] [diff] [review]
Another attempt v2

This idea makes no sense to me. The node is removed synchronously in the uninstall function, and the logs have verified the correct branch is running. I think we want more logging (attached just a few seconds ago). Could it be that another node with this ID is somehow in the document? Perhaps it was added twice somehow?

If we do want to make sure the node is removed, I think DOMNodeRemoved is run synchronously, so the code in the event listener would run before anything after ExtensionsView.uninstall. This means you could just set a flag in the event listener and make sure it is set after the uninstall call.
Attachment #529018 - Flags: review-
Comment on attachment 529019 [details] [diff] [review]
Permaorange, log waitForAndContinue and more sanity checks

># HG changeset patch
># User Benjamin Stover <bstover@mozilla.com>
># Date 1304042685 25200
># Node ID 01060ee94522b884b400403282eb302e42313b95
># Parent  e6cca204fccc04451ff5f2b95de02a62b2783688
>Bug 650965 Permaorange, log waitForAndContinue and more sanity checks
>
>diff --git a/mobile/chrome/tests/browser_addons.js b/mobile/chrome/tests/browser_addons.js
>--- a/mobile/chrome/tests/browser_addons.js
>+++ b/mobile/chrome/tests/browser_addons.js
>@@ -357,39 +357,43 @@ function testPrompt(aTitle, aMessage, aB
>   }
> }
> 
> // Installs an addon via the urlbar.
> function installFromURLBar(aAddon) {
>   return function() {
>     loadUrl(gTestURL, function() {
>       loadUrl(aAddon.sourceURL, null, false);
>+      let elt = get_addon_element(aAddon.id);
>+      ok(!elt, "Addon element is not present before installation");
>       checkInstallAlert(true, function() {
>         checkDownloadNotification(function() {
>           checkInstallPopup(aAddon.name, function() {
>             checkInstallNotification(!aAddon.bootstrapped, function() {
>               open_manager(true, function() {
>                 isRestartShown(!aAddon.bootstrapped, false, function() {
>                   let elt = get_addon_element(aAddon.id);
>+                  info("elt.id is " + aAddon.id);
>                   if (aAddon.bootstrapped) {
>                     checkAddonListing(aAddon, elt, "local");
>                     var button = document.getAnonymousElementByAttribute(elt, "anonid", "uninstall-button");
>                     ok(!!button, "Extension has uninstall button");
> 
>                     var updateButton = document.getElementById("addons-update-all");
>                     is(updateButton.disabled, false, "Update button is enabled");
> 
>                     ExtensionsView.uninstall(elt);
>                     waitForAndContinue(function() {
>                       let elt = get_addon_element(aAddon.id);

let's add something to tell use where this element is located, if it exists:

  if (elt)
    info("unexpectedly found element in: " + elt.parentNode.id);

>                       ok(!elt, "Addon element removed during uninstall");
>                       Browser.closeTab(gCurrentTab);
>                       close_manager(run_next_test);
>                     }, function() {
>                       let elt = get_addon_element(aAddon.id);
>+                      info("Looking for element with id " + aAddon.id + ": " + elt);
>                       return !elt;
>                     });
>                   } else {
>                     ok(!elt, "Extension not in list");
>                     AddonManager.getAllInstalls(function(aInstalls) {
>                       for(var i = 0; i < aInstalls.length; i++) {
>                         aInstalls[i].cancel();
>                       }
Attachment #529019 - Flags: review?(wjohnston) → review+
Comment on attachment 529018 [details] [diff] [review]
Another attempt v2

I am not against using DOMNodeRemoved, but I agree with Ben about using the event handler to set a flag if the element with the right ID is removed. Then check the flag in the "continue" section
http://tinderbox.mozilla.org/showlog.cgi?log=Mobile/1304047695.1304048666.29400.gz&fulltext=1#err0

My new theory is that this element is somehow getting added twice. Next step is probably logging when the addon is added to the DOM and see if the message occurs twice, and what the parent of the element is in waitForAndContinue.
Attached patch Logg adding addons (obsolete) — Splinter Review
More logging. Maybe we can watch when things are added to the list, and see if this is being added twice? I only see one place where we add items to the list.
Attachment #529561 - Flags: review?(ben)
This one should contain actual code.
Attachment #529561 - Attachment is obsolete: true
Attachment #529561 - Flags: review?(ben)
Attachment #529566 - Flags: review+
OK. So we are apparently adding this addon twice, and now I can reproduce! When we add the addon to the list, we watch for the install alert to be shown, but in my amazing smartness, I decided that on Android, where we can't see alerts, we should just skip ahead.

So on device we are showing the addon manager before the install finishes. We still shouldn't add the item if it has been added before:

http://mxr.mozilla.org/mobile-browser/source/chrome/content/extensions.js#922

but I suspect since we lazy load the addon manager (with a couple setTimeout 0's thrown in for good measure) the addon install finishes after we have the started creating the list, but before we have finished. Since there are no checks while we are making the list to make sure the addon doesn't already exist:

http://mxr.mozilla.org/mobile-browser/source/chrome/content/extensions.js#323

we happily add it twice.
Attached patch PatchSplinter Review
OK. Lets try this. This implements two fixes:

1.) It checks in the AddonManager.getAddonsByTypes callback to make sure that any addons we are adding are not already in the list. If they are, it moves them to whatever position it was moving addons to. We could also fix this in addItem, but I'd like to catch any more mistakes I've made here.

2.) It fixes the test to use an AddonInstall listener to trigger opening the addons manager.

Also removed all the logging. This fixes things in my local tests. Need to write a separate test for this particular problem.
Attachment #529761 - Flags: review?(mark.finkle)
Comment on attachment 529761 [details] [diff] [review]
Patch


>       // the search-engine-modified observer in browser.js will take care of
>       // updating the list
>     } else {
>-      AddonLogger.log("Removing extension.");
> 
>       if (!aItem.addon) {

don't leave a blank line at the top of the block

r+ (fingers crossed)
Attachment #529761 - Flags: review?(mark.finkle) → review+
Filed Bug 654555 for the race condition test I need to write. Resolving this fixed.
Status: REOPENED → RESOLVED
Closed: 13 years ago13 years ago
Resolution: --- → FIXED
Can this be marked as verified fixed?
bugspam
Assignee: nobody → wjohnston
Marking this as verified fixed based on Thinderboxpuslog.
Status: RESOLVED → VERIFIED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: