Nlog timestamp while using tasks

Viewed 72

I have something like this call structure:

Program -calls-> Service1.Function1 -calls-> Service2.Function2 -calls-> HTTP Call

At the end there is a HTTP call, so all my calls are made via async/await.

Here's a example:

        async function1()
        {
            logger.Info("START Function1 with parameters xy");

            logger.Info("CALL Function2 with parameters xy");
            await Service2.Function2();
            logger.Info("RET Function2 with parameters xy");

            logger.Info("END Function1 with parameters xy");
        }

        async function2()
        {
            logger.Info("START Function1 with parameters xy");

            await HTTPClient.Call();

            logger.Info("END Function1 with parameters xy");
        }

Using NLog I get this log

2021-11-04 14:44:12.6996|INFO |Service1.Function1 : START  Function1 with Parameters: xy
2021-11-04 14:44:12.6996|INFO |Service1.Function1 : CALL   Function2 with Parameters: xy
2021-11-04 14:44:12.6996|INFO |Service2.Function2 : START  Function2 with Parameters: xy
2021-11-04 14:44:17.7004|ERROR|Service2.Function2 : A task was canceled.

If you look at the timestamp, it shows always the exact same timestamp till the awaited HTTP Call is made. I think this has to do with the asynchronous (async/await) structure. How can i enable the "real" timestamps?

1 Answers
Related