Performance profiling Node.js applications
Here we take a look at profiling a node.js app from 3 different angles. Client, Server and System performance. Using free tools available.
1) Chrome Canary for client-side
Canary will print the initial function name, hugely helping us track down the heavier functions.
2) Iron-node for server-side
why: Great tool with Electron at its core. Allows server-side code to run in a browser like environment for full access to memory/heap/stack.
2 different things we want to profile here, first is evaluation time, second is event time.
We will start with evaluation time (i.e. on page load).
To start load any page with JS enabled.
To profile click
‘Timeline’ -> enable ‘JS Profile’ -> refresh page
The important results here is under ‘Summary’ -> ‘Scripting’.
That prints the entire evaluation time.
We can get a breakdown of why it is takes that time by observing the Yellow area in the flame graph.
This shows that jquery is taking 24ms of the 26ms evaluation time, possibly a consideration on whether its really worth it.
The second type is event times (i.e. click hijacking/or scrolling)
This example does DOM replacement on clicking a link.
Once the page has loaded click
I find it easiest to view the ‘Chart’ view. It prints a heat map (similar to above).
Here we can see the functions which are taking the longest and think about why.
My heat map shows jQuery DOM manipulation taking the longest followed by jQuery Ajax requests.
I could look at swapping jQuery’s `replaceWith` method for a native `replaceChild`. But unless we are replacing alot the difference becomes neglible and it comes down to programmer preference.
As mentioned above we can capture the full stack trace with iron-node.
A side-note, any app using Promises (e.g. Bluebird based) will find the large majority of calls from said library. For example Bluebird calls ‘_tickCallback’ to offload to Nodes event queue.
Again there are 2 ways to profile, (1) Node initialization time, and (2) request processing time. They follow the same client-side techniques.
For request profiling click
Here its possible to learn not just how much time/cpu/memory your own functions are taking but also those of your dependencies.
It is also possible to search for your own modules e.g. middleware. Get an understanding how your code compares to the complete request stack (see example in image).
On Mac it is possible to use a tool called ‘dtruss’ to print details of any process system calls.
Put the below in 1 tab
#sudo dtruss d n ‘node’ > /tmp/node.log 2>&1
Run node app in another.
Now we can view ALL system calls during a node process.
I found it interesting watching the System call ‘open()’ (which is obviously when system opens a file).
Node apparently opens ‘node_modules’ folder in the currently directory, then every single directory traversing up to the root directory, before finally issuing a ‘mdoule not found’ error.
I hope you have found some or any of the details here useful. I find profiling an incredibly valuable insight into how an app/functions/code actually performs. Something hugely important these days.