1326614 - setTimeout / setInterval aren't throttled properly for background tabs - round 2, fight

Status: NEW

(Core :: DOM: Core & HTML, defect, P3)

Description

[arni2033]

>>>   My Info:   Win7_64, Nightly 49, 32bit, ID 20160526082509
STR_1:
1. Open devtools -> web console, execute code [1]
2. Wait 3 seconds, then open new selected tab in current FF window
3. Open browser console to view console messages

AR:  Code from one of "setInterval"s is executed each 100ms
ER:  There should be no less than 1000ms between execution of code from setInterval

Note:
 Currently Firefox (pretends that it) throttles setInterval and setTimeout for some reason.
 What I did in STR_1 is created an example that works just like setInterval( ()=>{} , 100 ),
 i.e. exactly the type of intervals that you are trying to ban. So, if functions executed in
 "setInterval"s can communicate to each other, the whole throttling thing doesn't make sense.

[1]
setTimeout(function(){/*init*/
    function F(n){
        var N = n;
        setTimeout(function(){setInterval(function(){console.log(N, Date.now())},1000)}, n*100);
    }
    for (i=0;i<10;i++){
        F(i);
    }
},3000);


STR_2:  ("even this doesn't work"; difference in Step 2)
1. Open devtools -> web console, execute code [1]
2. In less than 3 seconds, then open new selected tab in current FF window
3. Open browser console to view console messages

Comment 2

[arni2033]

Have you checked what the bug says and whether it's still reproducible?

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

Yes I did.  Are you able to reproduce it in a nightly built after Dec 10?

Comment 4

[arni2033]

>>>   My Info:   Win7_64, Nightly 53, 32bit, ID 20161229030206 (2016-12-29)
Yes.
I'm not saying that it's 100% valid, but it's totally not a duplicate.
But it seems that nobody even read it yet. Same question for you again.

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

Attachment: Screenshot 2017-01-04 11.51.55.png

I followed your steps in comment 0 and got this result.  The setInterval() output is separated by 1 second.

Comment 6

[Alice0775 White]

I can reproduce the problem on Nightly53.0a1(2017-01-04) Windows10 and Linux.

AR:
16:40:56.901 0 1483602056901 
16:40:57.000 1 1483602057000 
16:40:57.100 2 1483602057100 
16:40:57.201 3 1483602057201 
16:40:57.299 4 1483602057299 
16:40:57.401 5 1483602057401 
16:40:57.500 6 1483602057500 
16:40:57.599 7 1483602057599 
16:40:57.701 8 1483602057701 
16:40:57.800 9 1483602057800 
16:40:57.900 0 1483602057900 
16:40:58.000 1 1483602058000 
16:40:58.101 2 1483602058101 
16:40:58.200 3 1483602058200 
16:40:58.299 4 1483602058299 
16:40:58.401 5 1483602058401 
16:40:58.501 6 1483602058500 
16:40:58.599 7 1483602058599 
16:40:58.701 8 1483602058701 
16:40:58.800 9 1483602058800 
16:40:58.900 0 1483602058900 

ER(but, allow +/- 0.01 second is acceptable):
16:40:56.901 0 1483602056901 
16:40:56.901 1 1483602056901 
16:40:56.901 2 1483602056901 
16:40:56.901 3 1483602056901 
16:40:56.901 4 1483602056901 
16:40:56.901 5 1483602056901 
16:40:56.901 6 1483602056901 
16:40:56.901 7 1483602056901 
16:40:56.901 8 1483602056901 
16:40:56.901 9 1483602056901 
16:40:57.900 0 1483602057900 
16:40:57.900 1 1483602057900 
16:40:57.900 2 1483602057900 
16:40:57.900 3 1483602057900 
16:40:57.900 4 1483602057900 
16:40:57.900 5 1483602057900 
16:40:57.900 6 1483602057900 
16:40:57.900 7 1483602057900 
16:40:57.900 8 1483602058701 
16:40:57.900 9 1483602057900 
16:40:58.900 0 1483602058900

