Implementing Tracer.Serilog.Fody for async method not working

Ashwini0721 commented 3 weeks ago

Hi csaba,

I am Ashwini Mahajan working in Struengineers India Pvt Ltd as Senior Software Engineer. We are implementing Tracer.Serilog.Fody in our application. But we observed that it is not working properly for async/await method. It just adds log for async parent method and it skips child methods or nested method calls in parent method.

**[TraceOn] public void GetMarks() { Task.Delay(100); } ///

/// The delete execute. ///

[TraceOn] private async Task DeleteExecute() { this.IsBusy = true; this.GetMarks(); // this method is skipped

// Get selected element marks
var elementMarks = from x in this.GetSelectedElementMarks() select x.PadLeft(12);  // this method is skipped

}**

Is there any specific way to implement this Tracer.Serilog.Fody for async methods.

Please help me with same

Regards, Ashwini Mahajan

ndrwrbgs commented 3 weeks ago

Hi Ashwini,

It seems that the issue you're encountering with Tracer.Fody not logging child async methods could be due to a misunderstanding of how async and await work in C#. Specifically, Task.Delay(100) and this.GetMarks() without an await will not perform the delay as expected, which can lead to missing log entries for nested method calls. If the application ends quickly after these calls, they may never be made during the run, depending on the TaskScheduler in use.

Here are some official tutorials and resources that might help you understand and correctly implement async and await in your application:

🪟 Microsoft Learn | This is a comprehensive resource that covers asynchronous programming with C#. It explains the Task-based Asynchronous Pattern (TAP) and how to properly use async and await to handle asynchronous operations link
⚫ Medium | Medium has an explanation about various TaskSchedulers, which can offer deeper details into how async methods are handled by the .NET runtime. link
▶️ PluralSight | If you have PluralSight, this course dives into the details of async/await link
🙍‍♂️ Stephen Toub | Stephen is a developer on the .NET language team, and was involved in the implementation of async/await. This blog post by him covers some of the more low-level details about SynchronizationContext and ExecutionContext with regards to async methods link. Another post about the internal state-machine is here. These items are integral to the implementation of Tracer.Fody

These resources should help you understand how to properly structure your async methods and ensure that all nested calls are awaited correctly, thus allowing Tracer.Fody to capture logs for all parts of the method.

P.S. the code above came through difficult to read or reproduce due to formatting. 🐙🐈 GitHub has a Creating and highlighting code blocks tutorial which may help clarity in the future.

Ashwini0721 commented 3 weeks ago

Sorry it was mistake in logger configuration. I have one more question like. This tracing works for async method only when async method return type is 'Task'. Otherwise, it do not log async method exit.

for example

[TraceOn] private async void DeleteExecute() // return type is not Task {

}

ndrwrbgs commented 2 weeks ago

Hi Ashwini,

I was unfamiliar with this limitation! I cannot presently say whether how the compiler handles these methods leaves it difficult to weave, or it is just a matter of not yet having been implemented. My guess would be that it is possible to implement.

Should it be possible, it may exist on a backlog for some time, so the rest of the message is focused on unblocking you today.

"Should we use `async void`?"

In my own experience I found that some libraries and tools did not work correctly with async void. From a performance standpoint I stopped using it because the tasks that were created were generally unobservable to the caller and could lead to resource leaks - the following post from the developers of the language largely influenced my opinions: 🪟Avoid Async Void.

"What if I have to?" (or, "sometimes code is not as well behaved as theory")

Sometimes legacy structures required us to do a fire-and-forget, and we either did _ = myAsyncTask() (an explicit discard variable which helped static analysis and later maintainers to know that we didn't forget to await the result, it was intentional).

Here's another post by 🙍‍♂️Stephen about other ways of connecting async code to synchronous code Task.Wait and "Inlining".

Further details about use case?

Is there some constraint you're under which mandates the use of async void method signatures? Sharing this could help identify out-of-box solutions or demonstrate a broader impact of the issue.

csnemes / tracer