Profiling mysteries

time to read 3 min | 473 words

In our profiling, we run into an expensive mystery call to string.Join. Nothing in our code called it, and it is expensive.

image

Looking at the code didn’t get us anywhere, so I profiled things again, this time using the debug configuration. The nice thing about the debug configuration is that it doesn’t inline methods (among other things), so what gets executed is much closer to the actual code.

Here are the results:

image

And now it is clear what is going on.

Here is the offending line:

var tryMatch = _trie.TryMatch(method, context.Request.Path);

With context.Request.Path being a PathString, and TryMatch accepting a string, we are silently calling the implicit string operator, which just calls PathString.ToString(), which just calls ToUriComponent(), which looks like:

public string ToUriComponent()
{
    if (HasValue)
    {
        if (RequiresEscaping(_value))
        {
            // TODO: Measure the cost of this escaping and consider optimizing.
            return String.Join("/", _value.Split('/').Select(EscapeDataString));
        }
        return _value;
    }
    return String.Empty;
}

Looking into the current code, it has already been optimized by removing the Linq call and its associated costs, but that is still expensive call to make.

The fix was to get the string directly:

var tryMatch = _trie.TryMatch(method, context.Request.Path.Value);

And here are 10% reduction in costs. Smile