Table of Contents
Issue
I have an Azure Function with a method that takes ILogger as an argument.
log.LogInformation(...)
log.LogWarning(...)
are fast, but
log.LogError(...)
is extermly slow.
What could be the reason?
2022-02-18T13:59:48.852 [Information] this is a test
2022-02-18T13:59:48.852 [Information] this is a test
x100
2022-02-18T13:59:48.856 [Information] Information loop: 4ms
2022-02-18T13:59:48.856 [Warning] this is a test
2022-02-18T13:59:48.856 [Warning] this is a test
x100
2022-02-18T13:59:48.859 [Information] Warning loop: 3ms
2022-02-18T13:59:48.902 [Error] this is a test
2022-02-18T13:59:48.996 [Error] this is a test
x100
2022-02-18T13:59:54.940 [Information] Error loop: 6080ms
Solution
The major difference of Log levels (like LogInformation, LogError, LogWarning, LogCritical, etc.,) is When you write traces from your application code, you should assign a log level to the traces. Log levels provide a way for you to limit the amount of data that is collected from your traces. Refer here
I have tried the way which you have followed to know the log level processing time.
Logging the error depends on the application code failure. If there are any unhandled exceptions in the azure functions these are handled by LogError only (Exception, exceptionMsg) but AppInsights don’t see it was the failure.
- To Return the bit more meaningful full error message, I guess that’s why for you it takes time to execute the error log.
The workaround followed
Here I am adding the log levels to know the exact time taken to complete those log level iteration times. I cannot see any delay in log execution & depends on the Business logic written from our end prior to log execution.
public static async Task<IActionResult> Run(
[HttpTrigger(AuthorizationLevel.Function, "get", "post", Route = null)] HttpRequest req,
ILogger log,ExecutionContext context)
{
Stopwatch sw = Stopwatch.StartNew();
log.LogInformation("Time taken:"+ sw.ElapsedMilliseconds.ToString());
log.LogInformation("C# HTTP Information log");
log.LogInformation("C# HTTP information log");
log.LogInformation("Time taken:" + sw.ElapsedMilliseconds.ToString());
log.LogWarning("C# HTTP Warning log");
log.LogWarning("C# HTTP warning log.");
log.LogInformation("Time taken:" + sw.ElapsedMilliseconds.ToString());
log.LogError("C# HTTP Error log");
log.LogError("C# HTTP Error log");
log.LogInformation("Time taken:" + sw.ElapsedMilliseconds.ToString());
log.LogCritical("C# HTTP Critical log");
log.LogCritical("C# HTTP Critical log");
log.LogInformation("Time taken:" + sw.ElapsedMilliseconds.ToString());
sw.Stop();
Results
Answered By – HariKrishnaRajoli-MT
Answer Checked By – Marie Seifert (BugsFixing Admin)