Skip to content

Instantly share code, notes, and snippets.

@Anna-Myzukina
Last active September 28, 2018 18:07
Show Gist options
  • Save Anna-Myzukina/21a0b6774f9f3c6a226a9e81b8d03114 to your computer and use it in GitHub Desktop.
Save Anna-Myzukina/21a0b6774f9f3c6a226a9e81b8d03114 to your computer and use it in GitHub Desktop.
bug-clinic
//Exercise 1
/*To proceed, write a program that prints "i am okay" to standard output
and "i am so incredibly not okay" to standard error.
*/
console.log('i am okay');
console.error('i am so incredibly not okay');
// Exercise 10
Although you'd think a debugger would be the first tool to reach for
when you're talking about debugging, Node developers tend to not use
debuggers as much. There are a few reasons for this, but there are two
main reasons why using the Node debugger is difficult enough that most
people don't bother:
* Node's dynamic module system means that you have to wait until a
module has been require()d to set function-based breakpoints in it.
* The Node event loop is implemented in such a way that it's
impossible to step across ticks of the event loop.
It doesn't help that the debugger's UI is obtuse to the point of pain,
but once you learn a few commands, it's not so bad:
* s - step in, or go to the next line in the program, stepping in to
function calls. The second most useful debugger command.
* <enter> - repeat the previous command. *The* most useful debugger
command.
* n - next command. Like `s`, without stepping into function calls.
* o - step out, for when you're not interested in anything else happening in
the current function.
* c - continue. Just run until the next breakpoint or `debugger` statement
is hit.
Speaking of the `debugger` statement, the key to efficiently using
the Node debugger lies in the `debugger` statement. It's basically
a breakpoint in code. When you've narrowed down roughly where the
issue is in your code, put `debugger;` into your code a few lines
*before* the troublesome line, so you can use the debugger REPL to
gather context. If you have a test case, it makes things much simpler.
This is a somewhat tedious process (and you should be careful to scrub
out your debugger statements when you're done -- jshint and eslint
will warn you about leftover debug statements, if you run them!), but
it's a lot easier than trying to deal with setting breakpoints.
To get to the debugger's REPL, just type 'repl' at the debugger prompt.
VERY IMPORTANT NOTE: to get out of the debugger REPL and back to the
debugger prompt, type 'ctrl-c' at the REPL prompt. The command-line
debugger is modal, which means that you can't use debugger commands in
the REPL and vice versa.
OTHER IMPORTANT NOTE: The debugger REPL is not as safe as one might
hope. Every variable that was in scope at the line where execution was
paused is visible to the REPL, which is sometimes the only way to see
what's going on inside a closure. However, *sometimes* (and it's not
always obvious when), trying to evaluate a variable in the REPL will
lock up the debugger so hard you have to kill the process from the
outside. This doesn't mean anything is wrong with your program, but it
does mean that you'll have to come up with another way of getting at
the information you want.
Another useful tip is that running `kill -SIGUSR1 <process id>` to a
node process will put it in debugger mode, so you can run `node debug
-p <process id>` on it from the outside. Think hard before doing this
against processes in production, though, because the Node debugger is
not super safe.
//Exercise 11
If you're going to be spending a lot of time debugging a single
problem, or if you're not comfortable with command-line tools, you can
try `node-inspector`. It's much more heavyweight and slower to start
than using the built-in debugger, so it's not as convenient if you're
jumping in and out of a test case many times a minute.
On the other hand, if you're familiar with Chrome's Dev Tools
interface, you'll feel right at home, because node-inspector uses
the Dev Tools UI to drive the V8 remote debugger API (in fact,
node-inspector requires you to use Chrome or Opera, because it
depends on the Blink rendering engine). It still has some of the same
weirdness about setting breakpoints as the built-in debugger, but it
has a *much* more interactive UI and is a lot easier to use as an
exploratory tool than the debugger REPL.
NOTE: if, when using the debugger, it appears to hang, things can
often be fixed by simply shift-reloading the debugger's tab in Chrome.
It is sometimes all too easy to scramble the inspector enough that
you'll need to reload.
//Exercise 12
Node is a garbage-collected language, but that doesn't mean that it
doesn't leak resources. In fact, badly-written Node programs can
leak an astounding amount of memory. Figuring out where all that
memory can be a pretty major project. Turning on `--trace-gc` will
tell you many informative things about how the garbage collector
operates in practice, but aside from telling you at a very coarse
level whether your process's memory usage is growing over time, it's
not very useful.
The single best tool for capturing information about what's going
on with a Node process's memory is the heapdump package. It needs to
be explicitly included in your app, but once it's in there, you can
capture a snapshot of the heap either programmatically from you code,
or (similarly to the debugger) send the process SIGUSR2 using `kill
-SIGUSR2 <process id>`.
What do you do with those heapdumps? Since they're snapshots of the V8
heap, you just load them up in the Chrome Developer Tools, by going
to the Profiles tab, right-clicking in the tab pane, and selecting
"Load profile...". The UI is semi-self-explanatory. If you load two
snapshots, you can see the diff between them.
The best rule of thumb for gathering heap snapshots is to wait to
capture the first snapshot until the app has been running a few
minutes, so that all of the program code has loaded, the JIT has had
a chance to stabilize, and the process is in its steady operational
state. You want to capture a few heaps, because over time there
will be a fair amount of variance as the garbage collector runs.
Interpreting heap snpshots (especially when diffing them) is a bit of
a black art, and there's no substitute for practice.
By the time you've made it this far, though, you've already mastered a
few arcane arts, so you should be used to this by now, no?
//Exercise 13
gdb, and its next-generation descendent, lldb, are versatile, mature
tools that are also kind of terrible. However, when you need them,
there isn't really a good substitute, so here's how you do it when you
need to.
There is one common use case for gdb all with Node: your code triggers
a failure in one of the assertions in Node's C++ layer. In that case,
here's what you run:
gdb `which node`
run path/to/command.js <and> <other> <args>
...time passes, node crashes...
thread apply bt all
or for lldb:
lldb `which node`
run path/to/command.js <and> <other> <args>
bt all
This will give you a set of backtraces for all the active threads in Node
at the time the program crashed, which may be useful to Node developers
experienced with Node's C++ internals.
If you have coredumps turned on on your system (on most Unix systems,
this is done by running `ulimit -c unlimited` as the user that's going
to be running the process, and check your system's documentation for
where core files are stored), you can call process.abort() to cause
your Node process to dump core. The nice thing about core files is
that they support postmortem debugging: as long as you have the binary
for the version of node that crashed, and the coredump itself, you can
continue to poke around inside the core file.
A sad thing about GDB is that it will only play nice with Node if you
have a custom build of a recent version of Node that has support for
gdb / lldb explicitly built into it. You'll need to configure your Node
binary like so:
./configure --gdb --without-snapshot --debug
Using a binary debugger with a JIT is pretty tricky, but the V8 team
has anticipated this use case, and if you run your node processes with
the options `--gdbjit --gdbjit-full`, you'll get much more usable
stacktraces in both gdb and lldb. Do it like so (run from the root
directory of the Node build):
gdb -d lib/ -d src/ --args ./node \
--gdbjit --gdbjit-full /path/to/app.js
If you have access to a SmartOS vm, SmartOS's low-level debugger, mdb,
has recently been taught how to read core dumps from Linux. mdb is a
much more powerful and better-designed debugger than gdb / lldb, but
it is at least as challenging to learn, and the number of people who
have mastered it is probably in the low double figures.
// Exercise 2 scenario.js
/*Replace the comments in the following program (which you can
save as scenario.js) with the relevant calls to the console API:*/
// scenario.js
var fs = require("fs");
var peach = function (obj) {
// trace the message "traced"
// dump obj to stdout
console.log(obj);
console.trace('traced')
};
var bowser = function (callback) {
fs.readFile(process.argv[2], {encoding : "utf8"}, callback);
};
var koopa = function (error, file) {
// handle error by printing something to stderr
if (error) {
console.error(error);
return;
}
peach(JSON.parse(file));
};
bowser(koopa);
/*Node includes some basic functions for output, not all of which are
well-known:
console.log(arguments): print to standard output
console.error(arguments): print to standard error
Two things to know about these functions:
1. You can pass as many comma-separated parameters to them as you
like, and the results will be printed separated by spaces.
2. The parameters to the call are passed to Node's util.format(),
so you can use %s (for strings), %d (for numbers), and %j (for
objects, passed through JSON.stringify()), just as you would
in a call to util.format().
For debugging, there are a few more useful methods:
console.trace(label): dump stacktrace at line trace is called, with label
console.time(label) / console.timeEnd(label): quick & dirty benchmarking
console.assert(expression, arguments): assert that expression is true
console.dir(object): call util.inspect() on `object`, print results
In day-to-day debugging, console.error, console.dir and console.trace
are the most useful of these functions. They will give you the why,
the what, and the where without requiring a bunch of extra effort.*/
//Exercise 3 filename.js
/*1. Install jshint (`npm install --global jshint` – maybe with sudo on
Linux, probably logged in as an administrator on Windows)
2. and use it
to figure out and fix what's wrong with this program (which has the
filename <filename.js> below):
today = 'today';
console.log('date is', timestamp());
console.log('today is', today);
function timestamp() {
today = Date();
return today;
}
3. Put it :
{
"node": true,
"undef": true
}
in a file named jshintrc, and then run jshint with
`jshint --config jshintrc <filename.js>`
*/
today = 'today';
console.log('date is', timestamp());
console.log('today is', today);
function timestamp() {
today = Date();
return today;
}
//Exercise 3
//You can start with this config file for jshint:
{
"node": true,
"undef": true
}
//Exercise 4
/*Here is a program with a problem:
module.exports = scenario;
function scenario(log, cb) {
function start() {
process.nextTick(thing);
}
var value = 97;
function foo() {
value *= 13;
cb(value);
}
start();
function racer() {
value &= 255;
setTimeout(foo, 0);
}
value = 213;
function thing() {
value += 131;
process.nextTick(racer);
}
}
Here is how to attack the problem using logging to debug:
1. It gets passed a logger (with at least `log.info()` and
`log.error()` functions defined) and a callback.
2. When things are working, `cb` should be called at the end with
the value 2964. There is something iffy with the operations
applied to the value. The program can be fixed by removing one
line.
3. Log an object containing the value of value and the currently
active function *after* EACH time `value` is assigned or changed.
Each call should look like this:
// "scenario" is the name of the currently executing function
log.info({value : value}, "scenario");
4. When you figure out what the error is, make a call to
log.error() indicating what the problem is *before* logging
what `value` is at that point once you've fixed things. You'll
want to keep the existing call to log.info:*/
module.exports = scenario;
function scenario(log, cb) {
function start() {
process.nextTick(thing);
}
var value = 97;
log.info({ value: value }, 'scenario');
function foo() {
value *= 13;
log.info({ value: value }, 'foo');
cb(value);
}
start();
function racer() {
value &= 255;
log.info({ value: value }, 'racer');
setTimeout(foo, 0);
}
//value = 213;
log.error({ value: value }, "value changed outside function");
log.info({ value: value }, "scenario");
function thing() {
value += 131;
log.info({ value: value }, 'thing');
process.nextTick(racer);
}
}
/*5. Here is a sample runner that will inject a Bunyan logger into your
sample program and prints JSON log output you can pipe through bunyan
like so: `node bunyan-runner.js scenario.js | bunyan`
var resolve = require("path").resolve;
var bunyan = require("bunyan");
var log = bunyan.createLogger({name : "sample"});
var scenario = require(resolve(process.cwd(), process.argv[2]));
scenario(log, function (value) {
log.info("value at finish is", value);
});
As a hint, you should be making 5 info logging calls and 1 error logging
call.
Using Bunyan to test your solution as you go is pretty easy:
var bunyan = require("bunyan");
var log = bunyan.createLogger({name: "scenario"});
Then, when you run your program, pipe the output through the Bunyan CLI:
node my-scenario-runner.js | bunyan*/
/*
(As a side note, if you've never read The Twelve-Factor App
Manifesto, now is a good time. It has a very different take on
how logs should work, although the underlying principles are
similar: http://12factor.net/logs)
Most good logging frameworks share a few principles in common:
1. Each entry has a consistent format.
2. Each loggable event maps to a single log entry.
3. The log entries are guaranteed to be recorded in the order in which
they occurred.
4. There are multiple levels at which you can log, so you can choose
the level of granularity that suits your current level of interest
(are you running in production? Debugging a new configuration?
Troubleshooting a complex or confusing function?).
5. A single stream of log events should be collected from multiple
sources and stored in a single place.
6. You should be able to browse the logs using standard tools.
Node has some low-level logging facilities, which we'll get to later,
but they're intended for use by the developers of the core Node
platform. In general, the Node world has settled on newline-delimited
JSON objects for logging. bunyan is the established favorite, although
the much newer bole is gaining popularity quickly.
To install bunyan, do `npm install --global bunyan` (maybe with sudo on
Linux, probably logged in as an administrator on Windows).*/
//Exercise 5
/*run `npm install stackup`, and then in your
program, add `require('stackup')` at the top
As an example, what happens when you run this program with bad input?
var readFile = require("fs").readFile;
module.exports = scenario;
function scenario(jsonPath, cb) {
readFile(jsonPath, {encoding : "utf8"}, function (error, contents) {
cb(error, JSON.parse(contents));
});
}
The challenge here is to figure out how to get a stacktrace that shows
the bug, and to get the long stacktrace to the verifier by passing the
Error you get to the callback. You will probably need to use either
domains or the trycatch module, because a simple try / catch won't
work. If you don't know domains, read the Node API documentation on
them, or use this brutally abbreviated primer:
var domain = require("domain");
function doSomethingDangerousAndAsync(cb) {
// create a new domain
var d = domain.create();
// "handle" the error (OMG DON'T DO THIS IN PRODUCTION CODE)
d.on("error", cb);
// use the domain
d.run(function () {
doDangerousAsyncThing(cb);
});
}
*/
require('stackup');
var readFile = require("fs").readFile;
var domain = require("domain");
module.exports = scenario;
function scenario(jsonPath, cb) {
var d = domain.create();
d.on('error', cb);
d.run(function () {
readFile(jsonPath, { encoding: "utf8" }, function (error, contents) {
cb(error, JSON.parse(contents));
})
});
}
//Exercise 7
/*Frequently, it's useful to write a set of test cases to exercise all
the edge cases of your program. The following example is contrived,
but it shows the basic pattern. The function being examined is
`isGreaterThanZero()`, which there are a series of test cases for, some
of which currently fail.
The module code below gets passed a tape test object by the
verifier, so you don't need to call t.end(). As mentioned above,
`isGreaterThanZero()` has something wrong with it (it shouldn't be too
hard to figure out, but you still need to fix it):
module.exports = scenario;
function scenario(t) {
t.ok(isGreaterThanZero(Infinity), 'Infinity is greater than 0')
t.ok(isGreaterThanZero(1), '1 is greater than 0')
t.notOk(isGreaterThanZero(0), '0 *is* 0, not greater than 0')
t.notOk(isGreaterThanZero(-0), 'why does -0 exist')
t.notOk(isGreaterThanZero(-1), '-1 is definitely not greater than 0')
t.notOk(isGreaterThanZero(-Infinity), '-Infinity is definitely not greater than 0')
function isGreaterThanZero(value) { return value >= 0 }
}*/
module.exports = scenario;
function scenario(t) {
t.ok(isGreaterThanZero(Infinity), 'Infinity is greater than 0')
t.ok(isGreaterThanZero(1), '1 is greater than 0')
t.notOk(isGreaterThanZero(0), '0 *is* 0, not greater than 0')
t.notOk(isGreaterThanZero(-0), 'why does -0 exist')
t.notOk(isGreaterThanZero(-1), '-1 is definitely not greater than 0')
t.notOk(isGreaterThanZero(-Infinity), '-Infinity is definitely not greater than 0')
function isGreaterThanZero(value) { return value > 0 }
}
// Exercise 7 scan-client.js
/*To show you how it works, here's a simple HTTP client that has
something wrong with it:
// scan-client.js
var request = require("http").request;
var contentType = "text/html";
var body = "<html>" +
"<head><title>hi</title></head>" +
"<body><p>yo</p></body>" +
"</html>";
var headers = {
host : "localhost",
port : 9876,
method : "GET",
headers : {
"content-type" : contentType,
"content-length" : body.length,
"requested-by" : "Request™"
}
};
var yolo = request(headers, function (res) {
res.setEncoding("utf8");
res.on("data", function (data) {
console.log("BODY: " + data);
});
res.on("end", function () {
console.error("done!");
});
});
yolo.end();*/
var request = require("http").request;
var contentType = "text/html";
var body = "<html>" +
"<head><title>hi</title></head>" +
"<body><p>yo</p></body>" +
"</html>";
var headers = {
host : "localhost",
port : 9876,
method : "GET",
/*headers : {
"content-type" : contentType,
"content-length" : body.length,
"requested-by" : "Request™"
}*/
};
var yolo = request(headers, function (res) {
res.setEncoding("utf8");
res.on("data", function (data) {
console.log("BODY: " + data);
});
res.on("end", function () {
console.error("done!");
});
});
yolo.end();
// Exercise 7 scan-server.js
//And here's a simple server to test it against:
/*If you run this server with `NODE_DEBUG=http node scan-server.js`,
it will show you what's going on with the server, when you test it with
the buggy `node scan-client.js`. You can also see an example
server run by running `bug-clinic run scenario.js` -- it will be the
text at the top of the output run.
Overall, it would make sense to do this with 3 separate terminal sessions :
1. node server.js
- this is the process you're debugging : get its PID with
(`ps fax | grep node` in Linux, for instance).
2. curl http://localhost:9999/XYZ
- stimulates the server to do something
3. jstrace -p <server-pid> watcher.js
- gives you the jstrace messages
*/
// scan-server.js
var createServer = require("http").createServer;
var server = createServer(function (req, res) {
res.end("hello");
});
server.listen(9876, function () {
console.log("listening");
});
// Exercise 8
/*You should be able to start your server, run `jstrace -p <server-pid>`
with the tracer script below, and see the status codes and URLs
being printed to the terminal as you hit your server with curl:
// watcher.js
module.exports = {
local : function (traces) {
traces.on("request:start", function (trace) {
console.log(trace.url);
});
traces.on("request:end", function (trace) {
console.error(trace.statusCode);
});
}
};
*/
module.exports = {
local : function (traces) {
traces.on("request:start", function (trace) {
console.log(trace.url);
});
traces.on("request:end", function (trace) {
console.error(trace.statusCode);
});
}
};
//Exercise 8
/*To install jstrace, run `npm install --global jstrace` (maybe with sudo
on Linux
So! Let's see how this works! Write a web server instrumented using
jstrace. The server should listen on port 9999 and return one of
two responses. When it gets a GET response to /prognosis, it should
return a status code of 200 and a payload of '{"ok":true}'. For ALL
other requests, it should return a status code of 404 and a payload
of '{"error":"notfound"}'. It should also print the message "up" to
standard error when it's listening, so the verifier knows it's ready
for requests.
The basic syntax of a `jstrace` call is `jstrace(signal, data)`, where
signal is the string name of the signal you're sending, and the data
is a JSON object with the data you'd like to pass back.
Your server ('server.js', for instance) should include two jstrace
probes:
1. At the beginning of the response handler, "request:start", with
a payload object that includes the URL of the request (as "url");
2. Immediately after calling `res.end()` to send the response body,
"request:end", with a payload object that includes the HTTP status
code as "statusCode", and the response body (as a JavaScript
object) with the name "body".*/
const summary = require('server-summary')
const trace = require('jstrace')
const http = require('http')
const url = require('url')
const server = http.createServer((req, res) => {
trace('request:start', { url: req.url })
res.setHeader('content-type', 'application/json')
var body = null
if (url.parse(req.url).path === '/prognosis') {
res.statusCode = 200
body = { ok: true }
} else {
res.statusCode = 404
body = { error: 'notfound' }
}
res.on('finish', function () {
trace('request:end', { statusCode: res.statusCode, body: body })
})
res.end(JSON.stringify(body))
})
server.listen(9999)
//Exercise 9
/**To install these modules, you'll need to `npm install replify` and
`npm install replpad` respectively.
If you really want to go through the wormhole to a magical world of
live application introspection, you can *combine replify and replpad*:
// in your application
var replify = require("replify");
var replpad = require("replpad");
var server = require("http").createServer(function (req, res) {
res.end("hello");
});
replify({name : "hello-server", start : replpad}, server);
server.listen(1234, function () {
console.log("listening");
});
Once you start that server, install `repl-client` and connect to the
running service:
rc /tmp/repl/hello-server.sock
// on Windows: rc \\.\pipe\tmp-repl\hello-server.sock
and you'll get connected to the replify'd replpad, where you can
type `app` and get the current state of your HTTP server! Whatever
object you pass to the call to replify is the `app` context in the
REPL, so you can pass it a database connection pool or HTTP agent for
making outbound requests and easily see the state of the service,
interactively, in realtime. MAGIC.
*/
//Exercise 9
/*Write a module that exports a function that takes
a callback, starts an HTTP server on port 8080 (that can reply with
whatever). The function should also use replify (and replpad, if you
feel like it) to expose an object that contains a property named
"__message" with the value "REPLs are neat" in its second argument.
The REPL should be named "bug-clinic" (include this somewhere in the
first argument). When everything is running, it should call the
callback with the server and the replify instance as arguments.
The function should look something like the following:
module.exports = scenario;
function scenario(callback) {
var createServer = require("http").createServer;
var server = createServer(// do HTTP response stuff here );
var repl = // do replify stuff here
callback(server, repl);
}*/
module.exports = scenario;
var replify = require("replify");
function scenario(callback) {
var createServer = require("http").createServer;
var server = createServer();
server.__message = "REPLs are neat";
var repl = replify({name : "bug-clinic"}, server);
server.listen(8080, function () { callback(server, repl); });
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment