First Time Calling Extension Methods is Slower Than Subsequent Calls

Question

Hello,

I have a class that modifies data via some extension methods. In order to debug performance, I have created some rough debug code to make multiple calls to the same methods using the same data a number of times. I am finding that it consistently takes a significantly longer time to do the calculations the first time through the loop than subsequent calls.

For example, for a small set of data, it appears to take about 5 seconds to do the calculations, while each subsequent call is a second or so.

Thanks, wTs

The code looks something like this:

Test Code

void TestCode()
{
    for (int i = 0; i < iterationsPerLoop; i++)
    {
        DateTime startTime = DateTime.Now;

        // The test is actually being done in a BackgroundWorker
        dispatcher.Invoke(DispatcherPriority.Normal,
                            (Action)(() => this.PropertyCausingCodeToRun = "Run";
        while (this.WaitForSomeCondition)
            Thread.Sleep(125);
        DateTime endTime = DateTime.Now;

        double result = endTime.Subtract(startTime).TotalSeconds;
    }
}

Method where extension methods called

private static List<ObservableItem> GetAvailableItems(MyObject myObject)
{
    var items = new List<ObservableItem>(myObject.Items.ToList());
    var selectedItems = items.OrderByDescending(item => item.ASortableProperty)
                             .SetItemIsAvailable(false)
                             .SetItemPriority() 
                             .OrderByDescending(item => item.Priority) 
                             .Where(item => item.Priority > 0) 
                             .SetItemIsAvailable(true) 
                             .OrderBy(item => item.Date);

    return selectedItems.ToList();
}

Extension Methods (ObservableItems all created on different thread)

static class MyExtensionMethods
{
    public static IEnumerable<T> SetItemIsAvailable<T>(this IEnumerable<T> sourceList,
            Boolean isAvailable) where T : ObservableItem
    {
        Action<T> setAvailable = i => i.IsAvailable = isAvailable;

        List<DispatcherOperation> invokeResults = new List<DispatcherOperation>();

        foreach (var item in sourceList)
        {
            invokeResults.Add(
                item.ItemDispatcher.BeginInvoke(setAvailable , new object[] { item }));
        }

        invokeResults.ForEach(ir => ir.Wait());
        return sourceList;
    }

    public static IEnumerable<T> SetItemPriority<T>(this IEnumerable<T> sourceList) where T : ObservableItem
    {
        Action<T, double> setPriority = new Action<T, double>((item, priority) =>
            {
                item.Priority = priority;
            });

        List<DispatcherOperation> invokeResults = new List<DispatcherOperation>();

        foreach (var item in sourceList)
        {
            double priority = ......;  // Some set of calculations

            invokeResults.Add(
                item.ItemDispatcher.BeginInvoke(setPriority, 
                            new object[] { asset, priority }));
        }

        invokeResults.ForEach(ir => ir.Wait());
        return sourceList;
    }
}

Answer 1

Most often, the first time methods are called, there is some overhead associated with the JIT compilation time. This will have an effect (though most likely not that much).

However, looking at your code, you're spending a huge amount of time waiting on asynchronous calls marshalling to the UI via the dispatcher. This is going to put a large hit on your overall performance, and slow this way down.

I'd recommend doing all of your operations in one dispatch call, and using Invoke instead of BeginInvoke. Instead of marshalling one message per item, just marshal a single delegate that includes the foreach loop through your items.

This will be significantly faster.

Answer 2

The real issue, as I've figured out, was caused by the property initially being called to sort the items (before the extension methods are even called).

The property is of the form:

public Double ASortableProperty
{
    get
    {
        if (mASortableProperty.HasValue)
        {
            return mASortableProperty.Value;
        }
        mASortableProperty = this.TryGetDoubleValue(...);
        return (mASortableProperty.HasValue ? mASortableProperty.Value : 0);
    }
}

Therefore, the first time through the loop, the values were not initialized from the database, and the cost was in retrieving these values, before the sort can take place.