The problem

There’s a big slowdown — unusable app — in high traffic hours.

As soon as I opened NewRelic, I saw that there’s something wrong.
The picture you see above is straight from the dashboard.

Today — finally — enough users reported slowness in the system for me to be able to dedicate time to solving this issue.

These web transaction times (picture from the dashboard too) indicate that we have crazy slow endpoints. That means that we’d need ridiculously high concurrency —more than the total amount of tabs our users open at the same time — to be able to stay responsive and serve all the requests fast.

These endpoints contain complicated business logic and while they can all be optimized, it would take a lot of time and testing, while our users suffer.

The idea

By decoupling the HTTP response from the request, while a background worker is creating the response, we can serve other requests.

How can we do this? How can we notify our user that the respone is ready? WebSockets, polling, and server-sent events.

With SSE we can make HTTP requests async. A lighter and easier solution than WebSockets. You can just do this from the browser console:

source = new EventSource('/my_endpoint');
source.onmessage = (event) => {
  console.log("EventSource message received:", event);
};

And from Rails:

class SseController < ActionController::Base
  include ActionController::Live

  def index
    response.headers['Content-Type'] = 'text/event-stream'
    sse = SSE.new(response.stream, retry: 300, event: "open")
    sse.write("Hello!", event: "message")
  ensure
    sse.close
  end
end

And ta-dam! Well, almost. Here’s my article on how to start using SSE with Rails.

Verifying the idea

There’s a bit more to this. Is this really going to free up our precious threads? Let’s test!

With the following endpoint

class SseController < ActionController::Base
  include ActionController::Live

  def index
    response.headers['Content-Type'] = 'text/event-stream'
    response.headers['Last-Modified'] = Time.now.httpdate

    sse = SSE.new(response.stream, retry: 300, event: "open")

    loop do
      sleep 2
      sse.write("The current time is: #{Time.current.to_s}", event: "message")
    end
  rescue ActionController::Live::ClientDisconnected
    sse.close
  ensure
    sse.close
  end
end

I will start Rails with 1 thread, as the idea is that like this, we’ll be able to use a single thread to serve multiple requests without blocking:

RAILS_MAX_THREADS=1 PORT=3001 bundle exec rails s

and open 3 browser tabs with my rails app and run the following from console:

source = new EventSource('/sse');
source.onopen = (event) => {
  console.log("The connection has been established.", event);
};
source.onmessage = (event) => {
  console.log("EventSource message received:", event);
};
source.onerror = (err) => {
  console.error("EventSource failed:", err);
};

• First tab connects nicely and starts printing out the message as expected.
• Second tab does the same.
• Third tab is stuck pending.
• I try to open a 4th tab, but of course, the message doesn’t reach my web server.

Well of course. :)

sleep(*args) public
Suspends the current thread for duration seconds

No surprise here, we basically put our server to permanent sleep. This is exactly the state that the requests are experiencing when they’re reported as “queuing” by NewRelic.

True asynchronicity

To free up the Rails thread while it’s computing and allow it to serve new requests, we can use Rack Partial Hijack. We’ll be using partial hijack, as the full is only supported with HTTP/1 which has limitations on SSE (see the warning part).

class SseController < ActionController::Base
  include ActionController::Live

  def index
    response.headers['Content-Type'] = 'text/event-stream'
    response.headers['Last-Modified'] = Time.now.httpdate

    response.headers["rack.hijack"] = proc do |stream|
      Thread.new { perform_task(stream) }
    end

    head :ok
  end

  def perform_task(stream)
    sse = SSE.new(stream, retry: 300, event: "open")

    loop do
      sleep 3
      sse.write("Time is: #{Time.current.to_s}", event: "message")
    end
  rescue ActionController::Live::ClientDisconnected, Errno::EPIPE
    sse.close
  ensure
    sse.close
  end
end

Browser limit

Using the code above, I could open 6 tabs and they were all promptly receiving their time updates. However I couldn’t open a 7th tab.
I warned you about the limitation on HTTP/1… well I’m on Rails and we can’t use HTTP/2 so we are limited to 6 connections to this domain by the browser. Opening a new (normal / incognito / private browsing) window is an easy way to bypass this limitation.

That said, our users will still complain — rightfully —about how the 7th tab fails to open.

In my case, when I just want to unblock the server, the solution is to retry connecting and close down this connection from the server side after the first message is delivered.

Server limit

On the server side, think about where your code runs. For example the Heroku thread limits could surprise you.

Also, now that you can accept a huge amount of slow and resource heavy requests, you can easily run out of memory (on web, worker or DB too). It might be a good idea to offload the processing to the workers (e.g. Sidekiq) and in the thread just checking in for the rendered response, that you can just put under a Redis key.

Final code

