A few odds and ends; more logging, a timeout, and a bad merge

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) {

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);

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'));

lib/logging/logger_factory.js

@@ -23,41 +23,33 @@ 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) {
     if (this.loggers[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;

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() {