CODEWITHSUNDEEP
ruby-on-railsdelaypumaaws-application-load-balancerrequest-queueing
brahmana
brahmana

Reputation: 1326

Puma starts processing a request 8-10 seconds after ALB has forwarded it

I have a regular Ruby on Rails application with Puma server running with the configuration -w 1 -t 1:1 (i.e. one worker and one thread). This is deployed on an EC2 instance, fronted by an AWS ALB. Pretty standard setup as seen below.

enter image description here

Recently we started observing slowness for certain requests at specific times. On checking the ALB logs, I found several requests with Target Processing Time greater than 8 - 10 seconds. When I look up the same requests (based on the request method, path, client IP and request time range) in the Rails log, the requests are shown as having been processed in a few milliseconds.

The odd part is that the timestamp of the Started line in Rails log itself is 8-10 seconds later compared to the request received timestamp in the ALB logs. As per ALB logs, it spent about a 1 millisecond to forward the request to the target. So the requests were not stuck at the ALB for that duration.

AWS ALB has a connect timeout of 10s (i.e. the target should accept the TCP connection within 10s). If not the request is not considered forwarded and marked as Error. Since that is not the case for these requests, the EC2 machine has accepted the connections within that limit.

Ref : Check request_processing_time description here https://docs.aws.amazon.com/elasticloadbalancing/latest/application/load-balancer-access-logs.html#access-log-entry-syntax

So, it appears that the requests were queued at the OS level or the Puma master level for that period of 8-10 seconds, after which point it was handed to the worker to process the request.

Questions :

  1. Where are my requests getting stuck? How can I find it out?
  2. How can I find out what is causing this delay?
  3. Is there a metric I can monitor to get alerted about such scenarios?

Upvotes: 0

Views: 41

Answers (1)

Greg
Greg

Reputation: 61

How many Puma servers are you running?

If you have one server running -w1 -t1:1, only one request can be processed at a time.

If a large number of requests hit the server at the same time, they will sit in the OS's backlog until Puma can process them.

Upvotes: 1

Related Questions