NodeJS being IO intensive, http requests form a major part of the application lifecycle. For monitoring and observability of a NodeJS application, understanding its behavior of requests made to other systems is an integral part of a micro-services architecture. Inspired by the tweet below, we decided to share how to improve the Observability in context of HTTP request-response lifecycle in a NodeJS application.

NodeJS HTTP request-response phases

In NodeJS, both HTTP Request and Response are NodeJS streams, they implement the EventEmitter interface and emit events for specific lifecycle events. We can add event listeners to these events in order to measure the important metrics for request and response. The events emitted by NodeJS for the parts of the above HTTP lifecycle phases are

The request starts with the creation of net.Socket object which emits the socket event once the socket is created. Now this socket can be used to listen to the DNS Lookup, TCP and TLS events. We will use process.hrtime() which marks High Resolution timestamp to mark the events and would find the duration from start of the request to each of those timestamps.

const request = https.request(options, callback)

const startTime = process.hrtime();

let dnsLookup, tcpConnection, tlsHandshake, responseBodyStart, responseBodyEnd; request.on("socket", socket => {

// Socket created for dnslookup

socket.on("lookup", () => {

dnsLookup = process.hrtime();

}); // TCP Connection established

socket.on("connect", () => {

tcpConnection = process.hrtime();

}); // TLS Handshake complete

socket.on("secureConnect", () => {

tlsHandshake = process.hrtime();

});

});

Once the request completes, the server would start sending responses. These response bytes can be listened on the http.Response object

https.request(requestOptions, res => {

// The first time response bytes are transferred

res.once("data", () => {

responseBodyStart = process.hrtime();

});

res.on("data", chunk => (response += chunk));

res.on("end", () => {

responseBodyEnd = process.hrtime();

callback(null, {

body: response,

duration: getEventDuration()

});

});

});

Now you can find the duration of each of these events marked with a timestamp to find the duration of important parts of the lifecycle.

DNS lookup = dnsLookup - startTime

TCP connection = tcpConnection - (dnsLookup || startTime)

TLS connection = tlsHandshake - tcpConnection

First byte = responseBodyStart - tlsHandshake

Content transfer = responseBodyEnd - responseBodyStart

Total = responseBodyEnd - startTime

This information can now be added to Monitoring and Distributed tracing to help improve the Observability of your systems.