C#•5mo ago

Slow requests to internal API?

I'm working on an ASP.Net API that, as part of what it does, makes a couple hundred requests to another internal API. I know the other API can handle many more requests per second than I'm trying to do (we've benchmarked it previously with the exact request I'm making to be able to handle a few thousand reqs/sec with no issues). However, the behavior I'm seeing is that it takes ~2-3mins for it to make all of the requests. I'm using RestSharp to do the reqs, with code similar to (but not exactly - wanted to give a simple example) this (where I don't really care too much about the response):

public async Task MyEndpoint() {
    var tasks = new List<Task>();
    foreach (var thing in things) {
        tasks.Add(MakeRequest(thing));
    }
    await Task.WhenAll(tasks);
}

public async Task MakeRequest(MyThing thing) {
    var req = new RestRequest("/endpoint", Method.Post);
    req.AddJsonBody(thing);
    Logger.LogInformation("making request");
    var resp = await Client.ExecuteAsync(req); // also tried with .ConfigureAwait(false) on this
    Logger.LogInformation("made request - response status code is {statusCode}", resp.StatusCode);
}

public async Task MyEndpoint() {
    var tasks = new List<Task>();
    foreach (var thing in things) {
        tasks.Add(MakeRequest(thing));
    }
    await Task.WhenAll(tasks);
}

public async Task MakeRequest(MyThing thing) {
    var req = new RestRequest("/endpoint", Method.Post);
    req.AddJsonBody(thing);
    Logger.LogInformation("making request");
    var resp = await Client.ExecuteAsync(req); // also tried with .ConfigureAwait(false) on this
    Logger.LogInformation("made request - response status code is {statusCode}", resp.StatusCode);
}

Another issue is that when I do something like this to time the request:

    var sw = Stopwatch.StartNew();
    var resp = await Client.ExecuteAsync(req);
    sw.Stop();
    Logger.LogDebug("request took {timeMs} ms", sw.ElapsedMilliseconds);

    var sw = Stopwatch.StartNew();
    var resp = await Client.ExecuteAsync(req);
    sw.Stop();
    Logger.LogDebug("request took {timeMs} ms", sw.ElapsedMilliseconds);

it seems like the timer is actually timing from the start of MyEndpoint, not from rihgt before the request is made to when it finishes? As in, when I asked the team who maintains the service I'm making requests to, they don't see some of the requests being made for over a minute after I start running this with it finishing in (for example) 50ms, but the timer shows it taking 60050 ms.

11 Replies

ACiDCA7•5mo ago

possible threadpool starvation? one of the members here sometime ago provided a talk about it.. lemme quickly find it

ACiDCA7•5mo ago

https://www.youtube.com/live/8lUs9ukVrFY?feature=shared&t=2767

C# Community Discord

YouTube

Solution1: Threads, Tasks and more with Mike Treit

This presentation recaps some of the basics of writing code that makes use of threads, tasks and asynchronous features in C#. It is a modified version of a t...

ACiDCA7•5mo ago

there it is maybe the king, the legend @mtreit can confirm

mtreit•5mo ago

The described symptoms are the kind of thing that indeed happens if you run out of thread pool threads and the initial call can never be scheduled. It waits a long time before it finally gets scheduled on a thread. Then once it is scheduled it completes quite quickly. If you have a repro, attach a debugger and look at how many threads are executing. Or add tracing to the code to log that.

ACiDCA7•5mo ago

👍 who needs courses and books if we have solution1 xD

mtreit•5mo ago

You can use the following helper function to verify how many thead pool threads are currently in use:

public static int GetRunningThreadPoolThreads()
{
    int max, available, ignore;
    ThreadPool.GetMaxThreads(out max, out ignore);
    ThreadPool.GetAvailableThreads(out available, out ignore);
    int running = max - available;
    return running;
}

public static int GetRunningThreadPoolThreads()
{
    int max, available, ignore;
    ThreadPool.GetMaxThreads(out max, out ignore);
    ThreadPool.GetAvailableThreads(out available, out ignore);
    int running = max - available;
    return running;
}

Pearl (asyncmeow)OP•5mo ago

oops, didn't see the replies here until now I thought that's what it was at first as well, but it seems like I had plenty of threads available when I was testing

Pearl (asyncmeow)OP•5mo ago

I ended up getting the team who implemented the other API to just add another endpoint that lets me submit multiple at once - they didn't want to at first (because "you shouldn't ever need this!", but when I told them what we were doing... yeah lol)

mtreit•5mo ago

That looks like you are showing max threads which is not interesting.

Pearl (asyncmeow)OP•5mo ago

This is what I was using to log that:

    public static void LogThreadPoolUsage(this ILogger logger)
    {
        ThreadPool.GetAvailableThreads(out var workerThreads, out var ioThreads);
        logger.LogDebug("Thread pool usage: {worker} worker threads, {io} io threads", workerThreads, ioThreads);
    }

    public static void LogThreadPoolUsage(this ILogger logger)
    {
        ThreadPool.GetAvailableThreads(out var workerThreads, out var ioThreads);
        logger.LogDebug("Thread pool usage: {worker} worker threads, {io} io threads", workerThreads, ioThreads);
    }

mtreit•5mo ago

You want to know how many threads are actually running. Which the code snippet I gave can show you. If you have like 1,000 threads running and you don't have 1,000 CPU cores available you are going to potentially be in a world of hurt. And you probably don't have 1,000 CPU cores. Also, the MinThreads setting is important because the thread pool will try to avoid injecting new threads above that setting. That LogThreadPoolUsage method is (forgive me for being blunt) useless. It gives the same output on any console program:

ThreadPool.GetAvailableThreads(out var workerThreads, out var ioThreads);
Console.WriteLine($"Available worker threads: {workerThreads}, Available IO threads: {ioThreads}");

ThreadPool.GetAvailableThreads(out var workerThreads, out var ioThreads);
Console.WriteLine($"Available worker threads: {workerThreads}, Available IO threads: {ioThreads}");

dotnet run
Available worker threads: 32767, Available IO threads: 1000

dotnet run
Available worker threads: 32767, Available IO threads: 1000

Gaming

Programming

Slow requests to internal API?

Did you find this page helpful?