Assertion failed in PoolingAsyncValueTaskMethodBuilderT

[adamsitnik]

@stephentoub I've found one interesting failure in the logs of the CI run for #56424.

Process terminated. Assertion failed.
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 419
   at System.Threading.Tasks.ValueTask`1.ValueTaskSourceAsTask.<>c.<.cctor>b__4_0(Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/ValueTask.cs:line 638
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SignalCompletion() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 233
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 62
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 250
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 60
   at System.IO.Strategies.BufferedFileStreamStrategy.ReadAsyncSlowPath(Task semaphoreLockTask, Memory`1 buffer, CancellationToken cancellationToken) in /_/src/libraries/System.Private.CoreLib/src/System/IO/Strategies/BufferedFileStreamStrategy.cs:line 492
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.ExecutionContextCallback(Object s) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 389
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 183
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.MoveNext() in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 410
   at System.Threading.ThreadPool.<>c.<.cctor>b__84_0(Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs:line 1059
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SignalCompletion() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 233
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 62
   at System.IO.Strategies.UnixFileStreamStrategy.ReadAsyncTaskSource.Read() in /_/src/libraries/System.Private.CoreLib/src/System/IO/Strategies/UnixFileStreamStrategy.cs:line 147
   at System.IO.Strategies.UnixFileStreamStrategy.ReadAsyncTaskSource.System.Threading.IThreadPoolWorkItem.Execute() in /_/src/libraries/System.Private.CoreLib/src/System/IO/Strategies/UnixFileStreamStrategy.cs:line 106
   at System.Threading.ThreadPoolWorkQueue.Dispatch() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs:line 708
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.WorkerThread.cs:line 63
   at System.Threading.Thread.StartCallback() in /_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs:line 105
./RunTests.sh: line 162: 71058 Abort trap: 6           (core dumped) "$RUNTIME_PATH/dotnet" exec --runtimeconfig System.IO.FileSystem.DisabledFileLocking.Tests.runtimeconfig.json --depsfile System.IO.FileSystem.DisabledFileLocking.Tests.deps.json xunit.console.dll System.IO.FileSystem.DisabledFileLocking.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait 

Doest it mean we have a bug somewhere?

Tagging subscribers to this area: @dotnet/area-system-threading-tasks
See info in area-owners.md if you want to be subscribed.

Issue Details

---

@stephentoub I've found one interesting failure in the logs of the CI run for #56424.

Process terminated. Assertion failed.
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 419
   at System.Threading.Tasks.ValueTask`1.ValueTaskSourceAsTask.<>c.<.cctor>b__4_0(Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/ValueTask.cs:line 638
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SignalCompletion() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 233
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 62
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 250
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 60
   at System.IO.Strategies.BufferedFileStreamStrategy.ReadAsyncSlowPath(Task semaphoreLockTask, Memory`1 buffer, CancellationToken cancellationToken) in /_/src/libraries/System.Private.CoreLib/src/System/IO/Strategies/BufferedFileStreamStrategy.cs:line 492
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.ExecutionContextCallback(Object s) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 389
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs:line 183
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.MoveNext() in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs:line 410
   at System.Threading.ThreadPool.<>c.<.cctor>b__84_0(Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs:line 1059
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SignalCompletion() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 233
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SetResult(TResult result) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs:line 62
   at System.IO.Strategies.UnixFileStreamStrategy.ReadAsyncTaskSource.Read() in /_/src/libraries/System.Private.CoreLib/src/System/IO/Strategies/UnixFileStreamStrategy.cs:line 147
   at System.IO.Strategies.UnixFileStreamStrategy.ReadAsyncTaskSource.System.Threading.IThreadPoolWorkItem.Execute() in /_/src/libraries/System.Private.CoreLib/src/System/IO/Strategies/UnixFileStreamStrategy.cs:line 106
   at System.Threading.ThreadPoolWorkQueue.Dispatch() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs:line 708
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.WorkerThread.cs:line 63
   at System.Threading.Thread.StartCallback() in /_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs:line 105
./RunTests.sh: line 162: 71058 Abort trap: 6           (core dumped) "$RUNTIME_PATH/dotnet" exec --runtimeconfig System.IO.FileSystem.DisabledFileLocking.Tests.runtimeconfig.json --depsfile System.IO.FileSystem.DisabledFileLocking.Tests.deps.json xunit.console.dll System.IO.FileSystem.DisabledFileLocking.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait 

Doest it mean we have a bug somewhere?

Author:	adamsitnik
Assignees:	-
Labels:	area-System.Threading.Tasks
Milestone:	6.0.0

[stephentoub]

What assert triggered?

[adamsitnik]

What assert triggered?

To be honest I don't know. The log points to a line of code that has no assert at all:

Stack trace:

https://github.com/dotnet/runtime/blob/main/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/PoolingAsyncValueTaskMethodBuilderT.cs#L419

runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/ValueTask.cs

Line 638 in d1b866e

vtst.TrySetResult(source.GetResult(vtst._token));

runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs

Line 233 in d1b866e

_continuation(_continuationState);

runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Sources/ManualResetValueTaskSourceCore.cs

Line 62 in d1b866e

SignalCompletion();

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

Line 250 in d1b866e

_valueTaskSource.SetResult(result);

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

Line 60 in d1b866e

m_task.SetResult(result);

The most suspicious is last line of the method which has [AsyncMethodBuilder(typeof(PoolingAsyncValueTaskMethodBuilder<>))] applied:

runtime/src/libraries/System.Private.CoreLib/src/System/IO/Strategies/BufferedFileStreamStrategy.cs

Line 492 in d1b866e

}

