Programming language debuggability

A few weeks ago I had the fortune to attend a talk by Douglas Crockford on various ideas related to JavaScript past and future and programming language design. The talk was thoughtful and well-received (and thanks to Crockford and Bigcommerce for making it happen!). The main theme, not new to those familiar with Crockford’s work, was that as programmers, we have a responsibility to create bug-free programs; and that therefore when faced with choices about which language features to use, we should always choose the safest ones — that is, we should always avoid the features that can sometimes be used unsafely when a safer feature is available.

On the surface, this seems like a no-brainer. This is the principle behind linters and other static analyzers, including Crockford’s own JSLint. (My favorite is still the less popular javascriptlint.) I try to lint just about all of the JavaScript I write not just before committing it, but each time I run it, because I find so often even while writing small chunks of new code I can easily wind up with super subtle bugs that take a while to debug but lint can catch quickly.

But while static analysis is enormously valuable, it’s not the only consideration for software developers. There are basically two paths for writing bug-free software:

  1. Write bug-free code the first time.
  2. Write good code, then test it, then find the bugs, and then fix the bugs.

This also sounds like a no-brainer, but it actually suggests something different from Crockford’s advice. Linters and static analysis are part of path 1: they attempt to find and fix well-known bugs before the program ever runs. That’s terrific, but it’s incomplete. Lint cannot verify that a chunk of reasonable code correctly implements what the programmer intends. There are always problems you don’t discover until you at least run the code (and in most cases, there will be problems you don’t discover until long after you’ve started running the code in production).

Path 2 accepts that many bugs won’t be found until you run the code, and for that reason making choices about code debuggability should be at least as important as choices about code safety. Some constructs are intrinsically more debuggable than others. JavaScript closures are great, but they do have a debuggability problem: even if you had a debugging oracle that you could use to show you any variable in your program while the program was running (which we basically do), how does the developer even express to the debugger what variable they’re interested in? When variables are referenced by closures and not by any globals, there’s no unique global name for it. It’s important to realize that this is an intrinsic challenge with closures in JavaScript, not a problem with some particular debugger.1 (That doesn’t mean you should never use closures, but this consideration can inform their use. For example, if there’s any state I want to be able to see in the debugger, I make sure it’s not just referenced by the closure, but is also hanging off some object I can find from the debugger.)

Another example of this came up later in Crockford’s talk, when he revealed that he no longer uses new or even Object.create, but instead defines classes using a normal function (not really a constructor) using local variables for instance state and closures to reference that state. Here’s an example (this is my interpretation, not his code):

function mypoint(args)
{
    var x = args.x;
    var y = args.y;

    return ({
        'getX': function () { return (x); },
        'getY': function () { return (y); },
        'setX': function (newx) { return (x = newx); },
        'setY': function (newy) { return (y = newy); }
    });
}

There are advantages to this style. You can avoid all the nastiness associated with this, and you can implement strong data hiding. But it has important downsides for debuggability. First, we have the closure problem we talked about earlier: given that you’ve got your program open in the debugger, how do you find a particular Point object? Supposing you do find one, how do you see what “x” and “y” actually are?

But there’s a deeper, subtler problem. Many JavaScript programs run into issues with memory usage (or leaks), and the first piece of information you typically want to debug an issue like that is a report of how many of each kind of object you have. But assuming you had a debugger that could do that, without a constructor name and without any non-function properties, how would you group objects in a way that’s useful for the developer?

Similar to the way there are language features to prefer in the name of safety, there are patterns to prefer to improve debuggability. It helps to name all functions, for example. Even inline functions. This makes stack traces more readable, and it also enables the debugger to tell you that you’ve created 800,000 closures of function “authenticateRequest” instead of “(anon) from file server.js line 37″.

These are just basic examples. I’d love to see the issue of programming language debuggability play a more significant role in discussions about programming language design and in selecting the good parts of a language. With a programming language built for debuggability and first-class tools to take advantage of it, there’d be even more to gain from developers investing time to build, learn, and use tools to help find bugs in code while it’s running or after it’s been run. And that’s how we fulfill our obligation to build bug-free software: not by writing perfect code, but by finding and fixing the bugs.


1 We addressed this problem in MDB by letting you search for objects by property names, but it’s still far easier if you can find relevant state through a singleton global object than if you have to wade through all objects with a common property like “hostname”.

Debugging enhancements in Node 0.12

(also on the Joyent blog)

Background

Node.js provides the richest postmortem debugging facilities of just about any dynamic language. Postmortem debugging refers to debugging programs from a core file, heap dump, or some similar dump of memory. With a core file of a Node program (which is essentially a snapshot of your program’s state), you can:

  • Find all JavaScript objects and classify them by their properties. This is very useful for identifying large memory leaks.
  • Find JavaScript objects by their constructors or properties and print them out.
  • Enhanced in 0.12: Print a stack trace of where the program was when the core file was created. (If you’re generating a core file on crash, this is the stack where the program crashed.) Unlike the stack you get when a Node program normally crashes, this stack includes function arguments. In 0.12, by default the printed stack trace is much friendlier, and it also contains the “this” argument for each function.
  • New in 0.12: Find all of the JavaScript closures that have been created. Closures can be a major source of memory leaks, so identifying which functions have created lots of closures helps find memory leaks.
  • New in 0.12: Find the chunk of native memory that’s being used for a given Node Buffer. When Buffers make up a large percentage of memory used in your program, this can help identify what they’re storing.
  • New in 0.12: Find the C pointer for a given V8 “internal” field. This is mostly interesting for add-on developers.

