gulp test never quits because of InMemoryCacheProvider

[csulok]

I'm unit-testing the integration of passport-saml with gulp and gulp-jasmine. The problem is the test script never quits when any test initalizing passport-saml runs.

With process._getActiveHandles() I traced this to a single 28800000ms timer - this is all I could find out because node-debug gulp is excruciatingly slow - which appears only once in the entire codebase:

if(!options.requestIdExpirationPeriodMs){
    options.requestIdExpirationPeriodMs = 28800000;  // 8 hours
  }

in saml.js#L46

This is used by the InMemoryCacheProvider's cache expiry timer in inmemory-cache-provider.js#L31

setInterval(function(){
        ...
}, this.options.keyExpirationPeriodMs);

Can you recommend a strategy to "fix" testing? I'd prefer not building a new cache provider, because that would leave the builtin one untested. Perhaps exposing the intervalObject returned by setInterval which would allow clearInterval?

Or maybe there's a simpler solution I just can't see it. This freezing of the test - making gulp watch unusable - has been driving me crazy over the past few days.

[csulok]

The best I came up with so far is:

afterEach(function() {

    var inmemoryCacheProviderIntervalObject = _.find(process._getActiveHandles(), {
        msecs: 28800000
    });
    //http://nodejs.org/api/timers.html#timers_unref
    inmemoryCacheProviderIntervalObject.unref();

});

[ploer]

Hmm, I'm not actually very familiar either gulp or jasmine, that's interesting. Do you know what the mechanism is that is causing them to block on that timer?

I would think lots of code sets timers with longer intervals for maintenance tasks, maybe there is a standard practice for dealing with that with those tools?

But as a quick fix for testing, I could see having a value of options.requestIdExpirationPeriodMs that causes the timer to just not be set at all. (I suppose null makes the most sense -- the setting of the default value would have to trigger specifically off being undefined instead of just being falsy)

[csulok]

null or undefined in setInterval is treated as 0ms, meaning it's executed as often as possible, so I'm afraid a different logic is needed to not set the interval at all if that value is strictly false.

Upon further inspection I can see that gulp actually returns, for instance the coverage report gets printed, it's actually nodejs that doesn't return and terminate and prevents gulp watch from running again. The mechanism that blocks it from terminating is there are active timers. Nodejs keeps track of active timers and active requests to keep running eg when you use it as a webserver and wait for requests.

So the only possibility is for tests to clear the interval either internally with a setting or externally like with the code above.

[csulok]

I thought this would be a common issue too, but google searches for "gulp watch setinterval" reveal nothing useful. I think this is because other test systems - like with grunt - use child processes that they terminate, and gulp is relatively new, especially for server side JS.

[ploer]

Well maybe your test code could just call process.exit() when done?

null or undefined in setInterval is treated as 0ms, meaning it's executed as often as possible, so I'm afraid a different logic is needed to not set the interval at all if that value is strictly false.

Yes, I was suggesting that you could put together a PR for passport-saml to make this behave differently.

[csulok]

Cannot call process.exit(), that makes gulp-watch quit too. I'll look into a PR then.

[ploer]

And good point, I agree false would be a better special value to look for than null.

[ploer]

Hmm, I notice at http://nodejs.org/api/timers.html the description of timer.unref(), which I've never paid any attention to before. Could be helpful here, although I'm a little leary of the "creating too many of these may adversely effect event loop performance" warning.

I'd be interested to hear whether that addresses the problem for you. (that is, modifying passport-saml to unref() the return value of setInterval())

[csulok]

unref() does work, and doesn't appear to affect the nodejs process - which is as expected since the webserver has other handles.

I see 2 possibilities where there may be problems:

1. If someone uses passport-saml without a webserver, but that's not possible, right?
2. timer.unref() was added in nodejs 0.9.1 (unstable) / 0.10 (stable), so this method would break the module in v0.8 which is supported according to package.json

[ploer]

re #1 -- you could theoretically be using passport-saml just for the saml code on some backend process. What problem would the unref() cause in that scenario?

re #2 -- if (timer.unref) timer.unref() seems like it ought to cover that. (and then you just don't get this fix in 0.8, which I think is fine)

[csulok]

Re re #1: a nodejs process quits (exit 0) when there's no more code to execute and nothing actively waits or listens. Waiting is settimeout or setinterval, listen is a request or a socket listener mentioned above. If we unref the loop, this particular setinterval may still want to do stuff, but nodejs will quit. You're a better judge of whether that's fine.

[ploer]

If the process is otherwise done with its work, there's no reason to keep it alive just to periodically clear a cache. (in fact, that would almost certainly be the wrong behavior -- it's just never been an issue for passport-saml before because we're typically run in a web server context)

[ploer]

So I'm sold on this as a good change. If you could submit it as a pull request that would be great; otherwise let me know and I can make it.

[ploer]

Actually, it's probably just as easy for me to just make it; will do that now.

[ploer]

Just an update here -- my change is not passing tests on Travis although it succeeded locally. It seems possible that it might be due to changes in timers in node 0.10.34 (see node issue #8897, for instance).

Will investigate more when I have a chance, but in the meantime if you could sync head and let me know if it seems to work well for you that would be helpful.

[ploer]

Yeah, it is easy to reproduce that something changed here in 0.10.34; I've filed a node issue at nodejs/node-v0.x-archive#8900.

I suppose we could workaround by using setTimeout() and rescheduling a new timeout in every call, but let's wait and see what the resolution in that bug is.

[ploer]

For the moment I've just disabled the unref() call if node version is 0.10.34. That bug is flagged to be fixed in 0.10.35, so seems reasonably safe.

Should be fine for your purposes as long as you don't use 0.10.34.