Underutilization of TimerQueue when application runs with CPU affinity

[ezsilmar]

Description

There's a sharding mechanism in TimerQueue that selects the queue based on the current CPU id

_associatedTimerQueue = TimerQueue.Instances[Thread.GetCurrentProcessorId() % TimerQueue.Instances.Length];

This doesn't work as expected when the application is bound to specific cores.

For instance, with 32-core server you may have 4 numa nodes each containing 8 logical cores, where every pair of logical cores is backed by a single physical core. In this case, the cpuset of first numa node may look like this: [0, 1, 2, 3, 16, 17, 18, 19] as Linux enumerates first the physical cores, then their HT counterpart.

This leads to underutilization of the timer queues as we'd only use the first 4 due to modulo.

Reproduction Steps

for (var i = 0; i < 100; i++) 
{
   Task.Run(() => Task.Delay(10*60*1000 + i));
}
Console.ReadKey();

Run it with

taskset -c 0,1,4,5 dotnet ./TimerRepro.dll

Then take a memory dump of the process and find the timer queues:

dotnet-dump ps
dotnet-dump collect -p <pid>
dotnet-dump analyze <dumpfile>

dumpheap -stat
do -mt <timerqueue_mt>
do <timerqueue>
dumparray -details <timerqueue_instances>

You'll observe that queues 0 and 1 are utilized while queues 2 and 3 are empty. Sample output (only interesting part):

                      MT    Field   Offset                 Type         VT     Attr                    Value     Name
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                   86     <ActiveCount>k__BackingField
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                   14     <ActiveCount>k__BackingField
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                    0     <ActiveCount>k__BackingField
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                    0     <ActiveCount>k__BackingField

Expected behavior

All timer queues are utilized

Actual behavior

Depending on CPU ids only some queues are utilized

Regression?

No response

Known Workarounds

Some options that comes to mind:

• Introduce more complex logic similar to what GC does with affinity ranges: querying the number of CPUs on the machine, then querying the affinity mask, filtering CPUs to available ones and building a dictionary cpuid => TimerQueue
• Always create timerqueues equal to the number of total cores on the machine, even if we won't use all of them
• Not use the CPU id but a thread id or any other sharding key

Configuration

Observed on dotnet 6.0.12 WSL2 Ubuntu and dotnet 5.0.x CentOS 7 but the code is the same in newer versions.

Other information

Are there other places in the runtime where the same sharding is utilized?

Tagging subscribers to this area: @mangod9
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Description

There's a sharding mechanism in TimerQueue that selects the queue based on the current CPU id

_associatedTimerQueue = TimerQueue.Instances[Thread.GetCurrentProcessorId() % TimerQueue.Instances.Length];

This doesn't work as expected when the application is bound to specific cores.

For instance, with 32-core server you may have 4 numa nodes each containing 8 logical cores, where every pair of logical cores is backed by a single physical core. In this case, the cpuset of first numa node may look like this: [0, 1, 2, 3, 16, 17, 18, 19] as Linux enumerates first the physical cores, then their HT counterpart.

This leads to underutilization of the timer queues as we'd only use the first 4 due to modulo.

Reproduction Steps

for (var i = 0; i < 100; i++) 
{
   Task.Run(() => Task.Delay(10*60*1000 + i));
}
Console.ReadKey();

Run it with

taskset -c 0,1,4,5 dotnet ./TimerRepro.dll

Then take a memory dump of the process and find the timer queues:

dotnet-dump ps
dotnet-dump collect -p <pid>
dotnet-dump analyze <dumpfile>

dumpheap -stat
do -mt <timerqueue_mt>
do <timerqueue>
dumparray -details <timerqueue_instances>

You'll observe that queues 0 and 1 are utilized while queues 2 and 3 are empty. Sample output (only interesting part):

                      MT    Field   Offset                 Type         VT     Attr                    Value     Name
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                   86     <ActiveCount>k__BackingField
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                   14     <ActiveCount>k__BackingField
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                    0     <ActiveCount>k__BackingField
        00007f40f009b3b8  4000b2b       30             System.Int64      1     instance                    0     <ActiveCount>k__BackingField

Expected behavior

All timer queues are utilized

Actual behavior

Depending on CPU ids only some queues are utilized

Regression?

No response

Known Workarounds

Some options that comes to mind:

