795746 - clearTimeout fails to clear timeout in SDK 1.11b2

Status: RESOLVED FIXED

(Add-on SDK Graveyard :: General, defect, P1)

Description

[John Nagle]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:15.0) Gecko/20100101 Firefox/15.0
Build ID: 20120724191344

Steps to reproduce:

Tested a previously working FireFox add-on with SDK 1.12dev. Testing is with "cfx run" on Windows 7 with Firefox 15.0. The add-on has a page mod which raises balloons on mouse-over, and uses timeouts to keep the balloon up for a while after mouse-over ends.  Mousing over the balloon itself cancels the timeout. 


Actual results:

With SDK 1.12dev, the call to cancelTimeout from a mouseover event doesn't seem to cancel the timeout.  Works with SDK 1.9 and SDK 1.10 with identical Firefox and add-on code. 

(Not sure if there is an SDK 1.11; the download link on this page (https://blog.mozilla.org/addons/2012/09/19/link-addon-sdk-1-11-the-page-mod-release/) downloads SDK 1.12dev instead of 1.11.)


Expected results:

The cancelTimeout should have worked as it did with previous SDKs.

I don't have a conveniently sized test case for this, but can easily test with other SDK versions. Provide me with links to SDK versions to test and I'll try to narrow down the version level at which this broke.

Comment 1

[John Nagle]

Further testing, using builds from
"https://ftp.mozilla.org/pub/mozilla.org/labs/jetpack/":

OK with SDK 1.10.
Seems to be broken in SDK 1.11b1. 

So that brackets it between two successive builds of 2012-09-12 and 2012-09-26. 

What changed between those two that could affect "cancelTimeout()"?  
(Remember, this is an SDK related bug, so interaction with wrappers is always a possiblity.)

Comment 2

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

Here's the changelog for those two builds: https://github.com/mozilla/addon-sdk/compare/1.10...1.11b1

Comment 3

[John Nagle]

I looked at the change log, but there's nothing directly related.  However, the wrapper logic for content scripts has been revised again, and this is a content script issue.  So it may be a wrapper-related problem.  Any ideas on what to look at?

Unfortunately, clearTimeout(id) does not raise an error if "id" is invalid.  There seems to be no way to validate a timer ID (which is a number, not an object).  So there's no way to tell if a clearTimeout(id) worked.   

My own logging shows this sequence of events (comments in parens):
SDK 1.10: (works correctly)
info: Mouseout event  (cursor moved from item that triggered balloon to balloon)
info: Mouseover on balloon (cursor enters balloon)
info: Hide timeout cancelled (so timeout is cancelled and balloon stays active)
info: Mouseout event (later, cursor leaves balloon, balloon disappears)

SDK 1.11b1: (BUG)
info: adlimiter: Mouseout event (cursor moved from item that triggered balloon to balloon)
info: adlimiter: Mouseover on balloon (cursor enters balloon)
info: adlimiter: Hide timeout cancelled (so timeout is cancelled and balloon stays active)
info: adlimiter: Hide timeout fired (Cancelled timeout fires! BUG. Balloon disappears while cursor is still on it.)
info: adlimiter: Hide timeout fired after cancel! (Additional message - timeout fired but a flag had been set indicating it had been cancelled.)

So it seems reasonably clear that in SDK 1.11b1 (and 1.12dev) the timeout callback (which is a closure, incidentally) did fire after the timeout was supposedly cancelled.

Comment 4

[John Nagle]

Note: "cancelTimeout" above should be "clearTimeout".

Comment 5

[John Nagle]

Attachment: Workaround for clearTimeout defect

This is a file which can be used to work around the clearTimeout bug.  It defines
setTimeoutDefectWorkaround and clearTimeoutDefectWorkaround, which can be used in place of the standard functions.  This allows use of defective versions of the SDK until the problem is dealt with. 

This file has debug messages which indicate when a clearTimeout did not work.

Comment 6

[John Nagle]

Further testing indicates that, at least for this addon code, and 1.11b1 through at least 1.12dev, clearTimeout never clears the timeout.  Some logging of the relevant events:

info: adlimiter: Timer ID 52 fired.  Cancelled: false
info: adlimiter: Timer ID 54 fired.  Cancelled: false
info: adlimiter: Timer ID 89 created.
info: adlimiter: Timer ID 92 created.
info: adlimiter: Timer ID 89 fired.  Cancelled: false
info: adlimiter: Timer ID 92 fired.  Cancelled: false
info: adlimiter: Timer ID 96 created.
info: adlimiter: Timer ID 96 cancelled.
info: adlimiter: Timer ID 99 created.
info: adlimiter: Timer ID 99 cancelled.
info: adlimiter: Timer ID 96 fired.  Cancelled: true
error: adlimiter: Mozilla defect #795746 - timeout callback occured after timer cancelled.
info: adlimiter: Timer ID 99 fired.  Cancelled: true
error: adlimiter: Mozilla defect #795746 - timeout callback occured after timer cancelled.
info: adlimiter: Timer ID 108 created.
info: adlimiter: Timer ID 108 cancelled.
info: adlimiter: Timer ID 111 created.
info: adlimiter: Timer ID 108 fired.  Cancelled: true
error: adlimiter: Mozilla defect #795746 - timeout callback occured after timer cancelled.
info: adlimiter: Timer ID 111 fired.  Cancelled: false 

For all cases where a cancel occurred before the timer fired, the timer still fired. It's not intermittent.  This doesn't appear to be intermittent or timer dependent; it looks like cancelTimeout was just simply broken for add-on content scrips.  I'd suggest looking for changes to the wrapper system.  That's usually the cause of "works on pages, doesn't work in content scripts" problems.

Comment 7

[Marc Chevrier]

Same problem exists for clearInterval.

Comment 8

[John Nagle]

Do you have a simple test case?  Then we could get this out of UNCONFIRMED state.

Comment 9

[Marc Chevrier]

Attachment: simple add-on showing clearInterval bug

Comment 10

[Marc Chevrier]

Comment on attachment 672309 [details]
simple add-on showing clearInterval bug

This simple add-on shows clearly the problem of clearInterval.
After installing the add-on (xpi included in the tar file was built with add-on SDK 1.11b2), open the error console and after open a hmtl page in a tab (any html page is OK).
In normal condition, only ONE message 'Action executed' must be displayed in the console. But, a *LOT* will be displayed with this add-on.

Same add-on built with add-on SDK 1.10 show only one message, as expected.

Comment 11

[Jeff Griffiths (:canuckistani) (:⚡︎)]

(In reply to John Nagle from comment #8)
> Do you have a simple test case?  Then we could get this out of UNCONFIRMED
> state.

John - this bug is P1 & assigned to Irakli. We don't really use Status in to differentiate between unconfirmed & new, but setting to new if it makes you feel better.

Comment 12

[Erik Vold [:erikvold] (please needinfo? me)]

I assume this is about clearTimeout.

Comment 13

[Irakli Gozalishvili [:irakli] [:gozala] [@gozala]]

Attachment: Pointer to Github pull request: https://github.com/mozilla/addon-sdk/pull/619

Pointer to Github pull-request

Comment 14

[Irakli Gozalishvili [:irakli] [:gozala] [@gozala]]

Attachment: Pointer to Github pull request: https://github.com/mozilla/addon-sdk/pull/619

Pointer to Github pull-request

Comment 15

[Irakli Gozalishvili [:irakli] [:gozala] [@gozala]]

Comment on attachment 672420 [details]
Pointer to Github pull request: https://github.com/mozilla/addon-sdk/pull/619

Creating a test case that reproduces this bug.

Comment 16

[Erik Vold [:erikvold] (please needinfo? me)]

Thanks for the report John!

Comment 17

[[github robot]]

Commit pushed to master at https://github.com/mozilla/addon-sdk

https://github.com/mozilla/addon-sdk/commit/5e3c301ae44a0eb182f22190831a9825c6eb6c34
Merge pull request #619 from Gozala/bug/clear-timeout@795746

Fix Bug 795746 - clearTimeout does not cancel timers in content scripts r=@erikvold

Comment 18

[[github robot]]

Commit pushed to stabilization at https://github.com/mozilla/addon-sdk

https://github.com/mozilla/addon-sdk/commit/ca0000c480c028ce54aa300e3f6a8afbf5dbd143
Merge pull request #619 from Gozala/bug/clear-timeout@795746

Fix Bug 795746 - clearTimeout does not cancel timers in content scripts r=@erikvold(cherry picked from commit 5e3c301ae44a0eb182f22190831a9825c6eb6c34)

Adjusted for stabilization's layout.