00-output.txt

[root@f5c6ad3d (nameservice) ~]$ time ./diagnose.js -o nostop -p 52942
all ok

real    0m4.108s
user    0m1.284s
sys     0m3.230s
[root@f5c6ad3d (nameservice) ~]$ time ./diagnose.js -o nostop -p 8607
dataChanged watcher on "/host/scloud/us-east/manta/87664c1f-853a-41c4-aa6e-0f2d7d90fe45" is faulty
dataChanged watcher on "/host/scloud/us-east/manta/b5326235-e733-4bcc-b6d2-5a715bdb722e" is faulty
dataChanged watcher on "/host/scloud/us-east/manta/ba95541e-4471-4a43-af75-b414b609bc63" is faulty
dataChanged watcher on "/host/scloud/us-east/stor/451" is faulty
dataChanged watcher on "/host/scloud/us-east/stor/1d20776a-ad0f-43b5-8e1b-337786935528" is faulty
dataChanged watcher on "/host/scloud/us-east/manta/bfc08407-e905-47a4-bc67-4fc4f0b4fecb" is faulty
dataChanged watcher on "/host/scloud/us-east/stor/229" is faulty
dataChanged watcher on "/host/scloud/us-east/stor/975ddac4-f6b3-42a0-ad5b-f753aabcfa59" is faulty
dataChanged watcher on "/host/scloud/us-east/stor/c5abbe9d-cb4d-4fbf-890f-5b1db4304673" is faulty
dataChanged watcher on "/host/scloud/us-east/stor/882" is faulty
dataChanged watcher on "/host/scloud/us-east/manta/09f71aa2-ad18-4707-ab3e-846d84d9e520" is faulty
found >10 faulty nodes, exiting early

real    0m11.044s
user    0m2.783s
sys     0m10.254s

diagnose.js

#!/usr/node/bin/node

var mod_child_process = require('child_process');
var mod_util = require('util');
var mod_crypto = require('crypto');
var mod_events = require('events');
var mod_assert = require('assert');

var START_UUID = mod_crypto.randomBytes(16).toString('hex');
var START_MARKER = '## ' + START_UUID;
var END_UUID = mod_crypto.randomBytes(16).toString('hex');
var END_MARKER = '## ' + END_UUID;
var MARKER_REGEX = new RegExp(START_MARKER + ' ?\\n((?:.|[\\r\\n])*)' +
    END_MARKER + ' ?\\n', 'm');

var MAX_FAULTY = 10;

function
MDB(opts)
{
	var self = this;
	mod_events.EventEmitter.call(self);

	self._exit = null;
	self._qq = null;
	self._q = [];

	self._proc = mod_child_process.spawn('/usr/bin/mdb', opts);

	self._data = '';
	self._proc.stdout.on('data', function (ch) {
		self._data += ch.toString('utf8');
		self._handle();
	});
	self._proc.stderr.on('data', function (ch) {
		self.emit('stderr', ch);
	});

	self._proc.once('exit', function(code, signal) {
		self._exit = { code: code, signal: signal };
		if (self._qq === null && self._q.length === 0)
			self.emit('exit', code, signal);
	});

	/*
	 * Send a dummy command to separate any Banner noise
	 * from actual output:
	 */
	self.command('::load libc', function () {
		self._started = true;
	});
}
mod_util.inherits(MDB, mod_events.EventEmitter);

MDB.prototype._dispatch = function
_dispatch()
{
	var self = this;

	if (self._qq !== null || self._exit != null || self._q.length === 0)
		return;

	self._qq = self._q.shift();

	self._proc.stdin.write('::echo ' + START_MARKER + '\n');
	if (self._qq.command)
		self._proc.stdin.write(self._qq.command + '\n');
	self._proc.stdin.write('::echo ' + END_MARKER + '\n');
}

MDB.prototype._handle = function
_handle()
{
	var self = this;

	var m = MARKER_REGEX.exec(self._data);
	if (!m)
		return;

	/*
	 * Throw away the data we just consumed.
	 */
	self._data = self._data.substr(m.index + m[0].length);

	/*
	 * Send the result to the callback:
	 */
	if (self._qq) {
		var output = m[1];
		if (self._qq.split) {
			output = output.split(/[\r\n]+/).map(function (line) {
				var parts = line.split(/[\s:]+/);
				while (parts.length > 0 && parts[0] === '')
					parts.shift();
				while (parts.length > 0 && parts[parts.length - 1] === '')
					parts.pop();
				return (parts);
			});
			while (output.length > 0 && output[0].length === 0)
				output.shift();
			while (output.length > 0 && output[output.length - 1].length === 0)
				output.pop();
		}
		if (self._qq.callback && self._qq.argument) {
			self._qq.callback(self._qq.command, self._qq.argument,
			    output);
		} else if (self._qq.callback) {
			self._qq.callback(self._qq.command, output);
		}
		self._qq = null;
	}

	if (self._q.length === 0 && self._exit) {
		self.emit('exit', self._exit.code, self._exit.signal);
		return;
	}

	/*
	 * Attempt to send the next command to mdb:
	 */
	self._dispatch();
}

