Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ThreadPool.CompletedWorkItemCount double counting IO completion work items #104284

Open
markalward opened this issue Jul 2, 2024 · 1 comment
Assignees
Milestone

Comments

@markalward
Copy link

Description

While upgrading a service from .NET 6 to .NET 8, we noticed that the 'Thread Pool Completed Work Item Count' counter values roughly doubled for our app. Based on the repro below, I believe that .NET 8 may be double-counting IO completion work items in the ThreadPool.CompletedWorkItemCount property that this counter is based on, so that the counter is no longer accurate.

Reproduction Steps

// Submit one IO completion work item per second and log ThreadPool.CompletedWorkItemCount
// to console.
public static void Main(string[] args)
{
    while (true)
    {
        SubmitIOCompletion();
        Thread.Sleep(1000);
        Console.WriteLine(ThreadPool.CompletedWorkItemCount);
    }
}

// Manually submit an IO completion packet to the thread pool and wait
// for the callback to run.
// Note: Calling Socket.ConnectAsync(...).GetAwaiter().GetResult() or any other guaranteed-async API
// gives the same repro as this code.
private static unsafe void SubmitIOCompletion()
{
    using var manualResetEvent = new ManualResetEventSlim(false);

    var overlapped = new Overlapped();
    NativeOverlapped* nativeOverlapped = overlapped.Pack((errorCode, numBytes, innerNativeOverlapped) =>
    {
        Overlapped.Free(innerNativeOverlapped);
        manualResetEvent.Set();
    }, null);

    ThreadPool.UnsafeQueueNativeOverlapped(nativeOverlapped);
    manualResetEvent.Wait();
}

Expected behavior

On .NET 6, this code prints:

1
2
3
4
...

The code is kicking off 1 IO completion per second, and ThreadPool.CompletedWorkItemCount counts 1 work item per second as expected.

Actual behavior

On .NET 8, this code prints:

3
6
9
12
...

The code is now counting 3 work items per second.

Regression?

Yes - regression from .NET 6.

Known Workarounds

No response

Configuration

.NET 8.0.302
Windows 11
x64

Other information

Compute work items submitted using ThreadPool.QueueUserWorkItem() don't repro this issue. It seems to be specific to IO completions.

I tried setting breakpoints on calls to ThreadInt64PersistentCounter.Add()/Increment() and found that the the same worker thread would increment the counter twice per work item, from these two different call stacks:

Stack 1
System.Private.CoreLib.dll!System.Threading.ThreadInt64PersistentCounter.Increment(object threadLocalCountObject)
System.Private.CoreLib.dll!System.Threading.PortableThreadPool.NotifyWorkItemProgress(object threadLocalCompletionCountObject, int currentTimeMs)
System.Private.CoreLib.dll!System.Threading.PortableThreadPool.NotifyWorkItemComplete(object threadLocalCompletionCountObject, int currentTimeMs)
System.Private.CoreLib.dll!System.Threading.ThreadPool.NotifyWorkItemComplete(object threadLocalCompletionCountObject, int currentTimeMs)
System.Private.CoreLib.dll!System.Threading.ThreadPoolWorkQueue.Dispatch()
System.Private.CoreLib.dll!System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

Stack 2
System.Private.CoreLib.dll!System.Threading.ThreadPoolTypedWorkItemQueue<System.Threading.PortableThreadPool.IOCompletionPoller.Event, System.Threading.PortableThreadPool.IOCompletionPoller.Callback>.System.Threading.IThreadPoolWorkItem.Execute()
System.Private.CoreLib.dll!System.Threading.ThreadPoolWorkQueue.Dispatch()
System.Private.CoreLib.dll!System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

I also found that another worker thread would wake up each second, find 0 work items to consume, and go back to sleep. This was also hitting the NotifyWorkItemProgress() breakpoint (Stack 1), and explains the 3rd increment to the counter that happens every second.

@dotnet-policy-service dotnet-policy-service bot added the untriaged New issue has not been triaged by the area owner label Jul 2, 2024
Copy link
Contributor

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

@mangod9 mangod9 removed the untriaged New issue has not been triaged by the area owner label Jul 3, 2024
@mangod9 mangod9 added this to the 9.0.0 milestone Jul 3, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants