Last Comment Bug 325418 - Calling init function of NsiTimer after calling cancel will add new time to old time.
: Calling init function of NsiTimer after calling cancel will add new time to o...
Status: RESOLVED FIXED
[good first bug] [mentor=jdm]
:
Product: Core
Classification: Components
Component: XPCOM (show other bugs)
: Trunk
: x86 Windows XP
: -- normal (vote)
: mozilla10
Assigned To: Michael Kraft [:morac]
:
Mentors:
Depends on: 740769
Blocks:
  Show dependency treegraph
 
Reported: 2006-01-31 23:37 PST by Michael Kraft [:morac]
Modified: 2012-03-30 04:29 PDT (History)
3 users (show)
bzbarsky: in‑testsuite+
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Extension which demonstrates the problem (3.14 KB, application/octet-stream)
2006-01-31 23:40 PST, Michael Kraft [:morac]
no flags Details
Test page (3.55 KB, text/html)
2007-04-26 09:07 PDT, Michael Kraft [:morac]
no flags Details
Advanced Test page (4.67 KB, text/html)
2007-04-26 10:52 PDT, Michael Kraft [:morac]
no flags Details
Patch and test (7.25 KB, patch)
2011-09-04 09:01 PDT, Michael Kraft [:morac]
bzbarsky: review-
Details | Diff | Review
Possible simpler fix (696 bytes, patch)
2011-10-04 11:25 PDT, Jeff Muizelaar [:jrmuizel]
no flags Details | Diff | Review
Patch based on comment 21 plus test (2.41 KB, patch)
2011-11-02 13:33 PDT, Michael Kraft [:morac]
bzbarsky: review+
Details | Diff | Review

Description Michael Kraft [:morac] 2006-01-31 23:37:51 PST
User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8) Gecko/20051111 Firefox/1.5
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8) Gecko/20051111 Firefox/1.5

I was writing an extension that has a periodic and I wanted to have the option to change the interval at which it runs.

To do this I created a NsiTimer using the createInstance function and store the object as a global variable and used the init() function to start it with a type of TYPE_REPEATING_PRECISE.  When the user changes the interval at which the periodic should run, I issue a cancel on the timer and then another init with the new interval value.  The problem is that any future calls to init will have the interval passed in that call added to the original interval from the first time the init was called.

So for example if I start the timer originally with a periodic of 5 minutes and the user changes it to 1 minute, the timer will start running at 6 minutes.

I found a work around for this.  Basically after I issue the cancel I have to issue another createInstance call which will destroy the current timer and create a new one.  According to the documentation at http://www.xulplanet.com/references/xpcomref/ifaces/nsITimer.html this shouldn't be necessary since the cancel should clear out the timer.



Reproducible: Always

Steps to Reproduce:
1.  Create TYPE_REPEATING_PRECISE NsiTimer and initialize with an interval of X seconds.
2.  Cancel this timer and reinitialize with an interval of Y seconds.


Actual Results:  
Timer will now expire every X+Y seconds.

Expected Results:  
Timer should expire every Y seconds.

I wrote an extension which will create a timer of 5 seconds and then change it everytime it expires.  It logs the times it takes to expire and how long it should take in the javascript console.  It stops after 6 changes.

Notice that the new timer will always expire 5 seconds after it was set to because it adds in the original 5 seconds.  

To make it work correctly add the following line after the cancel in StartTimer():

    gtimer_test_function.timer = Components.classes["@mozilla.org/timer;1"].
         createInstance(Components.interfaces.nsITimer);
Comment 1 Michael Kraft [:morac] 2006-01-31 23:40:21 PST
Created attachment 210331 [details]
Extension which demonstrates the problem 

This Firefox 1.5 only extension will create a timer when the browser opens and change its interval every time it expires.  It logs the expected and actual times it takes to expire in the javascript console as well as logging if it took too long to expire.
Comment 2 Michael Kraft [:morac] 2007-04-26 09:07:24 PDT
Created attachment 262899 [details]
Test page

Same as the other attachment except I converted the extension into a web page.  It will require the signed.applets.codebase_principal_support to be set to true to run it from this web site and it also requires clicking the allow button multiple times, but it doesn't require installing an extension.
Comment 3 Michael Kraft [:morac] 2007-04-26 10:52:11 PDT
Created attachment 262913 [details]
Advanced Test page

The other test page had an errors in it.  In addition I've found that the test results with or without calling the cancel() function are the same.  I also added more tests consisting of both precise and slack repeating timers (canceling and not canceling).

It appears the when a timer initialization function is called for a TYPE_REPEATING_PRECISE timer, if there was an old time value it is added to the new time value and the result is used as the expiration time.  For TYPE_REPEATING_SLACK timers it just immediately expires.

This might have something to do with the precise timers:
http://lxr.mozilla.org/seamonkey/source/xpcom/threads/nsTimerImpl.cpp#293