MDB.prototype.commandRaw = function
commandRaw()
{
	var self = this;
	var args = Array.prototype.slice.apply(arguments);
	var callback = args.pop();
	var cmdstr = mod_util.format.apply(mod_util, args);
	if (cmdstr.indexOf(START_UUID) !== -1 ||
	    cmdstr.indexOf(END_UUID) !== -1) {
		throw new (Error('command contains marker uuids'));
	}
	if (self._exit) {
		throw new (Error('attempt to run command after mdb already ' +
		    'exited'));
	}
	self._q.push({
		command: cmdstr,
		split: false,
		callback: callback
	});
	self._dispatch();
}

MDB.prototype.command = function
command()
{
	var self = this;
	var args = Array.prototype.slice.apply(arguments);
	var callback = args.pop();
	var cmdstr = mod_util.format.apply(mod_util, args);
	if (cmdstr.indexOf(START_UUID) !== -1 ||
	    cmdstr.indexOf(END_UUID) !== -1) {
		throw new (Error('command contains marker uuids'));
	}
	if (self._exit) {
		throw new (Error('attempt to run command after mdb already ' +
		    'exited'));
	}
	self._q.push({
		command: cmdstr,
		split: true,
		callback: callback
	});
	self._dispatch();
}

MDB.prototype.close = function
close()
{
	var self = this;

	self._proc.stdin.write('::quit\n');
	self._proc.stdin.end();
}

function waterfall_impl(opts)
{
	mod_assert.ok(typeof (opts) === 'object');
	var rv, current, next;
	var funcs = opts.funcs;
	var callback = opts.callback;

	mod_assert.ok(Array.isArray(funcs),
	    '"opts.funcs" must be specified and must be an array');
	mod_assert.ok(arguments.length == 1,
	    'Function "waterfall_impl" must take only 1 arg');
	mod_assert.ok(opts.res_type === 'values' ||
	    opts.res_type === 'array' || opts.res_type == 'rv',
	    '"opts.res_type" must either be "values", "array", or "rv"');
	mod_assert.ok(opts.stop_when === 'error' ||
	    opts.stop_when === 'success',
	    '"opts.stop_when" must either be "error" or "success"');
	mod_assert.ok(opts.args.impl === 'pipeline' ||
	    opts.args.impl === 'waterfall' || opts.args.impl === 'tryEach',
	    '"opts.args.impl" must be "pipeline", "waterfall", or "tryEach"');
	if (opts.args.impl === 'pipeline') {
		mod_assert.ok(typeof (opts.args.uarg) !== undefined,
		    '"opts.args.uarg" should be defined when pipeline is used');
	}

	rv = {
	    'operations': funcs.map(function (func) {
	        return ({
		    'func': func,
		    'funcname': func.name || '(anon)',
		    'status': 'waiting'
		});
	    }),
	    'successes': [],
	    'ndone': 0,
	    'nerrors': 0
	};

	if (funcs.length === 0) {
		if (callback)
			setImmediate(function () {
				var res = (opts.args.impl === 'pipeline') ? rv
				    : undefined;
				callback(null, res);
			});
		return (rv);
	}

	next = function (idx, err) {
		var res_key, nfunc_args, entry, nextentry;

		if (err === undefined)
			err = null;

		if (idx != current) {
			throw (new Error(mod_util.format(
			    'vasync.waterfall: function %d ("%s") invoked ' +
			    'its callback twice', idx,
			    rv['operations'][idx].funcname)));
		}

		mod_assert.equal(idx, rv['ndone'],
		    'idx should be equal to ndone');
		entry = rv['operations'][rv['ndone']++];
		if (opts.args.impl === 'tryEach' ||
		    opts.args.impl === 'waterfall') {
			nfunc_args = Array.prototype.slice.call(arguments, 2);
			res_key = 'results';
			entry['results'] = nfunc_args;
		} else if (opts.args.impl === 'pipeline') {
			nfunc_args = [ opts.args.uarg ];
			res_key = 'result';
			entry['result'] = arguments[2];
		}

		mod_assert.equal(entry['status'], 'pending',
		    'status should be pending');
		entry['status'] = err ? 'fail' : 'ok';
		entry['err'] = err;

		if (err) {
			rv['nerrors']++;
		} else {
			rv['successes'].push(entry[res_key]);
		}

		if ((opts.stop_when === 'error' && err) ||
		    (opts.stop_when === 'success' &&
		    rv['successes'].length > 0) ||
		    rv['ndone'] == funcs.length) {
			if (callback) {
				if (opts.res_type === 'values' ||
				    (opts.res_type === 'array' &&
				     nfunc_args.length <= 1)) {
					nfunc_args.unshift(err);
					callback.apply(null, nfunc_args);
				} else if (opts.res_type === 'array') {
					callback(err, nfunc_args);
				} else if (opts.res_type === 'rv') {
					callback(err, rv);
				}
			}
		} else {
			nextentry = rv['operations'][rv['ndone']];
			nextentry['status'] = 'pending';
			current++;
			nfunc_args.push(next.bind(null, current));
			setImmediate(function () {
				var nfunc = nextentry['func'];
				if (opts.args.impl !== 'tryEach') {
					nfunc.apply(null, nfunc_args);
				} else {
					nfunc(next.bind(null, current));
				}
			});
		}
	};

	rv['operations'][0]['status'] = 'pending';
	current = 0;
	if (opts.args.impl !== 'pipeline') {
		funcs[0](next.bind(null, current));
	} else {
		funcs[0](opts.args.uarg, next.bind(null, current));
	}
	return (rv);
}