The postmortem approach has several advantages over other debugging techniques:

  • It doesn’t require any runtime overhead.
  • It’s comprehensive. A core file is a complete snapshot of your program. If there’s something missing, you can add it by just storing it in your program.
  • In production, when you find a program behaving badly, you can save a core file and then immediately restart the program. This often fixes the problem, restores service, and still enables you to debug the problem after the fact.
  • Because all the debugging is offline (i.e., the program is not suspended), debuggers can use sophisticated (but expensive) analysis techniques like the ones mentioned above.

You can save core files of running programs using gcore(1) on most systems, and you can configure Node to generate a core file when it crashes using the --abort-on-uncaught-exception flag. Although MDB only runs on illumos-based systems (like SmartOS), it can read core files from GNU/Linux systems as well.

Changes in v0.12

If this is the first you’ve heard of debugging Node from core files, you’ll want to check out the Node.js MDB intro. The rest of this post is just a summary of changes.

These changes are part of the debugger module that ships with Node 0.12, but you can use this module on core files from versions of Node as far back as 0.4. So you can use these features today before even upgrading your programs to use Node 0.12.

Streamlined ::jsstack

In previous versions, ::jsstack‘s default output includes a lot of information that’s not relevant for JavaScript-only problems and is frequently overwhelming for new users. After these changes, it hides internal frames, frame pointers, and instruction pointers by default. It also chops long C++ symbol names to fit lines at 80 columns.

Before:

> ::jsstack
8043190 0xb4e1a5ee MyObject (ba780b15)
80431b4 0x94e0fba9 <ConstructFrame>
80431c8 0xb4e1096c <anonymous> (as <anon>) (ba7b3d59)
8043200 0x94e645bf <anonymous> (as EventEmitter.emit) (93f24ad9)
804321c 0x94e0f7a1 <ArgumentsAdaptorFrame>
8043240 0xb4e0f9c0 <anonymous> (as parser.onIncoming) (92609b45)
804327c 0xb4e0c9f3 parserOnHeadersComplete (ba7917e9)
804329c 0x94e0fe19 <InternalFrame>
80432d8 0x94e0a0aa <EntryFrame>
8043348 _ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0_6ObjectEEEiPS5_Pb+0xef
...
8047c98 uv_run+0xea
8047d08 node::Start+0x17b
8047d28 main+0x1b
8047d40 _start+0x83

After:

> ::jsstack
js:     MyObject
        (1 internal frame elided)
js:     <anonymous> (as <anon>)
js:     <anonymous> (as EventEmitter.emit)
        (1 internal frame elided)
js:     <anonymous> (as parser.onIncoming)
js:     parserOnHeadersComplete
        (1 internal frame elided)
        (1 internal frame elided)
native: _ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0...
...
native: uv_run+0xea
native: node::Start+0x17b
native: main+0x1b
native: _start+0x83

You can get the full native details with “-a” (for “all frames and information”).

this pointer and constructor names in ::jsstack -v output

::jsstack -v now includes the this pointer. Also, when it prints out object pointers (for this as well as function arguments), they include the constructor name.

Before:

> ::jsstack -vn0
8043190 0xb4e1a5ee MyObject (ba780b15)
    file: /root/example.js
    posn: position 62
80431b4 0x94e0fba9 <ConstructFrame>
80431c8 0xb4e1096c <anonymous> (as <anon>) (ba7b3d59)
    file: /root/example.js
    arg1: ba7ceb01 (JSObject)
    arg2: ba7cf781 (JSObject)
    posn: position 595
...

After:

> ::jsstack -vn0
js:     MyObject
          file: /root/example.js
          posn: position 62
        (1 internal frame elided)
js:     <anonymous> (as <anon>)
          file: /root/example.js
          posn: position 595
          this: ba7b3d7d (JSObject: Server)
          arg1: ba7ceb01 (JSObject: IncomingMessage)
          arg2: ba7cf781 (JSObject: ServerResponse)
...

New dcmd: ::jsconstructor: print constructor of a JavaScript object

Given an object, you can print the constructor that was used to create it:

> ba7ce109::jsconstructor
SlowBuffer

> ba7ce781::jsconstructor
Object

> ba7cdb75::jsconstructor
HTTPParser

With “-v”, the command prints out a pointer to the constructor function:

> ba7b3d7d::jsconstructor -v
Server (JSFunction: ba791bbd)

which is useful for passing to ::jssource (see next).

New dcmd: ::jssource: print source for a JavaScript function

Given a function, you can print the source code for it:

> 88a21d0d::jssource -n1
file: http.js

 1963
 1964   socket.addListener('error', function(e) {
 1965     self.emit('clientError', e, this);
 1966   });
 1967

