Question

A while ago I read an article stating that overhead of an async/await call was around 50ms. More recently I read an article that it was around 5ms. I was having a discussion about whether we should standardize async operations for all DB access and decided to take a crack at measuring it myself. And I ended up adding the following methods to a controller:

private int profileIterations = 1000;
[HttpGet]
public long NonAsyncLoop()
{
    var timer = new System.Diagnostics.Stopwatch();
    timer.Start();
    for (int i = 0; i < profileIterations; i++)
    {
        Thread.Sleep(5);
    }
    timer.Stop();
    return timer.ElapsedMilliseconds;
}

[HttpGet]
public async Task<long> AsyncLoop()
{
    var timer = new System.Diagnostics.Stopwatch();
    timer.Start();
    for (int i = 0; i < profileIterations; i++)
    {
        await Task.Delay(5);
    }
    timer.Stop();
    return timer.ElapsedMilliseconds;
}

This test returns surprisingly regular results indicating that the overhead of calling await Task.Delay() vs Thread.Sleep() is ~1/3 of a ms. Does anyone have any other easy test that could indicate the overhead? Because below 10ms of overhead it becomes a no-brainer to standardize async operations for all DB access.

The other devs and I are deciding about whether to just use async for all DB operations going forward, the app we're working with has all synchronous DB IO, so there is a possibility we may be converting large amounts of existing access when the opportunity arises.

To get an idea of DB latency I'm looking at app insights request profiles and looking at items listed under "SQL (Azure Database) Activities". Most of these "activities" show wait times of between 1 and 5ms. So if my test is roughly accurate, then using async/await for all DB access is clearly the way to go moving forward, and existing synchronous access should be converted whenever practical. However, if overhead is in the 5-50ms range, then using async would actually decrease thread availability while making response time slower simultaneously.

Was it helpful?

Solution

Overhead is less than 0.1 ms

The rest of the answer is how I got that.

I decided to introduce a version of the code that uses Task.Run(()=> Thread.Sleep(waitTime)) which I consider a fairer comparison to simply sleep. So I have three versions.

I'm also compute how much time the code is not waiting. That is, I define how many iterations profileIterations, how much to wait waitTime, and then I multiply them so I know how much time is supposed to be expended waiting… Subtract that from the total time. Then I profileIterations so I know how much time is not waiting per iteration.


This is the code:

Sleep version

int profileIterations = 1000;
int waitTime = 5;
var timer = new System.Diagnostics.Stopwatch();
timer.Start();
for (int i = 0; i < profileIterations; i++)
{
    Thread.Sleep(waitTime);
}
timer.Stop();
Console.WriteLine((timer.ElapsedMilliseconds - waitTime * profileIterations) / (double)profileIterations);

Task.Run version

int profileIterations = 1000;
int waitTime = 5;
var timer = new System.Diagnostics.Stopwatch();
timer.Start();
for (int i = 0; i < profileIterations; i++)
{
    await System.Threading.Tasks.Task.Run(()=> Thread.Sleep(waitTime));
}
timer.Stop();
Console.WriteLine((timer.ElapsedMilliseconds - waitTime * profileIterations) / (double)profileIterations);

Delay version

int profileIterations = 1000;
int waitTime = 5;
var timer = new System.Diagnostics.Stopwatch();
timer.Start();
for (int i = 0; i < profileIterations; i++)
{
    await System.Threading.Tasks.Task.Delay(waitTime);
}
timer.Stop();
Console.WriteLine((timer.ElapsedMilliseconds - waitTime * profileIterations) / (double)profileIterations);

And these are the times:

  • Sleep version: 10.605
  • Task.Run version: 10.584
  • Delay version: 10.814

Task.Run(()=> Thread.Sleep(waitTime)) appears to be faster than Thread.Sleep(waitTime), which is nonsensical. This measurement is clearly wrong.

Yeah, it is waiting around 15 to 16 milliseconds instead of 5 (it is waiting around 10 extra milliseconds). Because time resolution is a thing. See Can I improve the resolution of Thread.Sleep? So I tried with waitTime = 16, got these:

  • Sleep version: 14.181
  • Task.Run version: 14.82
  • Delay version: 15.113

Now it is waiting about 30 milliseconds? Let us set waitTime = 30, got these:

  • Sleep version: 1.288
  • Task.Run version: 1.432
  • Delay version: 1.561

Ha! - Let us do better. Change timer.ElapsedMilliseconds (long) to timer.Elapsed.TotalMilliseconds (double), and we have better resolution.

Got these:

  • Sleep version: 1.3736827000000011
  • Task.Run version: 1.4033598999999994
  • Delay version: 1.7195541999999986

Not all of those digits are significant. Stopwatch can't report below 0.0001 milliseconds (100 nanoseconds) in my computer.

It appears that Delay is slower always. It is not a fair comparison anyway. Between the other two… This measurements suggest an overhead of 0.03 to 0.1 milliseconds from Task.Run and await.


Let us replace Thread.Sleep with Thread.SleepWait, this time we will have the thread spin!

This is the new code:

SpinWait version

int profileIterations = 1000;
int iterations = 1000;
var timer = new System.Diagnostics.Stopwatch();
timer.Start();
for (int i = 0; i < profileIterations; i++)
{
    Thread.SpinWait(iterations);
}
timer.Stop();
Console.WriteLine(timer.Elapsed.TotalMilliseconds / (double)profileIterations);

New Task.Run version

int profileIterations = 1000;
int iterations = 1000;
var timer = new System.Diagnostics.Stopwatch();
timer.Start();
for (int i = 0; i < profileIterations; i++)
{
    await System.Threading.Tasks.Task.Run(()=> Thread.SpinWait(iterations));
}
timer.Stop();
Console.WriteLine(timer.Elapsed.TotalMilliseconds/ (double)profileIterations);

And these are the new results:

  • SpinWait version: 0.0410909
  • New Task.Run version: 0.053339

Increased to iterations = 10000, got these:

  • SpinWait version: 0.3893809
  • New Task.Run version: 0.4080467

That settles it for me. The overhead is between 0.01 and 0.02 milliseconds. Including both Task.Run and await.

I tried increasing the iterations even more, and that gave me a larger overhead. I believe at that point I'm no longer measuring overhead but the interference of other processes. However, if you are curious, it only got up to 0.06 milliseconds. Which is still below the 0.1 milliseconds I got using Sleep.


Finally, I want to mention that an async method that finished synchronously will have less overhead that one that did not. Similarly using ValueTask instead of Task can reduce overhead and allocations.


This tests were done in Windows 10, .NET 5.0, Intel I3. Oh, and using LINQPad. Yeah, LINQPad.

OTHER TIPS

Let me ask you this very politely, Ian ... "Why do you – as (of course) a professional software engineer – feel that you actually need to care about this?" If you're "accessing a database," isn't that going to involve far more "inherent timing uncertainty" than you are quibbling about here?

"Overhead" really matters only if it prevents you from being able to do something that you really need to be able to do at the time. Such that it actually makes a difference. With utter and complete respect to you, sir, I very simply do not yet see the cause of your present concern. Please tell me what I am overlooking.

Licensed under: CC-BY-SA with attribution
scroll top