var state = {};
waterfall_impl({
	'funcs': [
		startMdb,
		getIsolateKey,
		getIsolate,
		findThreadLocalTop,
		loadV8,
		addCellFields,
		getGlobalObject,
		getGlobalProperties,
		listGlobalPropertiesCells,
		findProcessGlobalCell,
		getProcess,
		getMainModule,
		walkModules,
		findCueballMod,
		getCueballSets,
		checkZKSet,
		getSetFsms,
		getZKSession,
		getZKSessProps,
		listStateChangedListeners,
		walkListeners,
	],
	'callback': function (err) {
		if (err) {
			if (err.name !== 'FaultyNodesError') {
				delete (state.mdb);
				console.error(state.stderr);
				delete (state.stderr);
				console.error(err.stack);
			}
			state.err = true;
		}
		if (state.mdb) {
			state.mdb.on('exit', finish);
			state.mdb.close();
		} else {
			finish();
		}
	},
	'args': {
		'impl': 'pipeline',
		'uarg': state
	},
	'stop_when': 'error',
	'res_type': 'rv'
});

function finish() {
	if (state.err) {
		if (state.faulty > 0)
			process.exit(2);
		else
			process.exit(1);
	} else {
		console.log('all ok');
		process.exit(0);
	}
}

function startMdb(_, cb) {
	var opts = [];
	opts = process.argv.slice(2);
	_.stderr = '';
	_.mdb = new MDB(opts);
	_.mdb.on('stderr', function (data) {
		_.stderr += data;
	});
	cb();
}

var ISOLATE_KEY_SYM = '_ZN2v88internal7Isolate12isolate_key_E';

function getIsolateKey(_, cb) {
	_.mdb.command('%s/d', ISOLATE_KEY_SYM,
	    function (cmd, lines) {
		_.isolateKey = lines.pop()[1];
		cb();
	});
}

function getIsolate(_, cb) {
	_.mdb.command('1::tsd -k %d', _.isolateKey,
	    function (cmd, lines) {
		var line = lines.pop();
		if (!line || !line[0]) {
			cb(new Error('failed to get isolate tsd'));
			return;
		}
		_.isolate = line[0];
		cb();
	});
}

function findThreadLocalTop(_, cb) {
	_.mdb.command('%s+30,1800/nap ! grep \'%s[ ]*$\'',
	    _.isolate, _.isolate, function (cmd, selfptrs) {
		selfptrs.shift();
		next();
		function next() {
			var selfptr = selfptrs.shift();
			if (selfptr === undefined) {
				cb(new Error('failed to find selfptr'));
				return;
			}
			_.mdb.command('%s,4/nap', selfptr[0],
			    function (cmd, ptrs) {
				if (ptrs[3][1] === '1') {
					_.context = ptrs[2][1];
					cb();
					return;
				}
				next();
			});
		}
	});
}

function loadV8(_, cb) {
	_.mdb.command('::load v8', function () {
		cb();
	});
}

