N|Solid Documentation

Versions

CPU Profiling

CPU Profiling can be used to indicate all the functions on the function call stack, when samples are taken. For instance, if a function foo() called a function bar() during its execution, and a sample was taken while bar() was running, the function call stack will show that foo() called bar(). Because multiple samples may be taken while bar() is executing, there will be an approximate start and stop time recorded for bar(), which is an indication of how long it took to run. In addition, further samples before and after the ones that captured bar() will capture foo(), and likewise to the bottom of the function call stack - typically, a callback of some sort.

This data can then be analyzed to show, for the function foo(), how much time was actually spent in foo() and not in bar() - every function has two time values - a self time and a total time. For the foo() and bar() case, if foo() only calls the bar() function, then the self time for foo() + the total time for bar() will equal the “total” time for foo().

Example

function foo() {
        … processing that takes a lot of time but calls no other functions ...
    bar()
        … processing that takes a lot of time but calls no other functions …
}

function bar() {
    …
}

foo’s total time = foo’s self time + bar’s total time.

Both values are interesting; total time shows you which functions are fastest and slowest, from start to finish, but doesn’t tell you if the time was spent in that function or other functions.

Named Functions

Named functions are easier to spot in CPU profiles. The stack frame entries available in a CPU profile include the name of function, and source code location information for detail views. For anonymous functions, the name will often be displayed as "(anonymous)". In some cases, the V8 JavaScript engine can calculating an "inferred name" for a function. When in doubt, name your functions so that you can easily spot them in a CPU profile.

For instance, let's say you have a function busyFunction(), which you like to easily track the callers for, and you have cases where it's called from an anonymous function, like this:

setInterval(function(){busyFunction()}, 1000)

In a CPU profile, you'll see that busyFunction() is being called by(anonymous) in this case.

To make this easier to easier to spot in a CPU profile, you can simply use:

setInterval(function busyFunctionCaller(){busyFunction()}, 1000)

In the CPU profile, you'll now see that busyFunction() is called by busyFunctionCaller().

For additional code cleanliness, and less chance of creating a "pyramid of doom", consider moving the entire function out into the same scope as the function usage; for instance:

setInterval(busyFunctionCaller, 1000)
//...
function busyFunctionCaller() {
  busyFunction()
}

Because JavaScript functions are "hoisted" to the top level of the scope they're defined in, you can reference busyFunctionCalled before it's actually defined.

CPU Profiling allows you to understand where opportunities exist to improve the speed and load capacity of your node process. N|Solid provides multiple ways to profile your CPU.

Analyzing Profiles Using the N|Solid Console

The N|Solid Console allows you to take and analyze profiles in one action. This is particularly useful if you need to take a series of profiles as it saves you the overhead of switching from one environment to another. The console also saves a history of profiles so you can quickly flip through profiles to identify troublesome areas.

  1. Launch the console and select the application of interest "All applications"
  2. Select the process of interest "Select process"
  3. Expand out the details panel and select ‘+ New Profile’
    "New profile"
  4. Select your profile window (5 to 60 seconds) and run profile "Run profile"
  5. Select a visualization (Sunburst, Flamegraph or Treemap). Once a visualization is selected, you can click on it to view the call stack to the right. The number of calls to that method are shown as are the time spent within it. Clicking on the method will show you the file responsible for that call. "Call stack"
  6. Profiles are saved in your console session so you can easily flip between profiles.

Visualizations Explained

All of the visualizations available for profile data show the unique set of stack traces captured during the profile, with the "area" of the stack indicating the proportional time spent in a function compared to that of its parent.

The Flame Graph visualization shows the time along the x-axis. The y-axis is used to show the function calls that make up a particular stack trace.

The Sunburst visualization is like the Flame Graph, where the x-axis is curved into a circle. Stack traces grow from the center to the outer parts of the graph.

The Treemap visualization shows time by area. The larger the rectangle, the more time a function took. The stack traces grow from the outer boxes into the inner boxes.

You can use the visualizations to find long-running functions. These can be identified by:

The stack trace height - how many functions deep a particular stack trace was - doesn't indicate a time issue, necessarily. You'll want to focus on the time values.

As you hover over the visualization itself, the method tied to the visualization will be show. If you click, you'll see a stack trace to the right of the visualization. Other areas in the visualization may "light up" with a less bright color as you hover over the visualization - these are entries in stack traces for the same function and indicates additional CPU usage for the function under the cursor.

So, the things to look for are stack trace entries that take up the most area: width in Flame Graph, circumference in Sunburst, and area in TreeMap.

Using the Chrome Profiler with N|Solid

You can also view the generated CPU profile in Chrome Dev Tools:

Profiling Using the Command Line Interface (CLI)

N|Solid's Command Line Interface (CLI) is a great way to quickly pull profiles from remote processes for local examination. You can learn more about the profile command in the N|Solid Command Line Interface (CLI) reference.

Profiling Using the N|Solid Node API

If you have a desire to trigger a CPU Profile progamatically from within your application and have the resulting profile saved to your N|Solid console, you can do this using the N|Solid Node API.

const nsolid = require('nsolid')
nsolid.profile(duration_in_seconds, err => {
  if (err) {
    // The profile could not be started!
  }
})