How can I properly use the Stopwatch class with an async action event that awaits calls to my database asynchronously inside an async Post method on DotNet Core ?
Why
To time my code and check for bottleneck. This is a simplified test method that will contain more code as time goes on.
Errors
I tried using an Action event, a Task event and a Func<Task> event without success and they all give me errors which always occurs when I am awaiting a call from my database asynchronously using EF Core
When I use Action event
An unhandled exception of type 'System.ObjectDisposedException' occurred in System.Private.CoreLib.dll. Cannot access a disposed context instance.
When I use Func<Task>
System.Threading.Tasks.TaskCanceledException: A task was canceled.
It doesn't print anything when I use Task event and the rest of the code executes without errors
Code
Post Method
public async Task<JsonResult> OnPostTest() {
// my Database Context
using DatabaseContext dc = _dbContext;
// list of json data that will be returned back to the client
List<object>? listJsonData = null;
// stopwatch initialization
Stopwatch sw = new();
sw.LogActionAsync(nameof(OnPostTest), (async () => { // new Task(async () => { // new Func<Task>(async() => {
// get list of data from TableTest database with a valid name and are not marked as delete
List<TableTest> listValidTabletest = await dc.ListTest.AsNoTracking().Where(t => !string.IsNullOrWhiteSpaces(t.strName) && !t.blnDelete).ToListAsync(); //<-- returns a list asynchronously and where the error occurs
// initialize list that will be returned
listJsonData = new();
foreach (TableTest t in listValidTableTest) {
// object that will be in the list of returned json objects
var returnData = new {
t.strName,
t.arrPrices,
t.strStartDate,
t.strEndDate
};
listJsonData.Add(returnData);
}
}));
return new JsonResult(new {
// return list or an empty array if list has not been initialized
arrJsonData = listJsonData?.toArray() ?? Array.Empty<object>(),
blnGetStatus = bool.TrueString
});
}
Stopwatch Extension Class
public static async void LogActionAsync(this Stopwatch sw, string? strMethodName, Action asyncAction, int intNbOfIterations = 1) {
sw.Reset();
sw.Start();
List<Task> listOfTasks = new();
for (int i = 0; i < intNbOfIterations; i ) {
listOfTasks.Add(Task.Factory.StartNew(asyncAction)); // for Action event
//listOfTask.Add(asyncTask); // for Task event
}
await Task.WhenAll(listOfTasks);
//await asyncFuncTask; // for Func\<Task> event
sw.Stop();
// log duration to a file using Serilog
Log.Debug($"{strMethodName} Action Duration: '{sw.Elapsed.Duration()}'");
}
EDIT:
I changed my stopwatch extension method to async Task LogActionAsync... and my stopwatch object to await sw.LogActionAsync... but now nothing is being logged*. Any idea ?
CodePudding user response：
There's a lot of bugs in this code. To summarize:
async voidin two places.- Missing
awaits. - Using a single database context concurrently.
- Adding to a list of results concurrently.
So, let's fix these one by one.
async voidin two places.- Missing
awaits.
As another answer noted, LogActionAsync should not be async void but should be async Task and awaited.
I changed my stopwatch extension method to async Task LogActionAsync... and my stopwatch object to await sw.LogActionAsync...
You're still missing one more async void. It's a tricky one: lambdas, when assigned to Action variables, become async void. The proper delegate type for an asynchronous method without a return value is Func<Task>, not Action.
Code:
public static async Task LogActionAsync(this Stopwatch sw, string? strMethodName, Func<Task> asyncAction, int intNbOfIterations = 1) {
sw.Reset();
sw.Start();
List<Task> listOfTasks = new();
for (int i = 0; i < intNbOfIterations; i ) {
listOfTasks.Add(asyncAction());
}
await Task.WhenAll(listOfTasks);
sw.Stop();
// log duration to a file using Serilog
Log.Debug($"{strMethodName} Action Duration: '{sw.Elapsed.Duration()}'");
}
And now you can properly use await everywhere.
- Using a single database context concurrently.
- Adding to a list of results concurrently.
As another answer noted, you will need one database context per action lambda. This is a limitation of Entity Framework (in turn imposed by a limitation of most SQL on-the-wire protocols).
The List<T>.Add method is also not threadsafe, and the code is potentially invoking it from multiple threads concurrently. It's possible to use a concurrent collection, but it's easier and cleaner to return result data instead of modifying a shared collection as a side effect.
But, really, I suspect that the concurrency in the posted code is an accident. It seems very odd to run N "iterations" of something concurrently when doing timing; I believe the desired semantics are to run N iterations of something serially.
If my assumption is correct, then the code should look like this:
public static async Task LogActionAsync(this Stopwatch sw, string? strMethodName, Func<Task> asyncAction, int intNbOfIterations = 1) {
sw.Reset();
sw.Start();
for (int i = 0; i < intNbOfIterations; i ) {
await asyncAction();
}
sw.Stop();
// log duration to a file using Serilog
Log.Debug($"{strMethodName} Action Duration: '{sw.Elapsed.Duration()}'");
}
public static async Task<T> LogActionAsync<T>(this Stopwatch sw, string? strMethodName, Func<Task<T>> asyncFunc, int intNbOfIterations = 1) {
sw.Reset();
sw.Start();
T result = default;
for (int i = 0; i < intNbOfIterations; i ) {
result = await asyncFunc();
}
sw.Stop();
// log duration to a file using Serilog
Log.Debug($"{strMethodName} Action Duration: '{sw.Elapsed.Duration()}'");
return result;
}
public async Task<JsonResult> OnPostTest() {
// my Database Context
using DatabaseContext dc = _dbContext;
// list of json data that will be returned back to the client
List<object>? listJsonData = null;
// stopwatch initialization
Stopwatch sw = new();
listJsonData = await sw.LogActionAsync(nameof(OnPostTest), (async () => {
// get list of data from TableTest database with a valid name and are not marked as delete
List<TableTest> listValidTabletest = await dc.ListTest.AsNoTracking().Where(t => !string.IsNullOrWhiteSpaces(t.strName) && !t.blnDelete).ToListAsync();
// initialize list that will be returned
var jsonData = new List<object>();
foreach (TableTest t in listValidTableTest) {
// object that will be in the list of returned json objects
var returnData = new {
t.strName,
t.arrPrices,
t.strStartDate,
t.strEndDate
};
jsonData.Add(returnData);
}
return jsonData;
}));
return new JsonResult(new {
// return list or an empty array if list has not been initialized
arrJsonData = listJsonData?.toArray() ?? Array.Empty<object>(),
blnGetStatus = bool.TrueString
});
}
CodePudding user response：
You're not awaiting your call to LogActionAsync, so your call happens after your page action is over, which is why you get all those disposed exceptions. Your entire page and all its DI objects and database contexts and everything have long been disposed by that point.
async void should be considered a debugging tool, it helps find any async issue inexperienced people make right away!
CodePudding user response：
The problem in your code has nothing to do with StopWatch and everything to do with entity framework.
Entity Framework DbContext is not concurrent safe.
You need to move the creation and disposal of the DbContext inside the Task.
Additionally, you should not be using Task.Factory.StartNew due to weird exception handling. And in this case, you should not use Task.Run nor Task.Factory.StartNew because you do not need a thread for concurrency.