function addCellFields(_, cb) {
	_.mdb.command('::v8field PropertyCell value 4', function () {
		_.mdb.command('::v8field JSGlobalPropertyCell value 4',
		    function () {
			cb();
		});
	});
}

function getGlobalObject(_, cb) {
	_.mdb.command('%s::v8context ! grep \'^global object:\'',
	    _.context, function (cmd, lines) {
		var line = lines.pop();
		if (!line || line[0] !== 'global') {
			cb(new Error('global object not found'));
			return;
		}
		_.globalObj = line[2];
		cb();
	});
}

function getGlobalProperties(_, cb) {
	_.mdb.command('%s::v8print ! grep \'properties =\'',
	    _.globalObj, function (cmd, lines) {
		var line = lines.pop();
		if (line[1] !== 'properties') {
			cb(new Error('no global properties found'));
			return;
		}
		_.globalProps = line[3];
		cb();
	});
}

function listGlobalPropertiesCells(_, cb) {
	_.mdb.command('%s::v8array', _.globalProps,
	    function (cmd, lines) {
		_.globalPropCells = lines.map(function (line) {
			return (line[0]);
		});
		cb();
	});
}

function findProcessGlobalCell(_, cb) {
	_.mdb.command('%s::v8array | ::jsprint -a ! grep \'"process"\'',
	    _.globalProps, function (cmd, lines) {
		var line = lines.pop();
		if (!line || line[1] !== '"process"') {
			cb(new Error('no process string'));
			return;
		}
		_.stderr = '';
		var idx = _.globalPropCells.indexOf(line[0]);
		_.processCell = _.globalPropCells[idx + 1];
		delete (_.globalPropCells);
		cb();
	});
}

function getProcess(_, cb) {
	_.mdb.command('%s::v8print ! grep \'value =\'', _.processCell,
	    function (cmd, lines) {
		var line = lines.pop();
		if (line[1] !== 'value') {
			cb(new Error('no process cell value found'));
			return;
		}
		_.process = line[3];
		cb();
	});
}

function getMainModule(_, cb) {
	_.mdb.command('%s::jsprint -ad0 mainModule', _.process,
	    function (cmd, lines) {
		_.mainMod = lines.pop()[0];
		cb();
	});
}

function walkModules(_, cb) {
	var modQueue = [_.mainMod];
	_.modQueue = modQueue;
	_.modLookup = {};
	function next() {
		var mod = modQueue.shift();
		if (mod === undefined) {
			cb();
			return;
		}
		_.mod = { addr: mod };
		waterfall_impl({
			'funcs': [
				getModKidsAndEnqueue,
				getModFilename,
				getModExports,
			],
			'callback': function (err) {
				if (err) {
					cb(err);
					return;
				}
				next();
			},
			'args': {
				'impl': 'pipeline',
				'uarg': _
			},
			'stop_when': 'error',
			'res_type': 'rv'
		});
	}
	next();
}

function getModFilename(_, cb) {
	_.mdb.commandRaw('%s::jsprint filename', _.mod.addr,
	    function (cmd, output) {
		_.mod.filename = output.trim();
		if (_.mod.filename.indexOf('zkstream') !== -1 &&
		    _.mod.filename.indexOf('/cueball/lib/index.js') !== -1) {
			_.cueballMod = _.mod;
			_.modQueue = [];
		}
		cb();
	});
}

function getModExports(_, cb) {
	_.mdb.command('%s::jsprint -ad0 exports', _.mod.addr,
	    function (cmd, lines) {
		_.mod.exports = lines.pop()[0];
		cb();
	});
}

function getModKidsAndEnqueue(_, cb) {
	_.mdb.command('%s::jsprint -ad1 children ! grep -F \'[...]\'',
	    _.mod.addr, function (cmd, lines) {
		lines.forEach(function (line) {
			if (line[0] === '[')
				_.modQueue.push(line[1]);
			_.modQueue.push(line[0]);
		});
		cb();
	});
}

function findCueballMod(_, cb) {
	if (_.cueballMod === undefined || _.cueballMod.exports === undefined) {
		cb(new Error('failed to find cueball mod'));
		return;
	}
	_.cueball = _.cueballMod.exports;
	cb();
}

function getCueballSets(_, cb) {
	_.mdb.command('%s::jsprint -ad1 poolMonitor.pm_sets ! grep -F \'[...]\'', _.cueball,
	    function (cmd, lines) {
		_.sets = lines.map(function (line) { return (line[1]); });
		cb();
	});
}

