A variation of ThreadPool starvation or a bug?

[soykar1]

Description

I ran into a thread-pool/timer "starvation" situation I haven't seen before.
It doesn't seem to be the case of neither debug-threadpool-starvation nor another case from Kevin Gosse.

Even though it resembles the later, it manifests differently.
The ThreadPool Thread Count remains very low at a constant value of 5-6 and never increases.
The ThreadPool Queue Length oscillates between 6-30.
The TimerCallback is called once and then it "stalls", even though an expectation is that it should be called every second.

ThreadPool Completed Work Item Count (Count / 1 sec)                  68
ThreadPool Queue Length                                               18
ThreadPool Thread Count                                                6
Time spent in JIT (ms / 1 sec)                                         0

0:013> !sos.threadpool
logStart: 0
logSize: 7
CPU utilization: 31 Worker Thread: Total: 5 Running: 5 Idle: 0 MaxLimit: 32767 MinLimit: 4
Work Request in Queue: 0
--------------------------------------
Number of Timers: 0
--------------------------------------
Completion Port Thread:Total: 1 Free: 1 MaxFree: 8 CurrentLimit: 1 MaxLimit: 1000 MinLimit: 4

0:012> !tpq
global work item queue________________________________
0x00000191A23568C0 System.Threading.Tasks.Task<System.Threading.Tasks.Task>
0x00000191A2356830 System.Threading.Tasks.Task<System.Threading.Tasks.Task>
0x00000191A23567A0 System.Threading.Tasks.Task<System.Threading.Tasks.Task>
0x00000191A2356710 System.Threading.Tasks.Task<System.Threading.Tasks.Task>
0x00000191A2356680 System.Threading.Tasks.Task<System.Threading.Tasks.Task>

local per thread work items_____________________________________
0x00000191A23E9E28 Task | NetCore.Program+c.b__1_1
0x00000191A23E9E68 Task | NetCore.Program+c.b__1_1
0x00000191A23E9EA8 Task | NetCore.Program+c.b__1_1
0x00000191A23E9EE8 Task | NetCore.Program+c.b__1_1
0x00000191A23F1C08 Task | NetCore.Program+c.b__1_1
0x00000191A23F1C48 Task | NetCore.Program+c.b__1_1
0x00000191A23F1C88 Task | NetCore.Program+c.b__1_1
0x00000191A23F1CC8 Task | NetCore.Program+c.b__1_1
0x00000191A23F1D08 Task | NetCore.Program+c.b__1_1
0x00000191A23EFC08 Task | NetCore.Program+c.b__1_1
0x00000191A23EFC48 Task | NetCore.Program+c.b__1_1
0x00000191A23EFC88 Task | NetCore.Program+c.b__1_1
0x00000191A23EFCC8 Task | NetCore.Program+c.b__1_1
0x00000191A23EFD08 Task | NetCore.Program+c.b__1_1
0x00000191A23EDC08 Task | NetCore.Program+c.b__1_1
0x00000191A23EDC48 Task | NetCore.Program+c.b__1_1
0x00000191A23EDC88 Task | NetCore.Program+c.b__1_1
0x00000191A23EDCC8 Task | NetCore.Program+c.b__1_1
0x00000191A23EDD08 Task | NetCore.Program+c.b__1_1
0x00000191A23EBC08 Task | NetCore.Program+c.b__1_1
0x00000191A23EBC48 Task | NetCore.Program+c.b__1_1
0x00000191A23EBC88 Task | NetCore.Program+c.b__1_1
0x00000191A23EBCC8 Task | NetCore.Program+c.b__1_1
0x00000191A23EBD08 Task | NetCore.Program+c.b__1_1

   24 Task  NetCore.Program+c.b__1_1
 ----
   24

0:011> !pstacks
________________________________________________
 ~~~~ 3454
    1 (dynamicClass).IL_STUB_PInvoke(IntPtr, Byte*, Int32, Int32 ByRef, IntPtr)
    1 System.ConsolePal+WindowsConsoleStream.ReadFileNative(IntPtr, Span, Boolean, Int32 ByRef, Boolean)
    1 System.ConsolePal+WindowsConsoleStream.Read(Span)
    1 System.IO.ConsoleStream.Read(Byte[], Int32, Int32)
    1 System.IO.StreamReader.ReadBuffer()
    1 System.IO.StreamReader.ReadLine()
    1 System.IO.SyncTextReader.ReadLine()
    1 System.Console.ReadLine()
    1 NetCore.Program+d__4.MoveNext()
    1 System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start(__Canon ByRef)
    1 System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start(__Canon ByRef)
    1 NetCore.Program.Main(String[])
    1 NetCore.Program.(String[])
