ServiceStack Request timestamps for debugging

Does ServiceStack provide/add any request timestamps of when the request started? Or do we need to add our own middleware?

Currently trying to debug an issue where many browser POST requests (under 64B) are stalled on “Waiting (TTFB)” for over a minute (1.8 min), but the timings (cache / db / bizlogic) within the SS MyService.Post() are under a second total.

When it works normally it returns a request in around 780ms to 925ms.

The issue seems to happen when there is a sudden increase in MyService.Post(), e.g. 100 or 200 Posts within several seconds.

There are some global request filters but nothing with db/cache calls. Just adding cookie if not exists (which they should in this case).

There is nothing to return, other than status 204 No Content.
The MyService.Post() is async.

Do you have any other suggestions on debugging this issue?

Note: Increasing the server size dropped the “Waiting (TTFB)” avg to 12.50 sec to 13.80 sec (still longer than wanted) instead of ~1.8 min. This was done to mainly determine that it wasn’t a browser related issue and that we don’t really want to scale up for semi rare instances of these sudden increase in posts.

ServiceStack only adds a Stopwatch if you have a Request Logger configured which you can resolve throughout your Request Pipeline with:

var stopWatch = req.GetItem(Keywords.RequestDuration) as Stopwatch;

Normally I’d use a profiler like dotTrace to identify performance issues. For Remote Apps you can look into something like Application Insights.

I briefly used dotTrace many many years ago… Edition 5 I think… so I’m still learning what all the new dotTrace has to offer.

In the mean time below is dotTrace of the “Hot Spots”. I was rather surprised that at first look, Redis seems to be the culprit. Assuming I did the performance profile correctly.

There is a redis call in our code apparently that is executed and it uses GeoRadius. Otherwise the other Redis calls are for the SS Session for Auth.

This was against the increased server size and had comparable 12.30 to 13.70 sec responses. I’ll look at the smaller server size tomorrow and see if there are any differences.

May need to look at the Redis servers or network…

1 Like

Also have a look at RedisStats.ToDictionary() (can use .Dump()/.PrintDump() to easily log contents) which provides a snapshot of different counters which may be able to yield some additional insights.

Thanks. Forgot about RedisStats.

Couple questions.

  1. Is there a reason why there aren’t async methods in ServiceStack.Redis?

  2. Do the GlobalRequestFilters execute asynchronously? GlobalRequestFilters.Add(MyRequestFilter.DoSomething);

Nevermind on #2. I keep going to the wrong documentation when searching.
To async GlobalRequestFilters use GlobalRequestFiltersAsync.Add(MyRequestFilter.DoSomething); (e.g. with Async on the end.)

Simply support for them haven’t been added yet, the best way to implement an async library keeps changing, the latest seems to be using the .NET Core 3 Project Bedrock framework (i.e. can’t be used in .NET FX or .NET Core 2.x), which was hyped a lot last year but development on it seems to have slowed down so it’s not clear what the best approach is. But will have to make a decision on what to use later in the year.

Async isn’t going to help making it run faster here, it just helps with server Thread utilization and adds a bit of overhead over sync, the response times from Redis is still going to take the same amount of time. If the issue is with lock contention from using the PooledRedisClientManager, you can try switching to
RedisManagerPool or try increasing the Pool Size (RedisConfig.DefaultMaxPoolSize) (e.g. >100). But this wont help if the issue is with your Networking or Redis Server performance, the only real choice is to cache more or redesign your implementation to use more batched APIs where possible, so you use them less.

1 Like

We use the following ServiceStack.Redis - Accessing the Redis Client when doing Redis operations in the GlobalRequestFilters. I’m assuming that is the recommended way in the GlobalRequestFilters?

var clientsManager = container.Resolve<IRedisClientsManager>();
using (IRedisClient redis = clientsManager.GetClient())
{
    // Redis ops
   redis...
}

We didn’t see a recommended way of doing the operations within a ServiceStack Service, e.g.

public class MyService : Service {
  public async Task<MyResponse> Post(MyDto request) {
       // Redis ops on base.Redis
      Redis...
  }
}

What is your recommended way of doing Redis operations within a ServiceStack Service?

Yes using the base.Redis client is the recommended way to use Redis in Services which gets disposed after the Service is executed