2
votes

We use

HostContext.RawHttpHandlers.Add(action)

to start a time measurement and

m_appHost.PreRequestFilters.Insert(0, action) // we want to be the first filter executed

to stop the time measurement. We sequentially send requests to the server (running on localhost using the IIS Express development server) and observe the time between those two actions. Sometimes it is as low as a few milliseconds but quite often it goes up to a few hundreds of milliseconds. This also happens with lightweight GET requests.

According to https://github.com/ServiceStack/ServiceStack/wiki/Order-of-Operations

  1. HostContext.RawHttpHandlers are executed before anything else, i.e. returning any ASP.NET IHttpHandler by-passes ServiceStack completely and processes your custom IHttpHandler instead.
  2. If the Request doesn't match any existing Routes it will search IAppHost.CatchAllHandlers for a match
  3. The IAppHost.PreRequestFilters gets executed before the Request DTO is deserialized

We also hooked into the CatchAllHandlers to make sure it is not called:

m_appHost.CatchAllHandlers.Insert(0, action)

We register the routes in the AppHost Ctor using attributes like this:

typeof(HelloRequestDTO).AddAttributes(new RouteAttribute("/hello/{Name}", "GET"));

Any idea what could cause this delay after the RawHttpHandler and before the PreRequestFilters?

ServiceStack version is 4.0.50.

1

1 Answers

1
votes

The time measurement was just wrong.

(DateTime.Now - lastDateTime).TotalMilliseconds

returned random values between 50 and 1000 milliseconds.

Using a System.Diagnostics.Stopwatch with

watch.ElapsedMilliseconds - lastMillisecondTime

yields an expected value of 1 - 5 milliseconds duration for the time between the

HostContext.RawHttpHandlers

and the

m_appHost.PreRequestFilters

I didn't think the DateTime imprecision was so high. I will never use it again for millisecond timing.