DEV Community: mary marchini

Node.js Performance Analysis Without Changing Your Code

mary marchini — Wed, 21 Jun 2023 02:22:10 +0000

Being a Performance Engineer in the Node.js Platform Team at Netflix means I oftentimes have to troubleshoot performance issues in applications my team doesn't own. It's unfeasible to expect all applications to have instrumentation code that allows them to run V8 performance analysis tools (such as CPU Profiles, Heap Profiles and Heap Snapshots), so I wrote a CLI that allows users to run those performance analysis tools without making any changes to their code: @mmarchini/observe. I realized I never wrote anything about this CLI, so this is a lil blog post about it :)

Why

As mentioned before, sometimes you need to troubleshoot an application that is already running. The Inspector Protocol allows you to call V8 troubleshooting tools without making any changes to your application. It's the same protocol used by Chrome DevTools, and it exposes similar troubleshooting features as the ones available on Chrome DevTools. It is, therefore, a powerful protocol.

Unfortunately, using the protocol by itself can be overwhelming for new users. Existing tools that use it are generally aimed at development environments, with either GUIs or REPLs as their only interfaces, which prevents automation.

There are libraries that make usage of the inspector protocol more straightforward, but most libraries I found had to be loaded within the app, therefore requiring code change and a redeploy, which can take time to happen and hinder performance investigation for time sensitive issues.

I also wanted something with as few direct and transitive dependencies as possible. Most packages I found had more dependencies than I wanted.

The closest I found to what I wanted was chrome-remote-interface, which is a great package with few dependencies and a programmatic API that allows users to connect to running applications and run inspector protocol commands on it. It doesn't abstract away the complexities of the Inspector Protocol though, and I wanted something that could be run as a one-liner most of the time.

Since the tools that Node.js/V8 provide for performance analysis via Inspector Protocol are well defined, it seemed like a good use case for a CLI. Its execution mode is somewhat inspired by Java Flight Recorder (but without the need to start an application with specific flags), dtrace, bpftrace, and similar tools. The resulting CLI depends only on ws and commander, which resulted in only two direct and no transitive dependencies. Small install size and lower vulnerability surface area ftw!

Using the CLI

@mmarchini/observe can be installed via your package manager of choice or can be run with npx. I'll be using npx in the examples below as that's my personal preference, but you should use whatever you have available and feel comfortable with.

A list of available commands can be seen by running:

npx @mmarchini/observe --help

Options for each command can be seen by running those commands with --help option:

npx @mmarchini/observe heap-profile --help
npx @mmarchini/observe heap-snapshot --help
npx @mmarchini/observe cpu-profile --help

As of right now, there are three tools available: heap-profile, heap-snapshot and cpu-profile. Heap Snapshots and Heap Profiles are memory analysis tools, with the former taking a "snapshot" of V8's memory, and the latter sampling stack traces every X allocations. Heap Snapshots are expensive but comprehensive and good to determine where most of the memory is currently being used.

Heap profiles (known as "Allocation Samples" on CDP interface) are a lightweight, sample based profiler that captures stack traces on allocations, and is a good tool to understand how memory is growing over time. CPU Profile, as the name suggests, is your typical CPU profiler and it samples stack traces at regular intervals.

Only JavaScript frames are captured for both profilers. If you need a combination of native frames and JavaScript Frames, consider using something like Linux perf or memleak. I'm currently working on a blog post about memleak usage with Node.js applications, and I might write an updated guide on Linux perf in the future.

You should pass the -f <filename> option to save the output from each tool into a file. Those files can then be loaded on Chrome DevTools (chrome://inspect and open the "dedicated DevTools for Node"), or with any other tools that can process these files. Since DevTools don't have FlameGraphs for CPU Profiles, I usually use Speedscope since it has a nice interface and features, and has no server-side processing. I won't go into how to interpret the results from each tool in this blog post, but I plan on writing individual interpretation guides for each tool.

Conclusion

That's @mmarchini/observe, a tool intended to be simple and portable, yet powerful. Contributions are welcome, I have some features in mind for future updates but don't know when I'll get to it. As mentioned above, I only showed how to use the tools here. I'll be writing follow up blog posts on how to successfully interpret the results from each tool.

Taming the dragon: using llnode to debug your Node.js application

mary marchini — Tue, 13 Jun 2023 03:53:03 +0000

Originally posted at Sthima Insights on Jun 20, 2018. Reposted here for preservation purposes.

Note: llnode hasn't been updated in years and the latest Node.js version it is known to work on is Node.js v14.

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-dev

After 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: **74262**

To 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:3000

Now 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   37182200

If 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\]=0x176dffba6329

The 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.

We just got a new super-power! Runtime USDT comes to Linux

mary marchini — Tue, 13 Jun 2023 03:30:21 +0000

Originally posted at Sthima Insights on Oct 30, 2017. Reposted here for preservation purposes. Links have been updated, but the content hasn't.

A new tracing capability has arrived in Linux: the ability to instrument user-level statically defined tracing (USDT) probes defined in dynamic languages such as Python and Node. Prior Linux USDT support has been limited to the static code, such as C or C++. Now, USDT probes can be defined in a Node.js program and used from there, allowing new analysis tools that combine custom Node.js tracepoints along with other library and kernel events. Dtrace-capable operating systems have libusdt, and now Linux has libstapsdt — a library to create USDT probes at runtime. Both have a similar API, as libstapsdt is inspired on libusdt, but they work very different internally.

