azure-functions-host icon indicating copy to clipboard operation
azure-functions-host copied to clipboard

Performance Area: ETW Logging of DateTime

Open NickCraver opened this issue 2 years ago • 0 comments

Overview

This is a small one, but with aspects of ETW I'm not aware of in terms of transitioning. In the IEventGenerator for ETW, every log line flowing through here (from ``SystemLogger](https://github.com/Azure/azure-functions-host/blob/dev/src/WebJobs.Script.WebHost/Diagnostics/SystemLogger.cs#L159)) is efficiently handled [down to a stack-allocated EventData`.

It's a very efficient pipe except for one allocation we repeat a lot: converting the date into a string once per event. In a Hello World scenario this is about 6.5% of our overall allocations in current dev branch (and growing, as we eliminate other allocations):

image

Proposal

ETW is designed around this to accept the DateTime as a long (using DateTime.ToFileTimeUtc()) - can we use this down through EventData creation? This is what the built-in converter does.

I'm not familiar enough with ETW -> Kusto to reason about the pipeline and what the consequences of changing to the efficient version are, or if there are tradeoffs. I'm not sure if we can change the string entries to long directly and it just work or this is an impactful schema change.

Writing this up as a performance impact area, hoping someone more familiar with ETW can chime in on if/how we can change this (or we accept this cost and move along).

cc @AnatoliB @RohitRanjanMS @gzuber

NickCraver avatar Feb 02 '22 14:02 NickCraver