HTTP2 – Performance saviour for application

Recently, I took the task of improving the performance of my application and shortlisted the probable reasons or factors for the same. Out of which few of them were:

  1. Large bundle size of the application.
  2. Wrong handling of the redirection logics i.e not using in-app redirection ways.
  3. Multiple 3rd party scripts delaying the rendering.
  4. Number of concurrent browser calls to download resources.

First three could still be handled, but what about the last one? I realized since the APIs were also time-taking. I concluded that probably its due to the high number of concurrent requests, some of the resource downloading are getting delayed. But I discovered that only one protocol version change can save me from the extra efforts of trying to avoid this. Let’s see how.

Below is an example of the resource timing in chrome Network tab.

Resource timing from the waterfall for a browser call on chrome

The figures which I found worrisome were the stalled and the queueing timing. The request was stalled/blocked for around 200ms before the request was sent. The reason for the blocking or queueing timings can be either of the following :

The request was postponed by the rendering engine because it’s considered lower priority than critical resources (such as scripts/styles). This often happens with images.

The request was put on hold to wait for an unavailable TCP socket that’s about to free up.

The request was put on hold because the browser only allows six TCP connections per origin on HTTP 1.

Time spent making disk cache entries (typically very quick.)

According to Understanding Resource Timing,

Wait! whats the third point? Do we need to re-do our logic to minimize the number of concurrent requests?

Well, yes, ideally, we should avoid the number of browser requests as most SEO site checkup websites recommend to not have more than 20 external requests on a page.

But what is this limitation? Well, the number of HTTP connections are limited for browsers and we can see Browser Connection Limitation for reference. It has multiple reasons altogether.

How does this slow the page down?

For example if i am trying to send 7 requests altogether to the same host, the 7th request may have to be blocked for any of the connections to be free. Therefore, the page may not get all the resources needed to render the entire page and therefore, the stalled time may get added to your loading time.

Let’s see what all we can do to tackle this.

  • Hmm.. As many do, we can keep different hosts for serving different kinds of resources. e.g apis.example.com for server APIs, style.example.com for CSS resources, console-static.example.com for other static resources. This can help as using different hosts can increase our limit of connections through browser.
  • Try and reduce API calls using techniques like Image or CSS sprites etc.
  • Keep a balance between the front end and back end to optimize browsing experience.
  • Cautiously, choosing the APIs which are most needed in our application, maybe.

But can we avoid the above problem without making host changes, code changes or logic changes???

Before jumping to the solution, let’s see one more field in the Network requests section of Chrome, which is the Protocol tab. Its tells you what protocol your connection or browser request has used.

Network tab with Protocol field

The above limitations were as mentioned in the quote were for the HTTP protocols of <=1.x versions.

Earlier in HTTP 1 protocol, each request needed a TCP connection to be made, therefore, repeating the handshake etc mechanism, therefore, delaying the browser requests and limiting the number of connections.

The HTTP 1.1 protocol tried to make it better by bringing in the facility to reuse the made connections but again it was based on First in first out but still keeping the connection alive.

HTTP 2 brings with it the new way of browser calls using Binary framing layer and thus tries to overcome the performance limitations of the earlier protocols by providing the following.

  1. Single Connection per Origin => i.e it caters multiple requests using a single connection therefore making parallel requests to be served without any blocking.
  2. Server Push => It has also brought with it the capability to send multiple responses for a request. e.g if you know, with a request, the other resources will also be needed, you can push them to the client without any extra call. Thus helping in improving the performance

Above was just an overview of HTTP2. Getting into it deeply is beyond the scope of this article. You can read about it more at Google’s developer site on HTTP2.

Using HTTP2 protocol can save us from putting the extra efforts needed to improve the performance for our applications while networking.

What all is needed to start using HTTP2 protocol?

  • From UI side

Nothing needs to be done, since the new browser versions already support this. So if you have you browser updated to support HTTP2, we are ready from browser side to start using the protocol.

  • From Server side

What if browser says, it can use HTTP2, but server says I cannot? Since we know, the protocols to be used are decided while handshaking between the client and server, our server also needs to support HTTP2 protocol.

In my case it was simple as i was using the nginx server for serving my application resources. Just adding the below line did the trick:

listen          443 ssl http2;

And its done!!!

My browser is updated, the server listens to http2 protocol, Now i can possibly delay the task of reducing the number of calls for later.

No more blocking, no more delaying.

Apart from the reason that we should keep our application updated with the latest technologies, bumping the protocol version to atleast HTTP2 gives us some extra performance improvements. Atleast those HTML, Scripts and CSS can be downloaded parallely. Thanks HTTP2 for taking care of these internally for me.

I hope it helps. Thanks for reading. Please add your feedbacks below and help me to make it more useful.

Tagged : / / /

Simple HTTP request logging middleware in Go

When we’re building a web application there’s some shared functionality that we want to run for many (or even all) HTTP requests. We might want to log every request, gzip every response, or authenticate request before doing any processing. There are already libraries present which do this, but its always fun learning something new and building on your own.

In this post I’m going to explain how to make a simple custom request logging middleware which can be used with gorilla/mux. Our middleware will log each incoming request to the application and will log the following parameters:

  1. Request Method
  2. Request Host
  3. Request Path
  4. Request query parameters
  5. Time took to complete request
  6. Response status code

Given below is a simple Go program which has 2 APIs, /ping, /hello.

package main

import (
	"net/http"

	"github.com/gorilla/mux"
)

