14

So my typical router log on the Cedar platform looks might look like

2012-03-22T18:26:34+00:00 heroku[router]: GET [my_url] dyno=web.9 queue=0 wait=0ms service=228ms status=302 bytes=212
2012-03-22T18:26:36+00:00 heroku[router]: GET [my_url] dyno=web.7 queue=0 wait=0ms service=23ms status=200 bytes=360
2012-03-22T18:26:45+00:00 heroku[router]: GET [my_url] dyno=web.30 queue=0 wait=0ms service=348ms status=201 bytes=1

I want to confirm my understanding of the terms queue, wait and service

My initial thoughts where that:

  • queue: The name of the queue if using background_job or resque
  • wait: how long is the request waiting in the router (Request Queueing in New Relic)
  • service: how long it actually takes your application to handle the request (not including queing time)

But my wait in my logs is always 0ms. Even if I have significant backlog.

Are my definitions wrong?

Jonathan
  • 16,077
  • 12
  • 67
  • 106
  • You say your wait is always 0ms, if the queue is also 0, how do you know you have a backlog outside of this? – Douglas F Shearer Mar 22 '12 at 19:19
  • So for example, take serving my crossdomain.xml -- a static file, that on low loads response within 10ms. At high loads it can be 6000ms+ all the way up to the 30s timeout. I would expect most of that time to be on queue and wait. – Jonathan Mar 22 '12 at 19:55
  • Also, when I add more dynos, the service time goes down, and vice-versa – Jonathan Mar 22 '12 at 20:05

1 Answers1

12
  • Queue: The number of requests waiting to be processed by a dyno.
  • Wait: The length of time this request sat in the queue before being processed.
  • Service: The processing time of the request.

Your total response time will be wait + service.

friism
  • 19,068
  • 5
  • 80
  • 116
Douglas F Shearer
  • 25,952
  • 2
  • 48
  • 48
  • Can you explain a bit more what "service" means? Does it mean, the time it took to run through whatever scripts before sending a response or is it some internal timer that doesn't have anything to do with the code one wrote? – dsp_099 Jul 17 '12 at 16:24
  • "the time it took to run through whatever scripts before sending a response" - This. – Douglas F Shearer Jul 25 '12 at 09:50
  • As a caveat, the "service" time seems to take into account network time. This is most likely similar to how "time-taken" in IIS logs works. http://www.microsoft.com/technet/prodtechnol/WindowsServer2003/Library/IIS/676400bc-8969-4aa7-851a-9319490a9bbb.mspx?mfr=true I base this off a comparison of some long running items (~20+ sec) according to "service", and comparing with the breakdown given by new relic's "real user monitoring" which indicates nearly 100% of that time is "network" time. – Jody Oct 04 '12 at 16:58
  • 2
    I can confirm the above - and if you're using Heroku's SSL Endpoint you seem to take a big hit. I see great figures in New Relic for my app, but the logs and Blitz.io both agree that performance collapses at about 50 requests per second per dyno. – Thom Jan 17 '13 at 11:42
  • 1
    I do not see queue information in Heroku Logs.. do you I need to enable it in some way? Or have they removed this.. – Inc1982 Mar 27 '13 at 23:52
  • 1
    They may have removed this as they changed the stats after Hipmunk called them out for publishing misleading stats. Have a look at some of Heroku's recent blog posts. – Douglas F Shearer Mar 28 '13 at 09:43
  • How did you get these definitions? Can someone provide a URL to some docs? I see https://devcenter.heroku.com/articles/logging and it isn't precise with definitions. – dfrankow Apr 08 '21 at 20:52