function checkZKSet(_, cb) {
	_.zkSet = _.sets[0];
	_.mdb.commandRaw('%s::jsprint cs_resolver.r_fsm.sr_backends[0].name',
	    _.zkSet, function (cmd, output) {
		if (output.trim() !== '"127.0.0.1:2181"') {
			cb(new Error('failed to find zk set'));
			return;
		}
		cb();
	});
}

function getSetFsms(_, cb) {
	_.mdb.command('%s::jsprint -ad1 cs_fsm ! grep -F \'[...]\'', _.zkSet,
	    function (cmd, lines) {
		_.fsms = lines.map(function (line) { return (line[1]); });
		cb();
	});
}

function getZKSession(_, cb) {
	var fsm = _.fsms[0];
	_.mdb.command('%s::jsprint -ad0 csf_smgr.sm_socket.zcf_session', fsm,
	    function (cmd, lines) {
		_.zkSession = lines.pop()[0];
		cb();
	});
}

function getZKSessProps(_, cb) {
	_.mdb.command('%s::v8print ! grep \'properties =\'', _.zkSession,
	    function (cmd, lines) {
		var line = lines.pop();
		_.zkSessProps = line[3];
		cb();
	});
}

function listStateChangedListeners(_, cb) {
	_.mdb.command('%s::v8array | ::jsprint -a stateChanged ! grep onStateChanged',
	    _.zkSessProps, function (cmd, lines) {
		_.listeners = lines.map(function (line) { return (line[0]); });
		cb();
	});
}

function walkListeners(_, cb) {
	var queue = _.listeners.slice();
	_.faulty = 0;
	_.faultyDupe = {};
	function next() {
		var listener = queue.shift();
		if (listener === undefined) {
			cb();
			return;
		}
		_.listener = { addr: listener };
		waterfall_impl({
			'funcs': [
				getListenerClosure,
				getCallbackBinding,
				checkTreeNode,
			],
			'callback': function (err) {
				if (err) {
					cb(err);
					return;
				}
				next();
			},
			'args': {
				'impl': 'pipeline',
				'uarg': _
			},
			'stop_when': 'error',
			'res_type': 'rv'
		});
	}
	next();
}

function getListenerClosure(_, cb) {
	_.mdb.command('%s::jsclosure', _.listener.addr,
	    function (cmd, lines) {
		var attrs = {};
		lines.forEach(function (line) {
			var key = line[0].replace(/^"/,'').replace(/",?$/,'');
			var v = {};
			v.addr = line[1];
			if (line[2])
				v.value = line[2].replace(/^"/,'').replace(/",?$/,'');
			attrs[key] = v;
		});
		var evt = attrs.evt.value;
		_.listener.event = evt;
		var self = attrs.self.addr;
		_.listener.watcher = self;
		_.mdb.command('%s::jsprint -a _events.%s', self, evt,
		    function (cmd, lines) {
			_.listener.callbacks = lines.map(function (line) { return (line[0]); });
			cb();
		});
	});
}

function getCallbackBinding(_, cb) {
	var func = _.listener.callbacks[0];
	if (func === undefined || func === 'undefined') {
		cb();
		return;
	}
	_.mdb.command('%s::v8print', func,
	    function (cmd, lines) {
		var bindings;
		lines.forEach(function (line) {
			if (line[1] === 'literals_or_bindings')
				bindings = line[3];
		});
		if (bindings === undefined) {
			cb(new Error('no bindings found'));
			return;
		}
		_.mdb.command('%s::v8array | ::jsprint -abd0 tn_watcher ! grep -F \'[...]\'',
		    bindings, function (cmd, lines) {
			var line = lines.pop();
			if (line[1] !== _.listener.watcher) {
				cb(new Error('watcher consistency check failed'));
				return;
			}
			_.listener.treeNode = line[0];
			cb();
		});
	});
}

function checkTreeNode(_, cb) {
	var tn = _.listener.treeNode;
	if (tn === undefined) {
		cb();
		return;
	}
	_.mdb.command('%s::jsprint -d0 tn_path tn_data', tn,
	    function (cmd, lines) {
		var line = lines.pop();
		if (line[1] === 'null' &&
		    _.listener.event === 'dataChanged' &&
		    !_.faultyDupe[line[0]]) {
			console.log('%s watcher on %s is faulty',
			    _.listener.event, line[0]);
			_.faulty++;
			if (_.faulty > MAX_FAULTY) {
				console.log('found >%d faulty nodes, exiting early',
				    MAX_FAULTY);
				var err = new Error('too many faulty nodes');
				err.name = 'FaultyNodesError';
				cb(err);
				return;
			}
			_.faultyDupe[line[0]] = true;
		}
		cb();
	});
}