func main() {
	r := mux.NewRouter()
	r.HandleFunc("/ping", handlePing).Methods(http.MethodGet)
	r.HandleFunc("/hello", handleHello).Methods(http.MethodGet)
	http.ListenAndServe(":http", r)
}

func handlePing(rw http.ResponseWriter, req *http.Request) {
	rw.Write([]byte("I am working...\n"))
	return
}

func handleHello(rw http.ResponseWriter, req *http.Request) {
	rw.Write([]byte("Hi, how are you...\n"))
	return
}

Writing the middleware

Now we will write a simple middleware, which logs all the incoming requests to our application. Initially we will only focus on printing the first 4 parameters.

func RequestLoggerMiddleware(r *mux.Router) mux.MiddlewareFunc {
    return func(next http.Handler) http.Handler {
        return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
            defer func() {
                log.Printf(
                    "[%s] %s %s %s",
                    req.Method,
                    req.Host,
                    req.URL.Path,
                    req.URL.RawQuery,
                )
            }()

            next.ServeHTTP(w, req)
        })
    }
}

We can use this with mux router as below:

r.Use(RequestLoggerMiddleware(r))

So the complete main function looks like

func main() {
    r := mux.NewRouter()
    r.HandleFunc("/ping", handlePing).Methods(http.MethodGet)
    r.HandleFunc("/hello", handleHello).Methods(http.MethodGet)
    r.Use(RequestLoggerMiddleware(r))
    http.ListenAndServe(":http", r)
}

Lets try calling the APIs now and check how the requests are being logged now:

Perfect, this looks great! Now we also want to add the time taken by the API. This can be done very easily in the middleware function by adding the following:

func RequestLoggerMiddleware(r *mux.Router) mux.MiddlewareFunc {
    return func(next http.Handler) http.Handler {
        return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
            start := time.Now()
            defer func() {
                log.Printf(
                    "[%s] [%v] %s %s %s",
                    req.Method,
                    time.Since(start),
                    req.Host,
                    req.URL.Path,
                    req.URL.RawQuery,
                )
            }()

            next.ServeHTTP(w, req)
        })
    }
}

So now the new output is something like below

Looks better! So the only part remaining is to add the response status code in the log message.

Do we have access to response status code in middleware ? Does http.ResponseWriter help ?

Frankly speaking, there is no direct way of adding that. In Go APIs, we use the response writer http.ResponseWriter object to write status codes in APIs. If we closely look at the implementation of http.ResponseWriter , it is an interface and has the following methods:

type ResponseWriter interface {
    Header() Header
    Write([]byte) (int, error)
    WriteHeader(statusCode int)
}

From our API methods, we call WriteHeader method on response writer object.

func handleHello(rw http.ResponseWriter, req *http.Request) {
    rw.WriteHeader(http.StatusOK)
    rw.Write([]byte("Hi, how are you...\n"))
    return
}

Though in our middleware we don’t have access to this status code and thus we cannot print it. To solve this problem, we will use a very cool feature of Golang and will embed the ResponseWriter interface in a custom struct. This custom struct will have a statusCode field inside it and thus can be used to print the status code in request logs. Let’s see how:

type statusResponseWriter struct {
    http.ResponseWriter
    statusCode int
}

// NewStatusResponseWriter returns pointer to a new statusResponseWriter object
func NewStatusResponseWriter(w http.ResponseWriter) *statusResponseWriter {
    return &statusResponseWriter{
        ResponseWriter: w,
        statusCode:     http.StatusOK,
    }
}

So we created a new structure statusResponseWriter which contains the statusCode field in it. Now since this structure embeds http.ResponseWriter interface, its methods are seen as if the custom struct is also implementing them.

When interfaces are embedded, their methods are promoted automatically. That means methods of interface are seen as if they are methods of the embedding struct

This means an object of our custom struct can be passed to ServeHTTP function, since it implements the http.ResponseWriter interface. But here comes another cool feature, we can also override the methods of interface.

It’s here where we do all the magic to assign the statusCode field of our custom struct whenever there is a WriteHeader from the API.

// WriteHeader assigns status code and header to ResponseWriter of statusResponseWriter object
func (sw *statusResponseWriter) WriteHeader(statusCode int) {
    sw.statusCode = statusCode
    sw.ResponseWriter.WriteHeader(statusCode)
}

Now let’s see how we can use the custom struct statusResponseWriter to print the status code in request logs. So instead of passing w http.ResponseWriter to ServeHTTP method, we pass sw statusResponseWriter to it. Then we use sw.statusCode field to log the response status code and thats it the work is done here!

func RequestLoggerMiddleware(r *mux.Router) mux.MiddlewareFunc {
	return func(next http.Handler) http.Handler {
		return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
			start := time.Now()
			sw := NewStatusResponseWriter(w)

			defer func() {
				log.Printf(
					"[%s] [%v] [%d] %s %s %s",
					req.Method,
					time.Since(start),
					sw.statusCode,
					req.Host,
					req.URL.Path,
					req.URL.RawQuery,
				)
			}()

			next.ServeHTTP(sw, req)
		})
	}
}

Let’s see how the final logs look now:

Wow! Amazing, our custom logging middleware is complete now and looks good! Try playing around with it and you can print all cool things like user agent, host ip etc in the request logs according to your use case.

Please comment and share if you liked this post. If you have any suggestions or feedback, please comment, we will be happy to discuss and improve this post. Thanks a lot for reading!

Tagged : / / /
%d bloggers like this: