How can that be? We’re in the realm of micro-micro-optimisation here, but I’m working on a log4net appender which writes to Event Tracing for Windows. The setup gives you the runtime configuration of ETW with the easy use of log4net. ETW logging is ultra-efficient, so I want to impact that as little as possible, which is why I’m optimising string comparison.
The appender will let you capture different levels of logging per assembly or per type, and I need to check where the call comes from to identify the correct level. So I can specify INFO level for anything in the namespace Sixeyed.Logging, and DEBUG for the class Sixeyed.Logging.Log.
In that comparison, equality comes first (so a type can be specified more granularly than an assembly), but if not equal I need to check if the type name starts with the specified namespace. StartsWith has to be more efficient than Contains, of course, because we’re only comparing the start of the string, not the whole thing. But actually no, for positive matches, StartsWith is consistently 40-50% slower than Contains:
10,000,000 iterations may seem excessive, but not in the context of enterprise logging. For non-matches (e.g. ascertaining that Acme.PetShop.Entities isn’t in the Sixeyed.Logging assembly), the two calls are more equally matched. Contains is typically slower, but usually less than 10%:
A very simple optimzation is the fastest – comparing the size of the strings first, then if the test string is longer than the pattern, checking the substring:
var match = (typeName.Length >= lookup.Length);
if (match)
{
match = typeName.Substring(0, lookup.Length) == lookup;
}
Assert.IsTrue(match);
That’s the fastest for positive and negative checks:
I’m expecting positive matches to be the dominant scenario, so this optimization saves a second every 10,000,000 logs. That efficient ETW appender for log4net is coming soon…