populateIn does not restart after pausePopulateIn triggers

[nemtsov]

Repro:

var distribucache = require('distribucache'),
  memoryStore = require('distribucache-memory-store'),
  store = memoryStore(),
  logEvents = require('distribucache-console-logger'),
  cacheClient = distribucache.createClient(store),
  cache;

cache = cacheClient.create('randomness', {
  populateIn: '5 sec',
  pausePopulateIn: '10 sec',
  populate: function (key, cb) {
    setTimeout(function () {
      var value = Math.round(Math.random() * 1000);
      console.log('[client] populating with:', value);
      cb(null, value);
    }, 250);
  }
});

logEvents(cache);

function doIt() {
  var t = Date.now();
  cache.get('k8', function (err, value) {
    if (err) return console.error('[client] ', err);
    console.log('[client] got `%j` (type: %s) in %dms',
      value, typeof value, Date.now() - t);
  });
}

console.log('--------------- GET ------------------')
doIt();

setTimeout(function () { 
  console.log('------------- POPULATE -------------')
}, 5000);

setTimeout(function () { 
  console.log('---------- PAUSING NOW ----------')
}, 10000);

setTimeout(function () {
  doIt();
  setInterval(doIt, 5000);
}, 16000);

Result:

--------------- GET ------------------
2016-02-09T19:45:32.991Z get:before - k8
2016-02-09T19:45:32.993Z get:after - k8,2
2016-02-09T19:45:32.994Z get:miss - k8
2016-02-09T19:45:32.994Z populate:before - k8
[client] populating with: 561
2016-02-09T19:45:33.246Z set:before - k8,561
2016-02-09T19:45:33.248Z set:after - k8,561,2
2016-02-09T19:45:33.248Z populate:after - k8,254
[client] got `561` (type: number) in 258ms
---------- POPULATE ----------
2016-02-09T19:45:38.254Z populateIn:before - k8
2016-02-09T19:45:38.256Z populate:before - k8
[client] populating with: 327
2016-02-09T19:45:38.510Z set:before - k8,327
2016-02-09T19:45:38.511Z set:after - k8,327,1
2016-02-09T19:45:38.511Z populate:after - k8,255
2016-02-09T19:45:38.511Z populateIn:after - k8,257
---------- PAUSING NOW ----------
2016-02-09T19:45:43.515Z populateIn:before - k8
2016-02-09T19:45:43.515Z populateIn:pause - k8
2016-02-09T19:45:43.516Z populateIn:after - k8,1
2016-02-09T19:45:48.995Z get:before - k8
2016-02-09T19:45:48.996Z get:after - k8,1
2016-02-09T19:45:48.996Z get:hit - k8
[client] got `327` (type: number) in 1ms
2016-02-09T19:45:53.997Z get:before - k8
2016-02-09T19:45:53.997Z get:after - k8,0
2016-02-09T19:45:53.997Z get:hit - k8
[client] got `327` (type: number) in 0ms
2016-02-09T19:45:58.998Z get:before - k8
2016-02-09T19:45:58.998Z get:after - k8,0
2016-02-09T19:45:58.998Z get:hit - k8
[client] got `327` (type: number) in 0ms
2016-02-09T19:46:04.000Z get:before - k8
2016-02-09T19:46:04.000Z get:after - k8,0
2016-02-09T19:46:04.001Z get:hit - k8
[client] got `327` (type: number) in 1ms
2016-02-09T19:46:09.007Z get:before - k8
2016-02-09T19:46:09.007Z get:after - k8,0
2016-02-09T19:46:09.007Z get:hit - k8
[client] got `327` (type: number) in 0ms

Issue:
The [client] got 327 does not change after pausePopulateIn.

[nemtsov]

/cc @jessegavin