• Introduce more complex logic similar to what GC does with affinity ranges: querying the number of CPUs on the machine, then querying the affinity mask, filtering CPUs to available ones and building a dictionary cpuid => TimerQueue
• Always create timerqueues equal to the number of total cores on the machine, even if we won't use all of them
• Not use the CPU id but a thread id or any other sharding key

Configuration

Observed on dotnet 6.0.12 WSL2 Ubuntu and dotnet 5.0.x CentOS 7 but the code is the same in newer versions.

Other information

Are there other places in the runtime where the same sharding is utilized?

Author:	ezsilmar
Assignees:	-
Labels:	area-System.Threading, untriaged, needs-area-label
Milestone:	-

[verdie-g]

Hi @stephentoub, I think you might be interested by this. It has become an important issue in some of our services that are using many Task.Delay as a timeout mechanism.

Having as many TimerQueue as cores on the machine looks like a simple fix, however I'm not sure if there is already a way to get the total number of cores on the machine from managed code. I've seen it's already used in native code, in the gc for example. Any idea?

[stephentoub]

It has become an important issue in some of our services that are using many Task.Delay as a timeout mechanism.

Are you sure it's related to this issue?

For example, are you canceling your Task.Delays when the thing you're using it to timeout completes? What does your code for creating those tasks look like?

[verdie-g]

I was wondering the same because when looking at the contention events in perfview I can only see FireQueue something. So I've compared an instance with the Task.Delay removed and I could see a 40% contention decrease.

All these metrics are collected from event counters.

[verdie-g]

By the way, this logic found in Timer

runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs

Line 511 in 17ed091

_associatedTimerQueue = TimerQueue.Instances[Thread.GetCurrentProcessorId() % TimerQueue.Instances.Length];

can also be found here

runtime/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs

Line 359 in 17ed091

int i = (int)((uint)Thread.GetCurrentProcessorId() % (uint)Environment.ProcessorCount);

runtime/src/libraries/System.Private.CoreLib/src/System/Buffers/TlsOverPerCoreLockedStacksArrayPool.cs

Line 324 in 17ed091

int index = (int)((uint)Thread.GetCurrentProcessorId() % (uint)s_lockedStackCount); // mod by constant in tier 1

[stephentoub]

I can only see FireQueue something

That's my point. Timers used for timeouts should rarely be firing. This sounds like more likely to be a bug in your code failing to cancel those tasks.

[ezsilmar]

But even if we cancel the timer, it would still take a lock on this path creating contention?

To give a bit more context, in one other application where we have latency constraints (i.e. it's better to answer something in 200ms than waiting for the dependency to answer our http request) many timers are created and destroyed frequently. We observe high spikes in thread pool queue (and latency) every couple of minutes, which we connect with two other observations: 95% of all contention events are in TimerQueue, and the high number of exceptions (as ~12% of all requests end up cancelled).

The affinity issue is one of the mitigations we think of, but we also want to change how we use timeouts in HttpClient to trigger OperationCancelledException and NetworkException less frequently. Something like this:

using (var cts = new CancellationTokenSource())
{
  cts.CancelAfter(TimeSpan.FromSeconds(5)); // set large timeout here
  
  var realTimeoutTask = Task.Delay(200); // the timeout we actually use
  var responseTask = httpClient.SendAsync(request, cts.Token);
   
  await Task.WhenAny(realTimeoutTask, responseTask);

  if (!responseTask.IsCompleted)
  {
    responseTask.ContinueWith(x => { ... }); // read the body to be able to reuse http connection
    return GetTimeoutResult();
  }
}

However this solution creates even more timers so we want to fix contention issue in any case.

[stephentoub]

We observe high spikes in thread pool queue (and latency) every couple of minutes

Canceled timers would not be queuing any work items.

var realTimeoutTask = Task.Delay(200);

This is how Task.Delay should not be used for timeouts.

I'd urge you to fix how you're implementing timeouts before assuming this issue is related. You should also look into using Task.WaitAsync is your goal is to timeout a wait on a Task, as it appears to be.

What OS are you running on? What .NET version? And what evidence do you have that affinity is causing you to use fewer timer queues?

[stephentoub]

(I just realized the most recent response was from @ezsilmar... I thought I was responding to @verdie-g. Comments about timeouts still apply, though.)

[stephentoub]

But even if we cancel the timer, it would still take a lock on this path creating contention

The lock is held for much longer when firing than when creating/destroying, and how long it's held is impacted by how many active timers there are.

[danmoseley]

Regardless, the modulo scheme will fail to lead to one queue per core, right?