We’d like to close the connection once the first message has arrived, or if the request times out. (like when you forget to start sidekiq :))

source = new EventSource('/sse?delay=0&wait_limit=5');
source.onopen = (event) => {
    console.log("The connection has been established.", event);
};
source.onmessage = (event) => {
    console.log("EventSource message received:", event);
    source.close();
};
source.onerror = (err) => {
    if (err.data === "timeout") {
        source.close();
        console.error("EventSource timeout", err);
    } else {
        console.error("EventSource error", err);
    }
};

and we’ll offload processing to a Sidekiq worker and wait for the response:

class SseController < ActionController::Base
  include ActionController::Live

  def index
    response.headers["Content-Type"] = "text/event-stream"
    response.headers["Last-Modified"] = Time.now.httpdate

    response.headers["rack.hijack"] = proc do |stream|
      Thread.new { perform_task(stream, params) }
    end

    head :ok
  end

  def perform_task(stream, params)
    sse = SSE.new(stream, retry: 300, event: "open")

    delay = params[:delay].present? ? params[:delay].to_i : 5
    response_key = "sse_#{SecureRandom.uuid}"
    SseWorker.perform_in(delay.seconds, response_key)

    wait_limit = params[:wait_limit].present? ? params[:wait_limit].to_i : 30
    wait_limit.times do
      sleep 1

      response = Redis::HashKey.new(response_key).all
      if response.present?
        sse.write({ response: response }, event: "message")
        break
      end
    end

    sse.write("timeout", event: "error")
    sse.close
  rescue ActionController::Live::ClientDisconnected, Errno::EPIPE
    sse.close
  ensure
    sse.close
  end
end

the worker will set the response:

class SseWorker
  include Sidekiq::Worker

  def perform(response_key)
    Redis::HashKey.new(response_key).bulk_set({ hello: "world!" })
  end
end

To test, try to open as many connections as you can and see how they’ll all nicely arrive.

Production results

You can easily compare this image with the first one as the usage was almost identical and the time frame too. We have practically no response queuing anymore and our users stopped complaining as well.

We did have to add some memory to our DB instance though, as now we have also workers running these expensive DB queries not just the web servers.

That’s it!

If you’re interested about implementation details see my other article.

Create the controller action as per the example in the guide and define the route.

> sse_controller.rb

class SseController < ActionController::Base
  include ActionController::Live
  
  def index
    response.headers['Content-Type'] = 'text/event-stream'
    sse = SSE.new(response.stream, retry: 300, event: "event-name")
    sse.write({ name: 'John'})
    sse.write({ name: 'John'}, id: 10)
    sse.write({ name: 'John'}, id: 10, event: "other-event")
    sse.write({ name: 'John'}, id: 10, event: "other-event", retry: 500)
  ensure
    sse.close
  end
end

> routes.rb

resources :sse, only: [:index]

Now we can start calling it from the browser, see what happens. I’m following the official docs from Mozilla.

In a new tab I open the local Rails app localhost:3001 and then I open a browser console. In the console I’ll connect to this EventSource and I set handlers for the 3 different even types described by the docs.

source = new EventSource(‘/sse’);
source.onopen = (event) => {
  console.log("The connection has been established.", event);
};
source.onmessage = (event) => {
  console.log("EventSource message received:", event);
};
source.onerror = (err) => {
  console.error("EventSource failed:", err);
};

Running this, you’ll start receiving a lot of errors. Don’t worry: source.close() will stop the madness.

Taking another look at our code, we can see that the server and client side events have nothing to do with each other. Let’s change the server side code to return events that we subscribe to.

def index
  response.headers['Content-Type'] = 'text/event-stream'
  sse = SSE.new(response.stream, retry: 300, event: "open")
  sse.write({ name: 'John'}, event: "message")
  sleep 2
  sse.write({ name: 'John'}, id: 10, event: "message")
ensure
  sse.close
end

After executing the same code from the console against this one, it looks much better! I got the something like this:

The connection has been established. Event {…}
EventSource message received: MessageEvent {isTrusted: true, data: '{"name":"John"}', origin: 'http://localhost:3001', lastEventId: '', source: null, …}
EventSource message received: MessageEvent {isTrusted: true, data: '{"name":"John"}', origin: 'http://localhost:3001', lastEventId: '10', source: null, …}
EventSource failed: Event {…}

The connection has been established. Event {…}
EventSource message received: MessageEvent {isTrusted: true, data: '{"name":"John"}', origin: 'http://localhost:3001', lastEventId: '', source: null, …}
EventSource message received: MessageEvent {isTrusted: true, data: '{"name":"John"}', origin: 'http://localhost:3001', lastEventId: '10', source: null, …}
EventSource failed: Event {…}