Comment 7

[Ben Kelly [:bkelly, not reviewing]]

Attachment: 2017-01-05_11-18-58.mp4

This is what I get for STR_2 in comment 0.  I think it shows that part is fixed.

I do see that STR_1 are slightly different and we still don't throttle there.  That is the case where the setInterval is started while the window is in the foreground, but then goes into the background.

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

Actually, I think we are working correctly here.

Let's unpack the STR_1 script in comment 0.  We are waiting for the interval logs to start before switch tabs, so we can remove the outer setTimeout().  That leaves us with:

    function F(n){
        var N = n;
        setTimeout(function(){setInterval(function(){console.log(N, Date.now())},1000)}, n*100);
    }
    for (i=0;i<10;i++){
        F(i);
    }

Each F() call starts a setInterval() with a 1000ms interval.  These setInterva() calls are staggered such that they start 100ms apart.

So while the page is in the foreground we see the setInterval() logs every 100ms.  Each individual setInterval() is delayed 1000ms as specified.

When the tab goes into the background we set a minimum delay on each setInterval() of 1000ms.  These intervals already meet that requirement, however, so nothing changes.

If the original code used a smaller interval delay like `setInterval(f, 100)`, then you would see a change when going into the background.  Each interval will be extended to 1000ms.

Now, comment 0 suggests that we should not only be stretching the delay for setInterval, but also aligning them to some arbitrary boundary somewhere.  Other browsers do this for battery efficiency reasons, but we haven't implemented it yet.  Also, there is no requirement that we do so.

I experimented with aligning background timers before in bug 1284368, but I could not measure any consistent battery improvement.  That situation may have changed as we have improved other parts of the timer code, but I have not checked recently.

In any case, I don't think there is anything to do here.  I'll post a video showing that we do throttle background timers even in the "wait 3 seconds first" case as long as the intervals are actually running faster than our throttle amount.  The timer aligning is a separate issue that we should consider, but only if it has a measurable benefit.

Comment 9

[Ben Kelly [:bkelly, not reviewing]]

Attachment: 2017-01-05_14-47-39.mp4

Its difficult to see in the scrolling text, but timers delta change like this:

While foreground:
 
14:46:57.506 0 1483645617506 
14:46:57.508 1 1483645617508 
14:46:57.510 2 1483645617510 
14:46:57.512 5 1483645617512 
14:46:57.548 4 1483645617548 
14:46:57.631 3 1483645617631 
14:46:57.632 0 1483645617632

While background:

14:47:42.308 0 1483645662308 
14:47:42.318 1 1483645662318 
14:47:42.474 6 1483645662474 
14:47:42.509 2 1483645662509 
14:47:42.527 5 1483645662527 
14:47:42.572 7 1483645662572 
14:47:42.584 8 1483645662584 
14:47:42.606 4 1483645662606 
14:47:42.906 9 1483645662906 
14:47:43.300 3 1483645663300 
14:47:43.308 0 1483645663308 

Look at the deltas for the "0" case.  Its ~100ms in the foreground case and ~1000ms in the background case.

Comment 10

[Ben Kelly [:bkelly, not reviewing]]

I'm not sure how to resolved this bug.  STR_2 is already fixed by bug 1316871.  STR_1 is really testing timer alignment and that is covered by bug 1284368.

Comment 11

[Ben Kelly [:bkelly, not reviewing]]

Also, please be aware that there is a tradeoff with aligning timers.  It can produce bursts of work from background tabs that can affect responsiveness of code trying to run for the foreground tab.  That should be mitigated by the timer ThrottledEventQueue now, but its still a potential issue if many background tabs have timers that all get aligned to the same point in time.

Comment 12

[Jonathan Watt [:jwatt]]

Mass bug change to replace various 'parity' whiteboard flags with the new canonical keywords. (See bug 1443764 comment 13.)