Pretty git log in the terminal

It’s easy to get a graphical git log tree view in the terminal like this:-

Pretty git log screenshot display the este repository commit tree
Pretty git log screenshot display the este repository commit tree

Running the git log command below inside your git project produces similar output to that shown above:-

Using a git config alias, the command can be shortened to make it easier type in the terminal by defining an alias e.g. “tree” (or whatever you want to call it) in the global config.

Now to get the pretty git log tree view, simply type:-

Debugging Performance Bottlenecks in a Node.js Application

Background

A recent update to one of our high volume production apps had the undesired consequence of increasing the time-to-first-byte by a staggering 500%. Although we had done rigorous testing, this bug did not clearly manifest itself until it was in production. To make matters worse, the application is isomorphic and we had just updated from React v0.13 to v0.14 refactoring components along the way so there was not one single change we could easily pinpoint as being the most probable cause. Tasked with identifying the problematic code, I began CPU profiling the JavaScript node application using the readily available tool – node-inspector.

This guide aims to demonstrate how to diagnose bottlenecks in your node application using node-inspector and Google Chrome.

Sample project

I’ve put together a very basic express app that calls off to a fake service which adds a delay of ~1 second (depending on your machine) to the response from the server. The code can be cloned from github:-

Quick start

To start the server, execute the following from the application root:-

The server should then output the following response:-

Node performance debug site server listening console output
Server ready and listening

Identifying the problem

Next, open up Chrome and with debugging tools enabled and focused on the network tab, navigate to http://localhost:3000/

Network trace for the node performance debug site showing a 1 second delay for time-to-first-byte
Network trace of our sample node application showing a delay of over a 1 second for time-to-first-byte.

We can clearly see that something is not right; over 1 second to get a response is too slow. So how can we diagnose what’s causing the delay?

CPU profilling Node.js

Node inspector Can help us to identify bottlenecks in the execution of the node application by profiling the code execution.

First install node-inspector globally (you may need to run as sudo),

then execute the node application using node-debug instead of node.

This will launch your application in node-inspector and open a Chrome debugger window.

Application console.log running under node-inspector
Application console.log running under node-inspector

If your browser does not automatically load, then open up a new browser instance and navigate to the debug url displayed in the console e.g. http://127.0.0.1:8080/?ws=127.0.0.1:8080&port=5858

node-inspector Chrome debug window
node-inspector Chrome debugger attached to the process and paused at the first line of code

By default, node inspector will pause execution of the application at the very first line of code.

Allow code execution to continue by pressing F8 or clicking the resume execution button.

Recording the CPU Profile

To record the JavaScript CPU profile, we need to instruct the node inspector debugging tools to record the CPU profiles, then in another browser window visit our site to generate a request that will appear in the CPU profile.

Step 1. Profiles tab

Start CPU profiling in node inspector
Start CPU profiling in node inspector

Step 2. Make sure the “Collect JavaScript CPU Profile” option has been selected.

Step 3. Click start.

Step 4. In a separate browser, navigate to http://localhost:3000/ and wait for the request to complete.

Step 5. Back in node inspector, click “Stop”.

Stop recording of the CPU profile in node inspector
Stop CPU profile recording in node inspector

6. The profile will automatically load.

Analysing the CPU profile graph

The CPU profile chart helps to easily identify where our application is spending its time whilst processing the request.

1. Make sure the chart view is selected.

Annotated node inspector CPU profile trace
The node inspector CPU profile trace – Note that the duration of the call time has increased from 1 second to almost 1 minute. Running with a debugger attached slows down the application significantly.

2. The graph shows the activity over time. We’re interested in this big block.

3. The call stack starting from top to bottom.

Looking at the call stack, we can quickly identify where our application is spending most of its time processing the request.

Using the mouse to hover over each method call, we can see that it looks like the culprit lies in slowService.js, around line 14. Armed with the knowledge let’s go to the code and see what’s going on.

So the method that’s taking a lot of time to execute is appropriately named cpuIntensiveProcess.

Clicking on the block with the name “service” will directly take you through to the source code whilst inside node inspector.

Node inspector source view of slowService.js
Viewing the problematic file in node inspector

In our sample application we can now refactor the cpuIntensiveProcess method out to be more performant, or in this example just delete it entirely because it’s not doing anything useful.

Conclusion

It is relatively pain free to troubleshoot performance problems in our application. Node-inspector is just one of a suite of tools available to help us monitor, report and diagnose performance problems.

In our production environment, we use newrelic to alert if there is ever a significant degradation in time-to-first-byte performance, as well as capturing server and client side errors giving better insights into how our applications behave in the real world.

Fixing node package vulnerabilities

It’s always a good idea to keep on top of your security updates because if you’re not looking at it, someone else probably will.

Acting on a recent denial of service vulnerability security alert from Node.js, I was tasked with upgrading our production servers to the latest Node.js version to fix the security alert. This was pretty straight forward upgrade only involving changing a version number in a config file then rerunning the build / production pipelines in teamcity to pull in the latest Node.js.

Following on from this I wanted to check if our applications themselves contained any security vulnerabilities, the only problem is that in just one project we have at least 30 top level package dependencies defined in our package.json and each referenced package references other packages and so on. Reviewing these packages by hand would take hours and is highly error prone to missing known vulnerabilities.

Thankfully there’s a tool to do all the hard work for you by scanning your node package.json and npm-shrinkwrap.json files for vulnerabilities.

nsp from nodesecurity.io audits your node application dependencies against its database of known security vulnerabilities.

To install globally:-

Then inside your project directory, where package.json is located, run this:-

Here’s a sample of the vulnerabilities found in just one of our production apps (security vulnerabilities now fixed!).

Node security vulnerability report showing 13 found vulnerabilities.
Node security vulnerability report showing 13 found vulnerabilities.

After upgrading all the affected packages and rerunning nsp check, I now get no security alerts reported:-

Node security vulnerability report showing no known vulnerabilities.
Node security vulnerability report showing no known vulnerabilities. All fixed.

Good times.

Take this further by incorporating nsp into your build processes using gulp to help stay on top of security.

Check out Node Security Project for more information.