18

My understanding is that ASP.NET Core middleware is run when a request is ready to be processed. But if the app is under load and ASP.NET Core can not process all the requests as they come in, they are put in a "queue" somewhere? I don't know whether this is some managed queue inside Kestrel or whether it has something to do with libuv.

I would like to be able to know how long a given request is spent in this queue. Is there something on HttpContext that can tell me this?

Thanks in advance

ChrisBellew
  • 1,144
  • 2
  • 12
  • 27
  • Out of interest, why does queue time matter? – DavidG Feb 13 '17 at 02:47
  • Because I want to attribute the lost time spent making a request to my service, whose logs otherwise report a fast request. For example my browser client might see that it took 2 seconds to get a response, but all logs from middleware report a total of 200ms. I want evidence of where that 1.8s was. Thanks for your attention :) – ChrisBellew Feb 13 '17 at 02:50
  • And what makes you think the missing time is due to the request queue? – DavidG Feb 13 '17 at 02:52
  • It's one of the possiblities. It may not be but I don't know that. – ChrisBellew Feb 13 '17 at 02:52
  • I'd be very surprised if that was the case. Kestrel can handle 5 million requests per second according to some benchmarks. – DavidG Feb 13 '17 at 02:53
  • But my app can't. What happens to the requests as my app is waiting to serve them? – ChrisBellew Feb 13 '17 at 02:54
  • How many threads have you given it? How many requests per second are you throwing at it? – DavidG Feb 13 '17 at 02:55
  • 1
    I haven't changed the thread count from default. It can handle about 200r/s and there are occasional spikes with more than that, maybe 300-400. I'm supposing that a request unlucky enough to have arrived as a spike is happening will go into a queue and wait there. – ChrisBellew Feb 13 '17 at 02:58
  • @ChrisBellew, did you manage to get something? I am in the similar soup, my server logs shows request completed in 2s while client show, it took 5s. Where did extra 3s when in the network? Latency, network translation, payload transmission, queue, etc... – Shabbir Apr 10 '17 at 06:16
  • Sorry, I didn't manage to find anything – ChrisBellew Apr 10 '17 at 06:33
  • @ChrisBellew, don't you love to get these "don't do it" instead of answers. I need to know the same thing because I need to track that specific value to understand where the time is spent. And it is disheartening to find these sideways discussions. – Tjunkie Oct 27 '21 at 17:09

1 Answers1

4

This question is not that easy.

If you want to track all of the times, you have to do a lots of steps. At the beginning add a unique stamp or the ticks to the requests, so you can identify them one by one. Second, create a handler, which intercepts your requests and logs the times. Third, add a logging point to every request related method. Fourth - this will be a surprise - you can't do anything big to reduce this time expect the configuration of IIS regarding threading, parallel requests, session handling, etc. Fifth - if your browser measures 2000 ms, your server measures 200 ms, it's not the .NET core, its your code/architecture/config. Sorry to tell you bad news.

Use the System.Diagnostics.Stopwatch class to measure the time.

Dexion
  • 1,101
  • 8
  • 14
  • would the "handler" be invoked while kestrel has not started processing the request i.e. the request is in the queue? – Tjunkie Oct 27 '21 at 16:39