This closure is an instance of the anonymous function defined inline.

New dcmd: ::nodebuffer: fetch native pointer for a buffer

When debugging memory leaks using ::findjsobjects, you may find that you have a ton of Buffer objects. These represent chunks of memory from the native heap. You often want to know what that memory contains. With the ::nodebuffer command, you can take one of these Buffers:

> b1a9ec5d::jsconstructor
Buffer

> b1a9ec5d::jsprint
{
    "length": 1423,
    "parent": {
        "length": 8192,
        "used": 7272,
    },
    "offset": 0,
}

and get a pointer to the underlying C memory:

> b1a9ec5d::nodebuffer
8db8c08

Then you can use ::dump (for example) to see what that memory actually contains:

> 8db8c08,0t64::dump
           0 1 2 3  4 5 6 7 \/ 9 a b  c d e f  01234567v9abcdef
8db8c00:  08200000 f89f103a 00000007 6f707469  . .....:....opti
8db8c10:  6f6e7300 00000468 65616400 00000470  ons....head....p
8db8c20:  6f737400 00000370 75740000 00066465  ost....put....de
8db8c30:  6c657465 00000005 74726163 65000000  lete....trace...
8db8c40:  06616363 65707400 00000e61 63636570  .accept....accep

This often points you to a particular HTTP request handler or other code path in your program.

New dcmd: ::jsfunctions: list closures

findjsobjects is very helpful for identifying classes of objects with many instances. Once you’ve found which objects are being leaked, you can use findjsobjects -r to find out which objects reference the leaked one. Sometimes memory is not referenced by other objects, but rather by closures: JavaScript functions that are pending and may be invoked some time in the future. The new jsfunctions command lists all functions in your JavaScript program, and how many different closures have been created for each one:

> ::jsfunctions
    FUNC   #FUNCS NAME                                     FROM
...
8803e63d     1667 <anonymous> (as parser.onIncoming)       http.js position 58040
880389c5      543 <anonymous> (as <anon>)                  _stream_readable.js position 26340
88038921      543 <anonymous> (as <anon>)                  _stream_writable.js position 8134
880388d5      543 <anonymous> (as cb)                      _stream_writable.js position 5923
8800be75      587 <anonymous> (as <anon>)                  /home/dap/demo/restify-ex.js position 616
8800be35     2114 _ifError                                 /home/dap/demo/node_modules/restify/lib/server.js position 2846
8800b229      691 <anonymous> (as <anon>)                  net.js position 12228
880099a1     1755 <anonymous> (as <anon>)                  http.js position 55840
8800997d     1755 <anonymous> (as <anon>)                  http.js position 54999
88009939     1696 socketOnDrain                            http.js position 57774
88009915     2234 serverSocketCloseListener                http.js position 54505
880098f1     2234 abortIncoming                            http.js position 54314
88009885     1754 g                                        events.js position 5742
...

You can take one of these functions and print the source. Here’s abortIncoming():

> 880098f1::jssource
file: http.js

 1907 function connectionListener(socket) {
 1908   var self = this;
 1909   var outgoing = [];
 1910   var incoming = [];
 1911
 1912   function abortIncoming() {
 1913     while (incoming.length) {
 1914       var req = incoming.shift();
 1915       req.emit('aborted');
 1916       req.emit('close');
 1917     }
 1918     // abort socket._httpMessage ?
 1919   }
 1920
 1921   function serverSocketCloseListener() {
 1922     debug('server socket close');
 1923     // mark this parser as reusable
 1924     if (this.parser)
 1925       freeParser(this.parser);

Note that it’s defined inside the connectionListener function. This explains why we have 2234 closures for it. Each time connectionListener is called, a new closures of abortIncoming is created to close around socket, self, outgoing, and incoming.

As with findjsobjects, the exact count in the jsfunctions list may be misleading, but large values often reflect memory leaks.

New advanced dcmd: ::v8internal: fetch internal fields

Native code that uses the V8 API (whether part of Node.js itself or part of an add-on) often uses internal fields, which are essentially slots inside an object for storing internal data. For example, Node classes like TcpWrap typically store the underlying libuv handle as internal field 0. So if you have a TCP object, then you can grab internal field 0 to get the underlying libuv handle.

Bug fixes

  • jsprint now quotes property names. (The current approach is simplistic, and the results are not to be confused for valid JSON, but it’s much clearer now than it was, particularly for properties with non-alphanumeric characters.)
  • Several bugs in 64-bit core files, particularly printing out source code using “::jsstack -v” and printing two-byte strings. Both 32-bit and 64-bit core files of Node 0.10 and 0.12 are fully supported. Core files from 0.4 and 0.6 should work as well, but have not been recently tested.
  • Two-byte strings are no longer erroneously truncated.

Stay tuned

We’re working on a few more impressive tools using jsfunctions. Stay tuned
for details!

For help

For help, file a Node issue or reach out to @dapsays, @tjfontaine, or @misterdjules on Twitter. Joyent also offers Nodejs Support that builds heavily on these tools.