________________________________________________
      ~~~~ 479c
         1 Interop+Kernel32.GetSystemTimes(Int64 ByRef, Int64 ByRef, Int64 ByRef)
         1 System.Threading.PortableThreadPool+CpuUtilizationReader.get_CurrentUtilization()
         1 System.Threading.PortableThreadPool+GateThread.GateThreadStart()
      ~~~~ 3c8c
         1 System.Threading.WaitHandle.WaitOneNoCheck(Int32)
         1 System.Diagnostics.Tracing.CounterGroup.PollForValues()
      ~~~~ 3128,4d50,422c,c14...
         5 System.Threading.Thread.Sleep(Int32)
         5 NetCore.Program+c.b__1_1()
         5 System.Threading.ExecutionContext.RunInternal(ExecutionContext, ContextCallback, Object)
         5 System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task ByRef, Thread)
         5 System.Threading.Tasks.ThreadPoolTaskScheduler.TryExecuteTaskInline(Task, Boolean)
         5 System.Threading.Tasks.TaskScheduler.TryRunInline(Task, Boolean)
         5 System.Threading.Tasks.Task.WrappedTryRunInline()
         5 System.Threading.Tasks.Task.WaitAllCore(Task[], Int32, CancellationToken)
         5 System.Threading.Tasks.Task.WaitAll(Task[])
         5 NetCore.Program.EndlessLoopProcessor()
         5 NetCore.Program+c+<b__4_2>d.MoveNext()
         5 System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start(__Canon ByRef)
         5 System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start(__Canon ByRef)
         5 NetCore.Program+c.b__4_2()
         5 System.Threading.Tasks.Task<System.__Canon>.InnerInvoke()
         5 System.Threading.Tasks.Task+c.cctor>b__272_0(Object)
         5 System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread, ExecutionContext, ContextCallback, Object)
         5 System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task ByRef, Thread)
         5 System.Threading.Tasks.Task.ExecuteEntryUnsafe(Thread)
         5 System.Threading.Tasks.Task.ExecuteFromThreadPool(Thread)
         5 System.Threading.ThreadPoolWorkQueue.Dispatch()
         5 System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()
    7 System.Threading.Thread.StartCallback()

==> 8 threads with 2 roots

The minimal code to reproduce the starvation

private static void TimerCallback(object state) => Console.WriteLine(state?.ToString() + DateTime.UtcNow);

private static void EndlessLoopProcessor()
{
    while (true)
    {
        var ts = Enumerable.Range(0, 6)
                            .Select(_ =>
        Task.Run(() => Thread.Sleep(16))).ToArray();
        Task.WaitAll(ts);

        WaitInsideEndlessLoopProcessor();
    }
}

private static void WaitInsideEndlessLoopProcessor() => Thread.Sleep(100);

private static async Task AwaitEverything()
{
    while (true)
    {
        await Task.Delay(1000); // <-- almost never get pass this await
        TimerCallback("AwaitEverything: ");
    }
}

static async Task Main(string[] args)
{
    var timer = new Timer(TimerCallback, "main: ", 0, 1000);

    var main = Task.Run(async () =>
    {
        var tasks = Enumerable.Range(0, 10)
                                .Select(_ => Task.Run(async () => EndlessLoopProcessor()))
                                .ToArray();

        Console.WriteLine(DateTime.UtcNow);
        Console.WriteLine("-----------------");

        await AwaitEverything();
    });

    Console.WriteLine("Press enter to end.");
    Console.ReadLine();
    await main;
    GC.KeepAlive(timer);
}

Questions

Based on the referenced articles, I assumed/verified that EndlessLoopProcessor keeps local thread-pool queues full.
What I don't understand is why the timer callback is never executed?
If callbacks in the global queue are never processed due to all running worker threads are busy processing
their local queues, why thread-pool simply doesn't spawn a new worker thread?
If my assumption regarding timer callback being queued into the global queue is correct, it's even more puzzling, because when I inspected the global queue I wasn't able to find the timer callback there (I might just missed it though).

When I attach debugger and freeze/un-freeze threads executing EndlessLoopProcessor there is a high chance the program "un-stalls" and continues as would be expected, that is, the TimerCallback gets called every second.
When this happens !sos.threadpool shows that number of worker threads is higher than it used to be.
That might explain why the timer callbacks resume, because now there is a worker thread which can process the timer callback.

Why doesn't the thread-pool increase the number of worker threads itself?

In the following scenarios, the thread-pool does increase the number of worker threads.

// timer callback thread blocked scenario
var t = new Timer(state => {
    Console.WriteLine("x");
    Thread.Sleep(TimeSpan.FromMinutes(100));
}, null, 0, 1000);

Console.ReadLine();
GC.KeepAlive(t);

// worker thread blocked scenario 
for (int i = 0; i<1000; i++)
{
    Task.Run(() =>
    {
        Console.WriteLine("x");
        Thread.Sleep(TimeSpan.FromMinutes(10));
    });

    await Task.Delay(1000);
}

Remarks

Just to be clear, I'm not interested in how to solve this situation, because it's obvious - don't block the thread pool thread as EndlessLoopProcessor does (using a dedicated thread for EndlessLoopProcessor does the trick, either creating it manually or using Task.Factory.StartNew with TaskCreationOptions.LongRunning hint which essentially does the same).

I'm curious, why the thread-pool doesn't self-tune by increasing the number of worker threads?

I observed this behavior on .NET Framework 4.8, .NET Core 3.1 and .NET 6.