Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Timer's unref unreliable when http module required after using them #1151

Closed
brycebaril opened this issue Mar 13, 2015 · 11 comments
Closed

Timer's unref unreliable when http module required after using them #1151

brycebaril opened this issue Mar 13, 2015 · 11 comments
Labels
confirmed-bug Issues with confirmed bugs. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout.

Comments

@brycebaril
Copy link
Contributor

Finally narrowed this down to a (admittedly bizarre) test case -- still looking into exactly why it happens -- but generally there appears to be a race condition or off-by-one in the timer unref management if the unref is called and then later the http module is required:

setImmediate(function () {
  require("http")
})

var i = setInterval(function () {
  setImmediate(process.exit)
}, 10)
i.unref()

process.on("exit", logstuff)

function logstuff() {
  console.log(process._getActiveHandles())
}

With 0.10 or 0.12 this logs [] which is expected because the interval was unreferenced.

In io.js you get:

[ { '0': [Function: listOnTimeout],
    _idleNext: 
     { _idleTimeout: 10,
       _idlePrev: [Circular],
       _idleNext: [Circular],
       _idleStart: 1218064360,
       _onTimeout: [Function: wrapper],
       _repeat: true,
       _handle: [Object] },
    _idlePrev: 
     { _idleTimeout: 10,
       _idlePrev: [Circular],
       _idleNext: [Circular],
       _idleStart: 1218064360,
       _onTimeout: [Function: wrapper],
       _repeat: true,
       _handle: [Object] },
    msecs: 10 } ]

Which is showing the unreferenced timer.

I found this when my application was supposed to be shutting down but was being kept alive by an unreferenced setInterval timer.

@Fishrock123 Fishrock123 added http Issues or PRs related to the http subsystem. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. investigate labels Mar 13, 2015
@brendanashworth
Copy link
Contributor

Running on node v0.11.14 on OSX, I get the latter output (same on io.js v1.5.2). Which operating system are you running on?

@brycebaril
Copy link
Contributor Author

@brendanashworth Ubuntu -- I also get the unexpected output with 0.11.14 (just tried it now)

@brycebaril
Copy link
Contributor Author

Yeah, appears to happen in node 0.11.12 through 0.11.14, but not the earlier/later versions.

@brycebaril
Copy link
Contributor Author

Applying this commit to iojs appears to fix this: nodejs/node-v0.x-archive@0d05123

@Fishrock123
Copy link
Contributor

Looks like a few core modules exhibit this. I can confirm that patch is not in io.js. Reading up on the original issue.

@Fishrock123 Fishrock123 added confirmed-bug Issues with confirmed bugs. and removed http Issues or PRs related to the http subsystem. investigate labels Mar 14, 2015
@thlorenz
Copy link
Contributor

@brycebaril testing @Fishrock123's fix for this.

I did get what you listed above before the fix for both the Release and Debug builds.

After the fix I get:

OSX

[ { '0': [Function: listOnTimeout],
    _idleNext: [Circular],
    _idlePrev: [Circular],
    msecs: 10 } ]

only when using the Debug build and only sometimes (well it's a timer issue).
For the Release build I get [] at all times.

So it seems not completely fixed right?

Linux

Here things appear to be fixed at least for this usecase, but one of the tests in the PR still segfaults.

@Fishrock123
Copy link
Contributor

Simplified test case:

var assert = require('assert');

setImmediate(function () {
  var count = 0;
  while (count++ < 1e7) {
    Math.random()
  }
});

var i = setInterval(function () {
  setImmediate(process.exit);
}, 10);
i.unref();

process.on('exit', function() {
  assert.strictEqual(process._getActiveHandles().length, 0);
});

Even better test case that may pinpoint the issue more clearly:

var assert = require('assert');

var i = setInterval(function () {
  // does not matter if we swap the nextTick with the setImmediate
  process.nextTick(function() {
    setImmediate(process.exit);
  })
}, 1);
i.unref();

process.on('exit', function() {
  assert.strictEqual(process._getActiveHandles().length, 0);
});

Update: order of nextTick / setImmediate does not matter.

Fishrock123 referenced this issue in nodejs/node-v0.x-archive Mar 30, 2015
Unlike the 'exit' event, this event allows the user to schedule more
work and thereby postpone the exit.  That also means that the
'beforeExit' event may be emitted many times, see the attached test
case for an example.

Refs #6305.
@brendanashworth
Copy link
Contributor

This was fixed in #1330.

@Fishrock123
Copy link
Contributor

@brendanashworth I'm not sure about that, did you test it? This is the "timers running during beforeExit time" issue.

@brendanashworth
Copy link
Contributor

@Fishrock123 whoops! I ran the original test and that didn't error, I didn't try your updated test. Reopening, sorry about that.

@Fishrock123
Copy link
Contributor

Defer to #1264

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
confirmed-bug Issues with confirmed bugs. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout.
Projects
None yet
Development

No branches or pull requests

4 participants