Introduction

In this article we are going to look at code profilers, we will look how to conduct simple code profiling in applications written in Node.js.

  • What is a profiler?
  • Why we need to profile our code?
  • How to conduct basic profiling in node.js

What is a profiler?

A profiler is a tool that can be used to analyse code for any performance issues. This can be done by the original developer or a 3rd party company, especially when dealing with big projects. A profile can answer simple questions like how many times have a function have been called, or it can also be useful to give you the amount of time a function takes to return a result. Profilers can be a very helpful tool when you want to give a perforce boost to your application.

Why we need to profile our code?

As developers we want to provide great experiences to our users. the following will illustrate some simple examples how profilers can be used.

When dealing with web applications, we want to provide the best possible performance to our users. Using a profiler can help you identify those bottle necks into your application which can reduce the amount of time for a request or database access.

Another useful scenario when to use a profiler is to identify memory leaks. A memory leak is a situation where the amount of memory used by the application is greater than the memory that same application is releasing for further use. Eventually this problem will make your application fail or act in an abnormal way.

A Profiler can also be used to identify how a library is acting in our application, we all came to love the huge repository at npmjs.org, but how can we be sure that the libraries we are using have the same code quality we are striving to achieve within our code.

In this article, we are going to go over one of the useful tools provided with the node binaries and which we use often at Lemonworx while developing web applications, this is node.js code profiler. This could easily become your first port of call when an application is running slow, when http requests from your web application are taking forever to return or when your application is entering in an abnormal state after a certain period of execution time.

At Lemonworx we profile code before we release to our clients. This helps us ensure that all of our code is highly optimised. On very big applications sometimes this can take several rounds of optimal results.

How to conduct basic profiling in Node.js

Let’s say our manager came to us with a problem, we must create a set of 10,000 folders for our company internal users on a daily basis. We have scratch a bit our heads on why management needs this but eventually we started coding a simple script to do so.

Example 1 – unoptimised code:

Our first attempt was to use the following code:

After testing the code and identified that it is following all the (simple) requirements we wanted to test its performance and see if the code was optimised. To start profiling code in Node.js we have to run the following command:

After running this command we get a new file name <isolated-XXXXX>-v8.log this is the raw log file and can be a little difficult to understand. Luckily for us we have a tool at our disposal to turn this raw file in something more readable and developer friendly. To do this perform the following command on the .log file

Load this newly created process_log.txt in your favourite text editor and you will get a handful of information of how your application is performing. In this tutorial we are only to go over the very basics, further articles will look into more details of the output that was produced.

The very first line in the text file is the following output:

This is basically saying that our application have used 321 ticks to execute our application. If you do not know what node ticks are do not worry we will soon have a article just to explain this terminology, for now just thing of a tick as one clock cycle used by a node process. So in theory for our application to execute it took 321 clock cycles.

We started looking at the code to try to optimise it to be more performant before we release it to our operations department. After looking into node documentation we have identified that we are using an synchronous call in our application and identified that if we use the asynchronous version of the call, it might speed up the process. So we created an updated version of our application with the following code.

Example 2 – optimised code :

After updating our code we again try to profile our new code to see if we achieved any performance improvements. After generating the raw logs and transformed it in a new log file with the –prof-process flag we open it in our text editor again and again we see the first line of the output.

With this simple code optimisation we have managed to get down our ticks from 321 to 287. That is quite an improvement in the code.

Summary

  • In this article we have gone over the very basics of how to profile code in node.js
  • We have looked on how to create a profiler output with the flag –prof
  • We have identified how to transform a profiler log to a more readable log using the –prof-process
  • We have identified how to read and understand how many node ticks our application needs to execute.

 


Authors Bio

Dr. Graham Hili – PhD MSc BSc (Hons.)  from Royal Holloway University of London, where he specialised in Cloud Software and Massively Distributed Architecture Security. His research interest revolve around Network Security, Software Defined Network Security and Automotive Security. Graham now works as a freelance consultant for different Information Security projects mainly concentrating on Automotive Security with clients based in Europe, USA and Asia.