I have an Azure Function that pulls workorders, logs them, modifies them, and then logs them again so we can capture the before/after on splunk, but it is taking ~3 minutes to complete because execution appears to pause when I call the asynchronous logging function. 3 minutes isn't a crazy long time but I thought that an async call would be basically instant.
The function call being made from within the Azure Function:
// Internal library that applies business logic to the workorders
ExceptionEngine Engine = new ExceptionEngine();
// This is our teams logging library that we built from scratch
Logger Logger = new Logger();
Dictionary<string, WorkOrder> workItems = null;
try
{
// This pulls ~15 thousand db rows with ~80 columns for each row. So the dataset is sizable but not huge
workItems = Engine.GetWorkOrderData();
}
catch (Exception e)
{
Logger.LogError("Something happened");
}
_ = Logger.LogModelsAsync("precalculationworkorders", workItems.Values.ToList(), Formats.Json);
// Apply business logic to all workorders in the dictionary (this changes values in the referenced object)
foreach (string workOrderID in workItems.Keys.ToList())
{
workItems[workOrderID].ApplyAllBusinessLogicAndCalculations();
}
_ = Logger.LogModelsAsync("postcalculationworkorders", workItems.Values.ToList(), Formats.Json);
Function body inside the Logger class:
public async Task<List<SendReceipt>> LogModelsAsync(string subject, IEnumerable<Object> iterable, Formats format = Formats.PipeDelimited)
{
List<Task<SendReceipt>> tasks = new List<Task<SendReceipt>>();
// Cycling through the iterable/collections
foreach (Object model in iterable)
{
// Converting model to dictionary
Dictionary<string, Object> tempDataDict = LoggerHelper.GetPropertiesAndValues(model);
// Generating log and sending to queue
tasks.Add(this.LogDictAsync(subject, tempDataDict, format:format));
}
SendReceipt[] receiptArray = await Task.WhenAll<SendReceipt>(tasks);
return receiptArray.ToList();
}
As the comments say, workItems will contain ~15,000 objects with ~80 properties each. So it is a moderate sized payload (but it is bigger than anything we've ever logged using this internal Logging library).
As you can see, the calls we make to LogModelsAsync are not awaited and are instead being discarded.
I initially thought that the issue could be that since we are modifying workItems with workItems.ApplyAllBusinessLogicAndCalculations(), the process was waiting for LogModelsAsync to complete before we could modify it but we aren't even logging the workItems object, just the values in a list form which, unless I'm mistaken, should mean it doesn't matter what happens to the workItems afterwards because it's not using the referenced memory location.
What I thought would happen here is that Logger.LogModelsAsync would spawn a new thread and then the main thread would immediately continue on to the foreach loop immediately. Then, after all the business logic calculations, we would spawn another thread to log it a second time while the main thread continues on.
Am I misunderstanding how async calls/discarding works or am I doing something that makes it execute synchronously? Why is it waiting for the function call to complete before continuing?
