Taming the dragon: using llnode to debug your Node.js application
If you ever experienced memory leaks or infinite loops in your applications, you know how frustrating can be to find the source of those issues. Even though Node.js has a Garbage Collector powered by V8, it is still possible to have memory leaks (or infinite memory growth) if we keep unnecessary references to objects.
One technique available to investigate those kinds of issues is postmortem debugging. Developers of native languages (such as C++ and Go) might be familiar with it, especially postmortem debugging of core dump files — files with a copy of the process memory at a given time.
Fortunately, we can use this same technique with our Node.js applications! This is possible through llnode: a LLDB plugin which enables us to inspect Node.js core dumps. With llnode, we can inspect objects in the memory and look at the complete backtrace of the program, including native (C++) frames and JavaScript frames. It can be used on a running Node.js application or through a core dump.
It’s dangerous to go alone. Take this!
llnode is available through npm and works on with active Node.js Release Lines (v6.x, v8.x, v9.x and v10.x by the time of this writing). Since it is a plugin for lldb, you'll need to install it first. llnode works best on LLDB 3.9 or later.
On Mac OS you get lldb by installing Xcode. If you’re using Ubuntu though, you can install LLDB by running:
sudo apt install lldb-4.0 liblldb-4.0-devAfter lldb is installed, you can use npm install -g llnode to install llnode globally. Please be aware that if you're not using Node.js through nvm or don't have a global prefix set, you'll need to run sudo install -g llnode.
Generating a core dump
llnode can either attach to a process or read a core dump file. In this tutorial we'll focus on the latter, and because of that we need to first be able to generate core dumps.
There are two main methods to generate core dumps in Unix systems: you can either create a core dump from a running process or create one when the process crashes.
To generate a core dump of a running process, you can use gcore {PID}(Linux) or lldb --attach-pid {PID} -b -o 'process save-core "core.{PID}"' (OS X), replacing {PID} with the PID of your application. Both methods will create a core dump file called core.$PID at the current working directory.
If, however, you want to generate a core dump when your process crashes (useful to debug your application when it dies by memory starvation, for example), you’ll need to set the ulimit of your system by running ulimit -c unlimited. This will set ulimit for the current terminal session, which means you'll need to set again if you open another terminal. Core dumps generated this way are saved in a file named core in the current working directory for Linux, while on OS X cores are stored in the /cores/ folder. Be careful on Mac OS, because core dumps can quickly fill your HD.
Another thing about generating core dumps when your process crashes: Node.js won’t crash when it terminates because of an uncaught exception. If you want to generate a core dump in those cases, you’ll need to run Node.js with --abort-on-uncaught-exception.
Taming the Dragon
Now that we have llnode installed and we know how to generate a core dump let's learn how to use them together. We'll be using a small Node.js HTTP server as an example:
First, let’s run this server:
$ node index.js
server is listening on 3000. Our PID is: 74262To make things interesting, let’s send some requests to this server with autocannon:
$ # Send requests to localhost:3000 during 10 seconds
$ npx autocannon -d 10 localhost:3000Now we’ll generate a core dump of the running process. In this case, the PID is 74262. Remember to change the PID in the commands below with the PID of your Node.js process.
To generate a core dump on Linux, run the following:
$ sudo gcore 74262 If you are on OS X, you can run the following:
$ lldb --attach-pid 74262 -b -o 'process save-core "core.74262"'Both commands will create a core dump in the current working directory with the name core.74262, and now we can use llnode to open it. llnode takes one required argument, which is the binary you want to debug (in this case, node) and a variety of optional arguments. Since we want to debug a core dump, we need to tell llnode where the core dump file is with -c {core-file}. The final command will look like:
$ llnode node -c core.74262
(llnode)Let’s start with a command that prints information about Node.js and its dependencies. This command will also help us understand the syntax of the commands for llnode. On the (llnode) prompt, type v8 nodeinfo and press Enter:
(llnode) v8 nodeinfo
Information for process id 74262 (process=0x1ca4ddb89cb9)
Platform = darwin, Architecture = x64, Node Version = v8.11.2
Component versions (process.versions=0x1ca4b45a0379):
cldr = 32.0
icu = 60.1
tz = 2017c
unicode = 10.0
Release Info (process.release=0x1ca4b45a0451):
Executable Path = /Users/mmarchini/.nvm/versions/node/v8.11.2/bin/node
Command line arguments (process.argv=0x1ca4b45a0411):
[0] = '/Users/mmarchini/.nvm/versions/node/v8.11.2/bin/node'
[1] = '/Users/mmarchini/workspace/blog-posts/index.js'
Node.js Comamnd line arguments (process.execArgv=0x1ca4b45a0579):llnode commands are prefixed by v8 + a space. This will help you distinguish between llnode and lldb commands. Speaking of help, v8 help will be your best friend from now on:
(llnode) v8 help
Node.js helpersSyntax:The following subcommands are supported: bt -- Show a backtrace with node.js JavaScript
functions and their args. An optional
argument is accepted; if that argument is a
number, it specifies the number of frames
to display. Otherwise all frames will be
dumped.
Syntax: v8 bt [number]
findjsinstances -- List every object with the specified type
name. Use -v or --verbose to display
detailed `v8 inspect` output for each
object. Accepts the same options as
`v8 inspect`
findjsobjects -- List all object types and instance counts
grouped by type name and sorted by instance
count. Use -d or --detailed to get an
output grouped by type name, properties,
and array length, as well as more
information regarding each type.
findrefs -- Finds all the object properties which meet
the search criteria. The default is to list
all the object properties that reference
the specified value.
Flags:
* -v, --value expr - all properties
that refer to the
specified
JavaScript object
(default)
* -n, --name name - all properties
with the specified
name
* -s, --string string - all properties
that refer to the
specified
JavaScript string
value
inspect -- Print detailed description and contents of
the JavaScript value.
Possible flags (all optional):
* -F, --full-string - print whole string
without adding
ellipsis
* -m, --print-map - print object's map
address
* -s, --print-source - print source code
for function
objects
* -l num, --length num - print maximum of
`num` elements
from string/array
Syntax: v8 inspect [flags] expr
nodeinfo -- Print information about Node.js
print -- Print short description of the JavaScript
value.
Syntax: v8 print expr
source -- Source code informationFor more help on any particular subcommand, type 'help <command> <subcommand>'.
Yes, there’s a lot of information there. But don’t worry, we’ll go through the interesting commands now.
v8 findjsobjects
v8 findjsobjects lists all object types alongside their sizes and quantities. This is useful to find out which object types are using most of your memory. The first time you run this command might take a few minutes to process, so don't worry if that happens.
(llnode) v8 findjsobjects
Instances Total Size Name
---------- ---------- ----
1 24 AssertionError
1 24 AsyncResource
1 24 Control
1 24 FastBuffer
1 24 Loader
1 24 ModuleJob
1 24 ModuleMap
1 24 Performance
1 24 PerformanceObserver
1 24 SafeMap
1 24 SafePromise
1 24 SafeSet
1 24 SocketListReceive
1 24 SocketListSend
1 24 TextDecoder
1 24 TextEncoder
1 24 URL
1 24 URLContext
1 24 URLSearchParams
1 24 WebAssembly
1 32 (Object)
1 32 ContextifyScript
1 104 ImmediateList
1 104 Stack
1 128 Server
1 168 Agent
2 48 (anonymous)
2 48 process
2 64 ChannelWrap
2 64 Signal
2 120 Resolver
2 128 PerformanceNodeTiming
2 136 NextTickQueue
2 144 FreeList
2 200 PerformanceObserverEntryList
2 208 EventEmitter
2 208 WriteStream
2 224 Console
2 272 Module
3 72 NodeError
3 96 TTY
3 280 AsyncHook
4 128 Timer
6 432 TimersList
10 2480 Socket
11 352 HTTPParser
11 352 WriteWrap
12 384 TCP
12 2688 WritableState
15 1360 (ArrayBufferView)
74 4736 NativeModule
5715 1234440 IncomingMessage
5744 781184 ServerResponse
5747 1103424 ReadableState
5748 275880 BufferList
45980 2942680 TickObject
69344 2219008 (Array)
235515 9420584 Visit
293720 15437744 Object
615411 3750984 (String)
---------- ----------
1283140 37182200If we look at the output, we'll see a lot of Visit objects generated by our autocannon run. We'll also see Visit is the third type using more memory. In a real case scenario, this information is the first step to track down memory leaks.
There’s also a detailed version of this command which can be called with v8 findjsobjects -d. The result will group types with the same attributes and number of elements, and will also provide the address to an example object of that type.
v8 findjsinstances
v8 findjsinstances gives you a list with all objects of a given type. It also has a detailed version which can be called with v8 findjsinstances -d. This will print all objects of a given type with their attributes and elements.
(llnode) v8 findjsinstances -d Visit
0x0000176d04402201:<Object: Visit properties {
.visit_id=<Smi: 82704>,
.headers=0x0000176d7d99f1c9:<Object: Object>}>
0x0000176d04402229:<Object: Visit properties {
.visit_id=<Smi: 82705>,
.headers=0x0000176d7d99f191:<Object: Object>}>
0x0000176d04402251:<Object: Visit properties {
.visit_id=<Smi: 82706>,
.headers=0x0000176d7d99f159:<Object: Object>}>
0x0000176d04402279:<Object: Visit properties {
.visit_id=<Smi: 82707>,
.headers=0x0000176d7d99f121:<Object: Object>}>
0x0000176d044022a1:<Object: Visit properties {
.visit_id=<Smi: 82708>,
.headers=0x0000176d7d99f0e9:<Object: Object>}>
0x0000176d044022c9:<Object: Visit properties {
.visit_id=<Smi: 82709>,
.headers=0x0000176d7d99f0b1:<Object: Object>}>
// A thousand miles later...
0x0000176dffba62d9:<Object: Visit properties {
.visit_id=<Smi: 156026>,
.headers=0x0000176dffbef559:<Object: Object>}>
0x0000176dffba6301:<Object: Visit properties {
.visit_id=<Smi: 156027>,
.headers=0x0000176dffbef8a9:<Object: Object>}>
0x0000176dffba6329:<Object: Visit properties {
.visit_id=<Smi: 156028>,
.headers=0x0000176dffb82481:<Object: Object>}>v8 findjsinstances -d accepts the same arguments you can pass to v8 inspect, which we will see next.
v8 inspect
v8 inspect prints all attributes and elements of a given object. It can also print additional information, such as the address to the object's map. If you want to see the object's map address, you should run v8 inspect -m. You can inspect the map like any other object by using v8 inspect.
(llnode) v8 inspect -m 0x0000176dffba6329
0x0000176dffba6329(map=0x0000176d689cec29):<Object: Visit properties {
.visit_id=<Smi: 156028>,
.headers=0x0000176dffb82481:<Object: Object>}>
(llnode) v8 inspect 0x0000176d689cec29
0x0000176d689cec29:<Map own_descriptors=2 in_object_size=2
instance_size=40
descriptors=0x0000176d7f284569:<FixedArray, len=8 contents={
[0]=<Smi: 2>,
[1]=<Smi: 0>,
[2]=0x0000176dd8566a11:<String: "visit_id">,
[3]=<Smi: 320>,
[4]=<Smi: 1>,
[5]=0x0000176dd8566a31:<String: "headers">,
[6]=<Smi: 1050112>,
[7]=0x0000176d117509f9:<unknown>}>>v8 findrefs
Now we know how to find which types are using a huge amount of memory, how to find objects of those types and how to inspect attributes of those objects. But if we want to find memory leaks, we'll need to find what's keeping those objects in the memory. In other words, we need to find other objects referencing them. There's a command perfect for that: v8 findrefs. This command will return all objects referencing another object. Let's give it a try:
(llnode) v8 findrefs 0x0000176dffba6329
0x176d1f4fac41: (Array)[156027]=0x176dffba6329The result shows us that there's an array holding a lot (156027) of objects, and is probably the reason we have so many Visit objects in memory (spoiler: it is, look at line 13 and 16 of our server). Unfortunately, llnode can't tell where this array is located yet, but there's an open issue to add this feature in the future.
Conclusion
Even with a limited set of features, llnode is a powerful debugging tool to have on our Node.js Diagnostics arsenal. It’s ability to inspect the state of an application right after it crashed and the lightweight nature of core dumps can help us identify memory issues with less effort when compared to traditional tools. It also makes llnode and core dumps a good fit to be used on production environments.
