Repeat unref'd interval persists program until next interval

[mhmeadows63]

Bug: Repeat unref'd interval persists program until next interval

After the ref'd timeout fires, the unref'd interval should not persist the program,
... but it does until the next time the unref'd interval fires.

                  (should-exit-here)     (actually-exits-here)
                              |                   |
                              v                   v
(time)-------------------------------------------->
         ^                   ^                   ^
         |                   |                   |
        300(1st interval)    |                   |
                            350(timeout)         |
                                                600(2nd interval)

// This is an issue for long unref'd intervals such as for garbage-collection.

var assert = require('assert');
var unref_interval = 0;

setInterval(function() {
    ++unref_interval;
}, 300).unref();

setTimeout(function() {}, 350);

process.on('exit', function() {
    assert.strictEqual(unref_interval, 1, "Repeat unref'd interval persists program until next interval");
});

[harlentan]

The uv loop should have exited after the setTimeout timeout.
I am taking time to see it. And I will fix it if it really is a bug.

[mhmeadows63]

That will be good as this has been bothering me for some time.

I am developing a service app, but when signalled to shut down, it sometimes takes up 150s to exit.

Using NODE_DEBUG="net timers" exposed an unknown 150s interval that I am guessing is gc() related and which sometimes delays the exit depending on whether the service has been running long enough.

Question - is there a way to audit the uv loop to see concisely what is preventing exit at any given moment?

[harlentan]

I think your problem has nothing to do with gc.

[mhmeadows63]

Gc() was just speculation, as the 150s interval is not mine, at least not directly.

have you been able to repro?

[harlentan]

yes. I can reproduce it.

[mhmeadows63]

Any conclusions on whether this is a bug or a feature?

If a bug, how long might the fix take to arrive is a stable release of Node ?

[sam-github]

@mhmeadows63

Question: what is preventing exit?
Answer: process._getActiveRequests(), process._getActiveHandles()

[mhmeadows63]

Thanks, I'll enjoy exploring those calls.

[harlentan]

This is not a bug. It's just the action of timer of unref.

[mhmeadows63]

I am surprised given your opening view that 'The uv loop should have exited after the setTimeout timeout'

Is there a way to avoid this delayed exit behaviour?

[harlentan]

The callback of setInterval will start next timer for 3000ms in your code, which is not the only item in the uv loop.
Every start of a timer will increase the reference of uv loop.

[mhmeadows63]

I am unable to make sense of the explanation, The actual behaviour seems to be at odds with the specified behaviour; because following the timeout, only the unref'd interval is outstanding, so should not prevent program exit. Sadly, nobody else seems interested in expressing a view so it appears I shall have to live with it.

Thank you for looking into it.

[tjfontaine]

I cannot get this to reproduce, what's your environment? (platform, arch, version)

[mhmeadows63]

environment: v0.10.26 Windows7 x64

[vkurchatkin]

0.10.26, 0.11.12 — reproduces on OS X 10.9.1

[mhmeadows63]

Further investigation using a modified version of the test script (given below) reveals an unref()d setInterval is honoured (program exit) where it has fired an even number of times, which is definable on the command line: node 7327.js <n>

var unref_interval = 0;
setInterval(function() {
    ++unref_interval;
}, 300).unref();
setTimeout(function() {}, +process.argv[2] * 300 + 50);
process.on('exit', function() {
    console.log('intervals: ' + unref_interval);
});

Example runs:

# node 7327.js 0
intervals: 0
# node 7327.js 1
intervals: 2
# node 7327.js 2
intervals: 2
# node 7327.js 3
intervals: 4
# node 7327.js 4
intervals: 4
# node 7327.js 5
intervals: 6
# node 7327.js 6
intervals: 6

This seems to correlate with the output of process._getActiveHandles() listing an unref()d setInterval prior to its 1st, 3rd, 5th, 7th ... etc firings, but not before the 2nd, 4th, 6th, 8th ... etc firings. i.e. it appears, disappears, appears, disappears ... from the list of handles.

So, it seems that an unref()d setInterval is only honoured immediately while listed in the output of process._getActiveHandles()

Personally reproduced on:
Window7 x64 v0.10.26
CentOS6.4 x64 v0.10.26
WindowsXP x86 v0.10.26
Debian arm v0.10.26 (raspberrypi)

Not sure where this leaves us, but it's distinctly odd.

[mhmeadows63]

Correction from my previous:

So, it seems that an unref()d setInterval is only honoured immediately while NOT listed in the output of process._getActiveHandles()

[harlentan]

@mhmeadows63
unref()d setInterval will be listed in the activeHandles when it starts.
The setInterval is just a series of timers. Though you unrefed it , the activeHandles will increase when one of the timer starts.

[jasnell]

Currently unable to reproduce on osx 10.10.3 with current v0.10 and v0.12 or io.js. Doesn't mean it's resolved yet tho. @joyent/node-coreteam ... thoughts on this one?

[Fishrock123]

This looks suspiciously like nodejs/node#1231

[jasnell]

Thanks... I thought I remembered seeing something similar but couldn't recall the specifics. I'll test on windows and ubuntu either later today or monday but I suspect this one has been resolved.

[jasnell]

Closing. Appears to be resolved in io.js. Will pick up the fix or we can backport.