Why 'await Task.Delay' executes synchronously in some cases? #114809
-
|
I'm encoutering a rare situation, when Use Case Context:I have added a helper type to batch concurrent GetAsync calls for the same key. The first call starts a task with a short delay (Task.Delay(50)). During the delay, other calls for the same key add their specific IDs to a shared entry in a dictionary. After the delay, the task fetches data for all collected IDs, removes the dictionary entry, and returns the combined results. GetAsync then provides the specific result to its caller. BatchExecutionHelper.cspublic class BatchExecutionHelper<TGroupKey, TValue> where TGroupKey : notnull
{
private readonly object lockObject = new();
private readonly Dictionary<TGroupKey, (HashSet<string> BatchedIds, Task<Dictionary<string, TValue>> BatchTask)> pendingBatches = [];
public async Task<TValue?> GetAsync(TGroupKey key, string batchedId)
{
Task<Dictionary<string, TValue>> batchTask;
lock (lockObject)
{
if (!pendingBatches.TryGetValue(key, out var batch))
{
Log($"GetAsync Factory: Key='{key}'. Creating new batch task.");
batch = ([], GetBatchedDataAsync(key));
pendingBatches.Add(key, batch);
Log($"GetAsync Added: Key='{key}'. New Task scheduled.");
}
(var batchedIds, batchTask) = batch;
batchedIds.Add(batchedId);
}
return (await batchTask).TryGetValue(batchedId, out var value)
? value
: default;
}
private async Task<Dictionary<string, TValue>> GetBatchedDataAsync(TGroupKey key)
{
Log($"GetBatchedDataAsync Start: Key='{key}'. Delaying...");
await Task.Delay(50);
Log($"GetBatchedDataAsync Delay Complete: Key='{key}'.");
string[] batchedIds;
lock (lockObject)
{
Log($"GetBatchedDataAsync Attempting remove for Key='{key}'.");
if (!pendingBatches.Remove(key, out var batch))
{
Log($"GetBatchedDataAsync Lock Enter: Remove FAILED for Key='{key}'.");
throw new InvalidOperationException("Pending batch not found. This should not have happened.");
}
Log($"GetBatchedDataAsync Pending batch for Key='{key}' removed. Releasing lock.");
batchedIds = [.. batch.BatchedIds];
}
Log($"GetBatchedDataAsync Retrieving data for batch for Key='{key}'.");
return await // GetActualData;
}
// Logging helpers
private static int ThreadId => Environment.CurrentManagedThreadId;
private long currentLogId;
private long currentBatchId;
private long LogId() => Interlocked.Increment(ref currentLogId);
private long NewBatchId() => Interlocked.Increment(ref currentBatchId);
private void Log(string message) => Console.WriteLine($"[{LogId()}] [TID:{ThreadId}] {message}");
}Observed Problem:We observed an unexpected execution order when using async/await with Task.Delay, leading to a race condition that breaks the batching logic. But in 0.1% of cases I can see that the thread is blocked for 50ms, it continues the execution of The issue is observed in AWS Lambda functions, not sure if that's relevant. I have confirmed that the Here's log example. You can see that the thread ID is the same, and it is blocked for ~60ms. In would expect the execution order to be more like this (and it works like this in 99.9% cases): P.S. I know how to fix the issue is my code at this point. Still, I want to understand why it happens. |
Beta Was this translation helpful? Give feedback.
Replies: 4 comments 6 replies
-
|
It’s not an answer, but if all you want is to unblock the thread, |
Beta Was this translation helpful? Give feedback.
-
|
If the code was originally executing in thread pool, it has a chance to be scheduled again onto the same thread by the pool. Using locks to access shared collection is a significant anti-pattern. Try |
Beta Was this translation helpful? Give feedback.
-
|
Locked access to an internal shared collection is fine, (although the way it's handled mixed with |
Beta Was this translation helpful? Give feedback.
-
|
Thanks for suggestions. The reason lock is used instead of Concurrent collections is because I modify not one, but two collections ( Still, my question is not how to fix this code (I know it at this point), but to understand how async works better. So In would expect logs like this even of the same thread: However, I can see in logs that the thread is blocked for ~60ms, which I didn't expect for an async operation. |
Beta Was this translation helpful? Give feedback.
-
|
Beta Was this translation helpful? Give feedback.
-
|
My question is not how to fix this code (I know it at this point), but to understand how async works better, and why such exection order is possible at all. Still, answering your questions:
|
Beta Was this translation helpful? Give feedback.
-
The compiler will prevent
.... yes, because a timing-dependent re-entrant lock is so much better....
The line I'm thinking of is this: return (await batchTask).TryGetValue(batchedId, out var value)
? value
: default;That's very definitely outside of a lock. That said, on reflection it's probably threadsafe for other reasons (but suspicious for worse ones, in particular the fact that it implies it won't always return a result).
You have a stored key by unique id is why I asked. Additionally, it's the first key, making it look like most uses will be for a smaller set of (mostly) duplicate ids. And because of that, all batches are per-unique-id, meaning if all the keys are actually unique you're not actually going to batch anything. If you're using this to talk to a database, you'd have to re-write statements to take advantage of this, which would be a non-trivial exercise. Note that doing that would also work extremely poorly with any per-instance transactions....
This was predicated on this being a cache of sorts, and just returning the task per unique key. Even then, under most circumstances I probably wouldn't make this something callers would directly control, as opposed to it only being an internal debug/logging batch id. |
Beta Was this translation helpful? Give feedback.
-
That's something I thought to be impossible until this point.
Again, wasn't planning to make it timing-dependent :) Fixed now, but still trying understand the causes.
That's the dictionary from GetBatchedDataAsync returned result. There's no need for locks, because this dictionary is only read after task is completed, and therefore dictionary is not updated afterwards (probably would make sense to return IReadOnlyDictionary).
Don't think that's true, unless I'm missing anything.
It's actually the contrary on our case - in most cases there is only one TGroupKey and lots of batchedIds. It's a database, but DynamoDB, not SQL. Maybe naming is not the best, as it's always the hardest part. |
Beta Was this translation helpful? Give feedback.
-
|
Async methods execute synchronously until they encounter the first A trace of execution looks something like this:
One thing that could cause a greater than 50 millisecond delay between steps 3 and 5 is thread A getting preempted by the operating system to run a different task. This is more likely on a busy system. This blog post describes in details how async methods work if you would like to know more. |
Beta Was this translation helpful? Give feedback.
-
|
Thread A being preempted seems like a plausable explanation, thanks a lot! While it sounds quite unlikely that the thread is preempted right after Thanks! |
Beta Was this translation helpful? Give feedback.
Async methods execute synchronously until they encounter the first
awaiton a non-completed task. In this case the race condition is caused by theTaskreturned byTask.Delaycompleting beforeGetBatchedDataAsyncchecks that it is completed.GetBatchedDataAsynccontinues to execute synchronously and then fails to find the data inpendingBatches.A trace of execution looks something like this:
BatchExecutionHelper.GetAsyncBatchExecutionHelper.GetBatchedDataAsyncTask.Delay, which creates aDelayPromise. TheDelayPromisecreates aTimerthat will complete theDelayPromise.