cb-inspector

node callback inspector

---

node callback inspector is an experimental debugging tool for code making heavy use of callbacks.

Callbacks are prone to human error (there is no guarantee your callback will get called except for that of the library and all of its deps) making it difficult (near impossible sometimes) to really know where things broke down.

A common example is the "cb() never called" error from npm, even if npm has no mistakes, any of the supporting libraries may have an edge case where a callback is not called. At that point there may be nothing left in the event loop, so node will start exiting the process. No errors, no trace, the implicit default of a callback is to stop execution.

Needless to say, it is not always an easy problem to debug.

How it works

The callback inspector has two parts: a command line tool for injecting debug hooks, and a library for tracking callbacks.

The command-line tool uses rocambole for parsing, code injection, and cleanup (removing hooks). It finds all functions with the argument signature function(...., cb){ } where cb must match the regular expression /(_?cb_?|callback|done)/. It wraps the cb function with some hooks, and adds a require statement at the top of each file. All code generated by the rewrite tool is wrapped in block comments /*CB_INSPECTOR__START*/ and /*CB_INSPECTOR__END*/ so that the rewrite tool can easily remove or replace it.

Each time a callback is passed into a new function (that has been modified by the rewrite tool), the callback is registered, and the function receiving the callback is noted as a handler. Each time the callback is called, the called property is incremented for the callback itself, as well as the individual handler.

Internally the library uses a WeakMap so that a callback function instance is tracked accurately, even when passed to multiple functions.

What it does for you

The goal is to have some vision into callbacks that are passed around but never called, or called multiple times. The initial inspiration was getting cb() never called from npm.. :)

The library API

Callback status data (from .pendingCallbacks, .allCallbacks, .completedCallbacks) is in the following format:

{
	name: "cb", //cb.name -- e.g function mycb(){} == mycb
	index: 0, //the order the callback was registered in
	argCount: 1, //cb.length -- e.g. function(a,b,c){} == 3
	called: 0, //number of times the callback has been called (since being registered)
	unixTimestamp: 0, //unix timestamp of the first registration (not guaranteed to match the handler)
	handlers: [{ //array of handlers -- functions the callback was passed as an argument to
		called: 0, //same as above, but specific to this handler
		unixTimestamp: 0, //time this handler was registered
		meta: {
			name: "", //name of the handler function, as above
			file: "", //full path to the file the handler can be found in
			line: 0, //line number the handler can be found on
			column: 0 //column the handler function starts on
		}
	}]
}

Methods:

.wrap(cb, opts) - where cb is the callback function to wrap and opts is an object with at least a file and line properties.

.pendingCallbacks - returns a list of pending callbacks

.completeCallbacks - returns a list of completed callbacks

.allCallbacks - returns a list of all (pending and completed) callbacks

.reportOnExit(all) - registers a process.on("exit") handler to log if any callbacks were never called. If all is true, then all callback states will be logged every time.

.httpReporter(port) - listens on a given port for http requests, returning callback data, supports /all, /pending, /complete. All other routes (including /) will respond with /pending

Example:

//generally this is just generated via the command-line tool
var cbInspector = require("cb-inspector");

console.log(cbInspector.pendingCallbacks());
cbInspector.reportOnExit();

The Command-line Tool

The command line tool will inject code that uses the library to track and report on callbacks.

Usage: cb-inspector-rewrite [-hre] <file(s)>
  -h, --help          This text.
  -r, --remove        Remove all handlers/hooks.
  -e, --exit-report   Report any pending callbacks on process exit (has no effect if -r is specified).
  -a, --all-report    Report status of ALL callbacks (including completed) implies --exit-report
  --http=<port>       Listen for HTTP requests, reporting status of all callbacks.

To debug cb() never called in npm, you may try something like:

# install cb-inspector if it's not already
npm install -g cb-inspector

# install npm locally to test
npm install npm@2.7.4

# patch all the code, and telling it to dump pending callbacks on process exit
cb-inspector-rewrite -e node_modules/npm node_modules/.bin/npm

# run whatever npm command is giving you trouble
node_modules/.bin/npm install some-set-of-packages-that-causes-the-behavior

Example Output:

For this example, I added a return statement to the dedup function on line 31 of dedup.js so it would not fire the callback.

node_modules/.bin/npm dedup

cb never called -- errorHandler args:1 -- was passed to 1 handler(s) (none called back)
    Passed to function dedupe_ at /home/nathan/projects/src/github.com/mastercactapus/node-cb-inspector/temp/node_modules/npm/lib/dedupe.js:31:0
npm ERR! cb() never called!