libstapsdt uses the same structure provided by Systemtap SDT. Thus it should work with any tool able to trace SDT probes from Systemtap (for example, bcc’s tplist and trace tools). It is written in C, which makes it easy to be wrapped by many other languages. If you want to learn more about how libstapsdt works internally, you can look at our documentation here.

In this tutorial, we will show how to use eBPF/bcc to trace probes using Node.js and Python wrappers for libstapsdt. We assume a basic understanding of software instrumentation and tracing tools on this tutorial.

Installing Dependencies

To use either Node.js or Python wrappers, you first need to install libstapsdt on your system. On Ubuntu 16.04, you can install libstapsdt from a PPA. For other distributions, you can build it from source following the instructions here.

sudo add-apt-repository ppa:sthima/oss  
sudo apt-get update  
sudo apt-get install libstapsdt0 libstapsdt-dev

NOTE: the PPA above is no longer maintained or updated. A new PPA might be provided in the future, otherwise users who want the latest version can follow build instructions on GitHub.

In this tutorial, we will use eBPF/bcc (version 0.4.0 or higher) to trace USDT probes. You can install the latest stable version by running:

sudo apt-key adv --keyserver keyserver.ubuntu.com --recv-keys D4284CDD  
echo "deb https://repo.iovisor.org/apt/xenial xenial main" | sudo tee /etc/apt/sources.list.d/iovisor.list  
sudo apt-get update  
sudo apt-get install bcc-tools libbcc-examples linux-headers-$(uname -r)

Now you can either try the Node.js Example or the Python Example.

Node.js Example

You can install Node.js’s wrapper by running:

npm install usdt

Copy the following code and paste it into a file named index.js:

// Import usdt module
const USDT = require("usdt");

// Create a Provider, which we'll use to register probes
const provider = new USDT.USDTProvider("nodeProvider");

// Register your first probe with two arguments by passing its types
const probe1 = provider.addProbe("firstProbe", "int", "char *");

// Enable provider (needed to fire probes later)
provider.enable();

let countdown = 10;
function waiter() {
  console.log("Trying to fire probe...");
  if(countdown <= 0) {
    console.log("Disable provider");
    provider.disable();
  }
  // Try to fire probe
    probe1.fire(function() {
    // This function will only run if the probe was enabled by an external tool
    console.log("Probe fired!");
    countdown = countdown - 1;
    // Returning values will be passed as arguments to the probe
    return [countdown, "My little string"];
  });
}

setInterval(waiter, 1000);

You can then run it with the following command. It will print “Trying to fire probe…” every 1 second.

node index.js

You can now use some tools to trace your program. For example, if you run the command below in another terminal, it will print the arguments returned on line 26 every time it fires a probe. You can also see that now your Node.js application is printing “Probe fired!” in the terminal.

\# PID is the pid number for "node index.js"  
sudo /usr/share/bcc/tools/trace -p \[PID\] 'u::firstProbe "%d - %s", arg1, arg2'

Now you can use any tool from bcc which uses USDT probes to analyze your Node.js programs with USDT probes!

This example is also available as an ASCIICast:

https://asciinema.org/a/144982

Python Example

You can install Python’s wrapper by running:

pip install stapsdt

Copy the following code and paste it into a file named demo.py:

from time import sleep

import stapsdt

# Create a Provider, which we'll use to register probes
provider = stapsdt.Provider("pythonapp")

# Register your first probe with two arguments by passing its types
probe = provider.add_probe(
    "firstProbe", stapsdt.ArgTypes.uint64, stapsdt.ArgTypes.int32)

# Enable provider (needed to fire probes later)
provider.load()

while True:
    print("Trying to fire probe...")
    # Try to fire probe
    if probe.fire("My little probe", 42):
        # This will only run if the probe was enabled by an external tool
        print("Probe fired!")
    sleep(1)

You can then run it with the following command. It will print “Trying to fire probe…” every 1 second.

python demo.py

You can now use some tools to trace your program. For example, if you run the command below in another terminal, it will print the arguments passed on line 18 every time it fires a probe. You can also see that now your Python application is printing “Probe fired!” in the terminal.

\# PID is the pid number for "python demo.py"  
sudo /usr/share/bcc/tools/trace -p \[PID\]'u::firstProbe "%s - %d", arg1, arg2'

Now you can use any tool from bcc which uses USDT probes to analyze your Python programs with USDT probes!

This example is also available as an ASCIICast:

https://asciinema.org/a/144984

Where to go from here

Instrumentation on Linux is growing fast, especially with recent improvements to eBPF on the Kernel and the fantastic tools present on bcc. With libstapsdt, we’re taking another step by adding the ability to developers to instrument their code in dynamic languages.

There are still some refinements to be done on libstapsdt, but it works for most use cases. If you want to contribute to libstapsdt, you can find us on our Github page. If you decide to write a wrapper, please let us know (we’ll add it to the list of wrappers on the main page)!