diff --git a/client.js b/client.js index 363b1fda..3033a358 100644 --- a/client.js +++ b/client.js @@ -85,8 +85,8 @@ RingpopClient.prototype.protocolPingReq = function protocolPingReq(opts, body, c this._request(opts, '/protocol/ping-req', null, body, callback); }; -RingpopClient.prototype.protocolDampReq = function protocolDampReq(host, body, callback) { - this._request(host, '/protocol/damp-req', null, body, callback); +RingpopClient.prototype.protocolDampReq = function protocolDampReq(opts, body, callback) { + this._request(opts, '/protocol/damp-req', null, body, callback); }; RingpopClient.prototype.destroy = function destroy(callback) { diff --git a/config.js b/config.js index 0a161045..6b64cd04 100644 --- a/config.js +++ b/config.js @@ -68,10 +68,11 @@ Config.prototype._seed = function _seed(seed) { // Logger configs seedOrDefault('defaultLogLevel', LoggingLevels.info); - seedOrDefault('dampingLogLevel', LoggingLevels.debug); + seedOrDefault('dampingLogLevel', LoggingLevels.error); seedOrDefault('disseminationLogLevel', LoggingLevels.error); - seedOrDefault('gossipLogLevel', LoggingLevels.off); + seedOrDefault('gossipLogLevel', LoggingLevels.error); seedOrDefault('joinLogLevel', LoggingLevels.warn); + seedOrDefault('membershipLogLevel', LoggingLevels.error); seedOrDefault('suspicionLogLevel', LoggingLevels.error); // Gossip configs @@ -83,6 +84,7 @@ Config.prototype._seed = function _seed(seed) { seedOrDefault('dampedMemberExpirationInterval', 60000); seedOrDefault('dampReqNVal', 6); seedOrDefault('dampReqRVal', 3); + seedOrDefault('dampReqTimeout', 1000); seedOrDefault('dampScoringEnabled', true); seedOrDefault('dampScoringDecayEnabled', true); seedOrDefault('dampScoringDecayInterval', 1000); diff --git a/lib/gossip/damper.js b/lib/gossip/damper.js index fd6391c1..35f29978 100644 --- a/lib/gossip/damper.js +++ b/lib/gossip/damper.js @@ -155,6 +155,10 @@ Damper.prototype.addFlapper = function addFlapper(flapper) { Object.keys(this.flappers).length); if (this._getFlapperCount() === 1) { + this.logger.debug('ringpop damper starting damp timer; a flapper has been added', { + local: this.ringpop.whoami(), + flapper: flapper.address + }); this._startDampTimer(); } @@ -188,6 +192,10 @@ Damper.prototype.dampMember = function dampMember(addr) { this.addDampedMember(member.address); if (!this.isExpirationTimerEnabled) { + this.logger.debug('ringpop damper starting expiration timer; a member has been damped', { + local: this.ringpop.whoami(), + member: member.address + }); this._startExpirationTimer(); } @@ -224,6 +232,9 @@ Damper.prototype.expireDampedMembers = function expireDampedMembers() { // If there are no more damped members, stop trying to expire them. if (Object.keys(this.dampedMembers).length === 0) { + this.logger.debug('ringpop damper stopping expiration timer; no damped members left', { + local: this.ringpop.whoami() + }); this._stopExpirationTimer(); } @@ -349,9 +360,10 @@ Damper.prototype.initiateSubprotocol = function initiateSubprotocol(callback) { Damper.prototype.removeFlapper = function removeFlapper(flapper) { var address = flapper.address || flapper; if (!this.flappers[address]) { - this.logger.debug('ringpop flapper has not been added to the damper', { + this.logger.debug('ringpop damper did not remove flapper; it was not added. it may be damped.', { local: this.ringpop.whoami(), - flapper: address + flapper: address, + isDamped: !!this.dampedMembers[address] }); return false; } @@ -366,6 +378,9 @@ Damper.prototype.removeFlapper = function removeFlapper(flapper) { Object.keys(this.flappers).length); if (this._getFlapperCount() === 0) { + this.logger.debug('ringpop damper stopping damp timer; no flappers left', { + local: this.ringpop.whoami() + }); this._stopDampTimer(); } @@ -380,7 +395,10 @@ Damper.prototype._fanoutDampReqs = function _fanoutDampReqs(flapperAddrs, dampRe for (var i = 0; i < dampReqMembers.length; i++) { var dampReqAddr = dampReqMembers[i].address; this.ringpop.stat('increment', 'damp-req.send'); - this.ringpop.client.protocolDampReq(dampReqAddr, request, + this.ringpop.client.protocolDampReq({ + host: dampReqAddr, + timeout: this.ringpop.config.get('dampReqTimeout') + }, request, createDampReqHandler(dampReqAddr)); } @@ -391,7 +409,11 @@ Damper.prototype._fanoutDampReqs = function _fanoutDampReqs(flapperAddrs, dampRe // Accumulate responses until rVal is satisfied or is impossible to satisfy because // too many error responses. function createDampReqHandler(addr) { + var start = Date.now(); return function onDampReq(err, res) { + var timing = Date.now() - start; + self.ringpop.stat('timing', 'protocol.damp-req', timing); + // Prevents double-callback if (typeof callback !== 'function') return; @@ -407,6 +429,7 @@ Damper.prototype._fanoutDampReqs = function _fanoutDampReqs(flapperAddrs, dampRe // Enrich the result with the addr of the damp // req member for reporting purposes. res.dampReqAddr = addr; + res.timing = timing; results.push(res); } @@ -459,6 +482,9 @@ Damper.prototype._startDampTimer = function _startDampTimer() { // in the event that a Ringpop cluster is significantly degraded. Fanning-out // damp-req requests may only make matters worse. self.dampTimer = self.timers.setTimeout(function onTimeout() { + self.logger.debug('ringpop damper damp timer tick', { + local: self.ringpop.whoami() + }); self.initiateSubprotocol(function onSubprotocol() { // It may be the case that the damp timer is stopped while in the // middle of a subprotocol. Make sure we don't schedule another @@ -488,6 +514,9 @@ Damper.prototype._startExpirationTimer = function _startExpirationTimer() { function schedule() { self.expirationTimer = self.timers.setTimeout(function onTimeout() { + self.logger.debug('ringpop damper expiration timer tick', { + local: self.ringpop.whoami() + }); self.expireDampedMembers(); if (self.isExpirationTimerEnabled) schedule(); }, self.ringpop.config.get('dampedMemberExpirationInterval')); diff --git a/lib/logging/logger_factory.js b/lib/logging/logger_factory.js index 4e14c0ec..71f43b81 100644 --- a/lib/logging/logger_factory.js +++ b/lib/logging/logger_factory.js @@ -23,7 +23,19 @@ var ModuleLogger = require('./module_logger.js'); function LoggerFactory(opts) { this.ringpop = opts.ringpop; + this.defaultLogger = new ModuleLogger(this.ringpop, 'defaultLogLevel'); this.loggers = {}; // indexed by name + // TODO This mapping should eventually go away. It seems that log + // level names by convention (logger name + "LogLevel") is the way + // to go. + this.loggerNamesToLevels = { + damping: 'dampingLogLevel', + dissemination: 'disseminationLogLevel', + gossip: 'gossipLogLevel', + join: 'joinLogLevel', + membership: 'membershipLogLevel', + suspicion: 'suspicionLogLevel', + }; } LoggerFactory.prototype.getLogger = function getLogger(name) { @@ -31,33 +43,13 @@ LoggerFactory.prototype.getLogger = function getLogger(name) { return this.loggers[name]; } - switch (name) { - case 'damping': - this.loggers[name] = new ModuleLogger(this.ringpop, - 'dampingLogLevel'); - break; - case 'gossip': - this.loggers[name] = new ModuleLogger(this.ringpop, - 'gossipLogLevel'); - break; - case 'join': - this.loggers[name] = new ModuleLogger(this.ringpop, - 'joinLogLevel'); - break; - case 'suspicion': - this.loggers[name] = new ModuleLogger(this.ringpop, - 'suspicionLogLevel'); - break; - case 'dissemination': - this.loggers[name] = new ModuleLogger(this.ringpop, - 'disseminationLogLevel'); - break; - default: - this.loggers[name] = new ModuleLogger(this.ringpop, - 'defaultLogLevel'); - } + return this._createLogger(name); +}; +LoggerFactory.prototype._createLogger = function _createLogger(name) { + var level = this.loggerNamesToLevels[name] || 'defaultLogLevel'; + this.loggers[name] = new ModuleLogger(this.ringpop, level); return this.loggers[name]; -}; +} module.exports = LoggerFactory; diff --git a/test/unit/damper_test.js b/test/unit/damper_test.js index fe76c557..4c9e2ceb 100644 --- a/test/unit/damper_test.js +++ b/test/unit/damper_test.js @@ -91,9 +91,9 @@ testRingpop({ var targets = setupMembership(deps, nVal + 1); // Remove member from list when a damp-req is sent to member. - stubClient(deps, function protocolDampReq(host, body, callback) { + stubClient(deps, function protocolDampReq(opts, body, callback) { targets = targets.filter(function filter(member) { - return member.address !== host; + return member.address !== opts.host; }); process.nextTick(function onTick() {