It’s worth going to the Network tab as well to check the request log. What you will notice there, is that despite the sleep 2 on the server side, all the messages are being delivered at the same time, then the request is just closed. That’s not really async and it really defeats the purpose.

Luckily, we are not the first ones with the issue, as you can see on this StackOverflow question. The culprit is a middleware called Rack::ETag which wants to buffer your response. It’s an issue reported on GitHub and the proposed solution is to use Rack 3, but as it’s not an option for me at the time of writing. The suggested workaround there is:

response.headers['Last-Modified'] = Time.now.httpdate

Yes, this fixes it. We receive the two messages with 2 seconds of delay, yay!

The next issue I noticed, is that if I source.close() before all the messages are delivered, it throws an error, so let’s handle that and see how the code will look like:

class SseController < ActionController::Base
  include ActionController::Live

  def index
    response.headers['Content-Type'] = 'text/event-stream'
    response.headers['Last-Modified'] = Time.now.httpdate

    sse = SSE.new(response.stream, retry: 300, event: "open")

    5.times do
      sleep 2
      sse.write({ name: 'John'}, event: "message")
    end
  rescue ActionController::Live::ClientDisconnected
    sse.close
  ensure
    sse.close
  end
end

Perfect, I did source.close() after 3 messages and there were no issues on the server side reported.

Read my other post on how you can use Rails server-side events to fix responsiveness issues (when requests are queueing for too long)!

By that I mean when the client (e.g. mobile or web app) sends an ID token with each request to the server and using the Firebase Admin SDK it is resolved into a User UID, identifying the sender.

First we need a Firebase client:

opt := option.WithCredentialsFile("serviceAccountKey.json")
firebaseApp, err := firebase.NewApp(context.TODO(), nil, opt)
client, err := firebaseApp.Auth(context.TODO())

Then we can get a UID from the ID token:

authToken = client.VerifyIDToken(context.TODO(), idToken)
authToken.UID

That’s quite straightforward, but how can we get an ID token to test with? The easiest way I’ve found is to create a custom token using the Admin SDK passing the UID we can find on the Firebase console.

customToken, err := client.CustomToken(context.TODO(), "<UID>")

Then create a Web app on Firebase console and use its API key to transform it into an ID token.

payload, err := json.Marshal(map[string]string{"token": customToken, "returnSecureToken": "true"})

response, err := http.Post(
"https://www.googleapis.com/identitytoolkit/v3/relyingparty/verifyCustomToken?key=<API_KEY>",
"application/json",
bytes.NewBuffer(payload))

body, err := ioutil.ReadAll(response.Body)

type tokensResponse struct {
   IDToken string
}
var tokens tokensResponse
json.Unmarshal(body, &tokens)

tokens.IDToken

And that’s it, we have an ID token that we can pass to client.VerifyIDToken.

Hopefully I could save you some time!

For dependency management I’m using go mod. As far as I know that’s the recommended — and in my experience the most convenient — way.
All you do is go mod init then check in the created files.

This is how my current bitbucket-pipelines.yml looks like:

image: golang:1.12

pipelines:
  default:
    - step:
        caches:
          - gomodules
        script:
          - if [ ! -d "vendor" ] || [ -z "$(ls -A vendor)" ]; then go mod vendor; fi
          - go test -mod=vendor ./...
definitions:
  caches:
    gomodules: vendor

What happens here?
Define a cache called gomodules by specifying the directory name vendor .
Run go mod vendor if the vendor folder doesn’t exist or empty.
Execute the tests.

FYI: The cache will only be uploaded if the build passes, and if you add a new dependency then you’ll have to invalidate the cache from the UI. Maybe I’ll improve this to handle that, or if you do so, please comment! :)

For further information on caching: https://confluence.atlassian.com/bitbucket/caching-dependencies-895552876.html

I appreciate feedback.
If this was useful to you click applaud below. Thank you!

“Just tried some searching and couldn’t do much with it — it kills the browser. I guess we should add some debouncing (if not already added) to it and approach searching smarter, the DOM is probably super heavy for that, could be even filtered with ajax.”

first comment: “Ember UI anyone?”

After just a few seconds, we are thinking about rewriting something — classic. ;)

But what is actually taking that much time?
As we are talking about a client side search we turn to Chrome’s profiler.

Developer Tools / Profiles

Load the page, start recording, search, stop recording, results:

Let’s not get lost in the numbers too much: 39 seconds, CSS. That’s a clue. The source was simple enough to quickly find these:

showElements: (elements) ->
  @list.find(elements).parents(@listElement).slideDown()

hideElements: (elements) ->
  @list.find(elements).parents(@listElement).slideUp()

What if we just…

showElements: (elements) ->
  @list.find(elements).parents(@listElement).show()

hideElements: (elements) ->
  @list.find(elements).parents(@listElement).hide()

Measuring…

Voilà!