@stephentoub does it mean that the assert comes from the code generated by the compiler? (I am guessing)

[zlatanov]

I want to ask something about this code fragment:

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

Lines 356 to 367 in 3847790

	// Get the current processor ID. We need to ensure it fits within s_perCoreCache, so we
	// could % by its length, but we can do so instead by Environment.ProcessorCount, which will be a const
	// in tier 1, allowing better code gen, and then further use uints for even better code gen.
	Debug.Assert(s_perCoreCache.Length == Environment.ProcessorCount);
	int i = (int)((uint)Thread.GetCurrentProcessorId() % (uint)Environment.ProcessorCount);
	// We want an array of StateMachineBox<> objects, each consuming its own cache line so that
	// elements don't cause false sharing with each other. But we can't use StructLayout.Explicit
	// with generics. So we use object fields, but always reinterpret them (for all reads and writes
	// to avoid any safety issues) as StateMachineBox<> instances.
	Debug.Assert(s_perCoreCache[i].Object is null || s_perCoreCache[i].Object is StateMachineBox<TStateMachine>);
	return ref Unsafe.As<object?, StateMachineBox<TStateMachine>?>(ref s_perCoreCache[i].Object);

What happens if the running thread is suspended right after executing line 360

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

and then resumed on another processor? Wouldn't that make the value that i holds incorrect here

Debug.Assert(s_perCoreCache[i].Object is null || s_perCoreCache[i].Object is StateMachineBox<TStateMachine>);
return ref Unsafe.As<object?, StateMachineBox<TStateMachine>?>(ref s_perCoreCache[i].Object);

and could that cause issue if another thread went through the same code path on the same processor, while this thread was suspended?

[stephentoub]

It's possible the assert could erroneously fire if between the two expressions in the assert the value went from non-null to null. I can fix that, but this doesn't correspond to the flagged stack trace.

[zlatanov]

@stephentoub I think it might, because PerCoreCacheSlot is marked with [MethodImpl(MethodImplOptions.AggressiveInlining)] which is called from ReturnToCache method which also is being aggressively inlined, which in turn is called from void IValueTaskSource.GetResult(short token).

[stephentoub]

Hmm. Maybe? That would mean the line number is wrong.

[zlatanov]

If you run the following code with dotnet run

using System.Diagnostics;
using System.Runtime.CompilerServices;

class Program
{
    static void Main()
    {
        try
        {
            Run();
        }
        finally
        {
            Throw();
        }
    }

    private static void Run()
    {
    }

    [MethodImpl(MethodImplOptions.AggressiveInlining)]
    private static void Throw() => Debug.Assert(false);
}

you should see something like

Process terminated. Assertion failed.
   at Program.Main() in C:\Users\ivan\source\repos\ConsoleApp2\Program.cs:line 7

Line 7 is the start of the Main() method and not where the assert occurred. If I change the Debug.Assert with a throw statement, then the output is:

Unhandled exception. System.Exception: Exception of type 'System.Exception' was thrown.
   at Program.Main() in C:\Users\ivan\source\repos\ConsoleApp2\Program.cs:line 14

[stephentoub]

Yes, but with the corresponding stack trace, it was highlighting the line inside the try, e.g. in your example it would have been line 10.

[zlatanov]

I am not sure if this was checked build, where the test are run with optimizations on, but if I add

<Optimize>true</Optimize>

to the csproj, then the output with Debug.Assert(false) becomes:

Process terminated. Assertion failed.
   at Program.Main() in C:\Users\ivan\source\repos\ConsoleApp2\Program.cs:line 10