For the test page, unless the "remember" option is selected, the popping up of the security alerts causes the timer count to be off (possibly because the timer is still counting in the background) so please allow and remember to complete this test.  A new profile can be created to test this is.
Comment 4 Doug Turner (:dougt) 2007-10-08 16:17:15 PDT
mass reassigning to nobody.
Comment 5 Josh Matthews [:jdm] 2010-06-13 07:54:31 PDT
From nsTimerImpl::SetDelayInternal:

>  PRIntervalTime now = PR_IntervalNow();
>  if (mTimeout == 0 || mType != TYPE_REPEATING_PRECISE)
>    mTimeout = now;
>
>  mTimeout += delayInterval;

Looks like there should probably be an else clause that sets mTimeout to 0.
Comment 6 Michael Kraft [:morac] 2010-06-13 09:10:35 PDT
(In reply to comment #5)
> Looks like there should probably be an else clause that sets mTimeout to 0.

I don't think mTimeout should be set to 0 since that is supposed to be set to the current time.  The delay is added to the current time so that the timer expires in the future.


I do see some discrepancies in the code though.  When nsTimerImpl:init is called for an existing TYPE_REPEATING_PRECISE timer, it calls nsTimerImpl::InitCommon which never updates mTimeout to the current time before calling nsTimerImpl::SetDelayInternal.

For a call to nsTimerImpl::setDelay, which also calls nsTimerImpl::SetDelayInternal, the code updates the mTimeout to the current time first:

>  if (mTimeout != 0 && mType == TYPE_REPEATING_PRECISE)
>     mTimeout = PR_IntervalNow();
> 
>  SetDelayInternal(aDelay);

The above causes mTimeout to always get set to the current time for all timers when nsTimerImpl::setDelay is called which would seem correct.


When re-initializing a pre-existing TYPE_REPEATING_PRECISE timer, the mTimeOut value is never set correctly, since there will already be an old mTimeOut value.

That makes me think the fix should be to set the mTimeOut value to 0 in nsTimerImpl::Cancel.  That way the timer will be correctly initialized the next time nsTimerImpl::InitCommon is called.



Also for whatever reason the Advanced Test attachment no longer works correctly in Firefox(timers aren't rescheduled most of the time).  The add-on test still works and fails in the nightly trunk loads.
Comment 7 Michael Kraft [:morac] 2011-09-03 12:17:30 PDT
This is still a problem over 5 years after I reported it.

Easy to reproduce.  Simply paste the following in the error console:

var time = (new Date()).getTime(); var obs = { notify:function(aTimer) { alert("done in " + ((new Date()).getTime() - time)/1000 + " seconds."); aTimer.cancel() }}; var timer = Components.classes["@mozilla.org/timer;1"].createInstance(Components.interfaces.nsITimer); timer.initWithCallback(obs, 5000, Components.interfaces.nsITimer.TYPE_REPEATING_PRECISE); timer.cancel(); timer.initWithCallback(obs, 8000, Components.interfaces.nsITimer.TYPE_REPEATING_PRECISE);


It starts a 5 second timer, cancels it and then starts an 8 second timer.  The timer expires in 13 seconds.

The fix is still as I posted in comment #6.
Comment 8 Josh Matthews [:jdm] 2011-09-03 15:00:53 PDT
From comment #6:

>That makes me think the fix should be to set the mTimeOut value to 0 in >nsTimerImpl::Cancel.  That way the timer will be correctly initialized the next time >nsTimerImpl::InitCommon is called.

Let's do this. Easy fix for an old bug for some enterprising contributor to take on.
Comment 9 Michael Kraft [:morac] 2011-09-03 16:07:31 PDT
(In reply to Josh Matthews [:jdm] from comment #8)
> Easy fix for an old bug for some enterprising contributor to take on.

Is that supposed to be a hint. :)

I could code it myself, though as my machine is dog slow, it would take a very long time to compile.  Also I've coded fixes in other areas (name SessionStore) so it wouldn't be a first bug for me.

On a side note, is there a "good way" to test timer expiration duration?  Precise timers aren't exactly precise.  They are usually close, plus or minus around 0.2, so the dirty way I thought of is to simply start a 5 second timer, cancel it and then start a 1 second timer.   If 0 < the expiration time < 2 it would be a pass.  Anything else would be a failure.  Currently it would expire in 6 seconds.
Comment 10 Josh Matthews [:jdm] 2011-09-03 16:12:37 PDT
Not a hint unless you want to take it as one. This simply seems like a good bug to add to the list of ones that I link new contributors to, as it's well-scoped and has a testcase and a description of how to solve it.
Comment 11 Michael Kraft [:morac] 2011-09-03 16:26:23 PDT
I just looked at the mozilla-central code and it's not as straightforward as it was under the old code.  The new code uses a TimeStamp class which doesn't have a way of setting the value back to 0.  That makes the new fix to create a new instance of the TimeClass and then assign it to mTimeOut.  C++ isn't my first language, but I'm pretty doing that would cause a memory leak.

The alternative might be to do something like this:
> mTimeout -= mTimeout

Looking at the code, that should theoretically 0 out the mTimeout value.  

The only other alternative would be to modify the TimeStamp class to allow assigning a value.

Of those, I think I'll try the "mTimeout -= mTimeout" one and see what happens.
Comment 12 Michael Kraft [:morac] 2011-09-03 19:15:59 PDT
Well I created a patch and test and tried to compile after pulling in the last changes from Mercury, but I ran into some kind of weird configuration error (error C2006: '#include' : expected a filename, found 'identifier').  From what I can tell I shouldn't have gotten that.

Since I hadn't compiled since last October, I wiped everything and tried cloning mozilla-central, but it failed to clone for some reason (got a "transaction abort!" for some reason).

Is there another way to get the patch build and tested?
Comment 13 Josh Matthews [:jdm] 2011-09-03 19:21:03 PDT
Tryserver is an option, but just sending patches to it to see if they build doesn't sound like the best use of resources.
Comment 14 Michael Kraft [:morac] 2011-09-03 19:24:33 PDT
Plus I don't have a Tryserver account, though I'm not worried about it failing to compile since I only added one line.

I did manage to grab the mozilla-central bundle so once that unpacks I'll try compiling again.  I'm still not sure why it failed, but I'm going to get rid of my .mozconfig file and try just a plain compile.  If that doesn't work, then I'm giving up and I'll just post the patch and hopefully someone else can try it.
Comment 15 Michael Kraft [:morac] 2011-09-04 09:01:06 PDT
Created attachment 558155 [details] [diff] [review]
Patch and test

Okay after wiping and recreating from scratch, Firefox compiled.  The patch turned out to not be quite as straightforward as what I posted, but it was still quite simple.

My test case above passes as does the test I wrote.
Comment 16 Josh Matthews [:jdm] 2011-09-13 07:42:10 PDT
Comment on attachment 558155 [details] [diff] [review]
Patch and test

I was hoping to be able to spend some time looking at this and give some feedback, but I don't know the code well enough and don't have the time. I think bz is the right person for this.
Comment 17 Jeff Muizelaar [:jrmuizel] 2011-09-21 23:09:27 PDT
Comment on attachment 558155 [details] [diff] [review]
Patch and test

I'd like to look at this too.
Comment 18 Jeff Muizelaar [:jrmuizel] 2011-10-04 11:25:28 PDT
Created attachment 564614 [details] [diff] [review]
Possible simpler fix

It seems like this would fix the issue as well.
Comment 19 Michael Kraft [:morac] 2011-10-04 14:01:48 PDT
(In reply to Jeff Muizelaar [:jrmuizel] from comment #18)
> Created attachment 564614 [details] [diff] [review] [diff] [details] [review]
> Possible simpler fix
> 
> It seems like this would fix the issue as well.

That would work and actually was my original idea when looking int to, but that would mean a new TimeStamp class is created every time a timer is canceled.  TimeStamp classes aren't that large, but it doesn't seem like a good idea to needlessly create and destroy the TimeStamp class.  Then again, with the new memory manager, it might not make a difference.
Comment 20 Boris Zbarsky [:bz] (Out June 25-July 6) 2011-10-12 12:16:04 PDT
Timestamps are cheap.  In particular, the default constructor is inline, so any sane optimizing compiler will optimize this:

  mTimeout = TimeStamp();

to this:

  mTimeout.mValue = 0;
Comment 21 Boris Zbarsky [:bz] (Out June 25-July 6) 2011-10-12 12:23:02 PDT
Comment on attachment 558155 [details] [diff] [review]
Patch and test

I'm very sorry for the long lag here... next iteration will be much faster!

I think the right way to solve this issue is for InitCommon to set mTimeout to nsTimeStamp().  It's already resetting various other state (mCanceled, mGeneration, etc), so this seems like it would fit well with that.
Comment 22 Michael Kraft [:morac] 2011-11-02 13:33:33 PDT
Created attachment 571436 [details] [diff] [review]
Patch based on comment 21 plus test

I finally found time to do this so here's a patch base on the comment 21 plus the test from the original patch.
Comment 23 Boris Zbarsky [:bz] (Out June 25-July 6) 2011-11-02 20:43:55 PDT
Comment on attachment 571436 [details] [diff] [review]
Patch based on comment 21 plus test

r=me.  Thanks!
Comment 24 Boris Zbarsky [:bz] (Out June 25-July 6) 2011-11-02 20:46:44 PDT
http://hg.mozilla.org/integration/mozilla-inbound/rev/fdb29823b1d4

Thank you for the patch!
Comment 25 Marco Bonardo [::mak] 2011-11-03 08:53:13 PDT
https://hg.mozilla.org/mozilla-central/rev/fdb29823b1d4

Note You need to log in before you can comment on or make changes to this bug.