Profiling performance

[Rafael]

Hi,

I'm facing an issue that i don't understand.
The scenario is pretty basic, i have a table "FOWineGrappe" that i read and add the List<FOWineGrappe> to a Memory Cache.

public static string GetCurrentWineGrappes(FOWine wine)
{
    string grappesStr = "";
    List<FOWineGrappe> grappes = (from c in ProductManager.GetAllWineGrappes()
                                  where c.WineId == wine.WineID
                                  orderby c.Percentage descending
                                  select c).ToList();
    if (grappes.Count > 0)
    {
        for (int i = 0; i < grappes.Count(); i++)
        {
            grappesStr += grappes[i].Percentage + "% " + grappes[i].GrappeName + ", ";
        }
        grappesStr = grappesStr.Trim().TrimEnd(',');
    }
    return grappesStr;
}

ProductManager.GetAllWineGrappes:

public static List<FOWineGrappe> GetAllWineGrappes()
{
    List<FOWineGrappe> wineGrappes = CacheManager.GetItemFromCache("Wines_FOWineGrappe") as List<FOWineGrappe>;
    if (wineGrappes == null)
    {
        lock (BuildCacheLock)
        {
            List<FOWineGrappe> contentsToCache = ProductData.GetAllWineGrappes();
            CacheManager.AddItemToMemoryCache("Wines_FOWineGrappe", contentsToCache);
            wineGrappes = CacheManager.GetItemFromCache("Wines_FOWineGrappe") as List<FOWineGrappe>;
        }
    }
    return wineGrappes;
}

and the ProducersDate method:

public static List<FOWineGrappe> GetAllWineGrappes()
{
    List<FOWineGrappe> lst = new List<FOWineGrappe>();
    try
    {
        HighLevelFOModel dbContext = GetHighLevelFODBContext();
        IQueryable<FOWineGrappe> dcLst = from c in dbContext.FOWineGrappes
                                     orderby c.WineId ascending
                                     select c;
        return dcLst.ToList();
    }
    catch (Exception ex)
    {
        LogManager.LogError("ProductData", MethodBase.GetCurrentMethod().Name, ex);
        throw;
    }
}

Now when i profile the application, on the first access to GetCurrentWineGrappes takes just 216ms.
See image A-run1.jpg.

On the 2nd acces it takes 8S! (A-run2.jpg). Note that this time it's all on the cache, not acess to te DB is done.

On 3rd and + access it take only 1ms to get the items from cache. (A-run3.jpg)

I don't understand why run2 takes all that time in the getWineID..

Rafael

[Rafael]

Perhaps it's due to openaccess tracking internals. So i tried to "detach" the FOWineGrappes entites this way:

public static List<FOWineGrappe> GetAllWineGrappes()
{
    List<FOWineGrappe> lst = new List<FOWineGrappe>();
    try
    {
        HighLevelFOModel dbContext = GetHighLevelFODBContext();
        IQueryable<FOWineGrappe> dcLst = from c in dbContext.FOWineGrappes
                                     orderby c.WineId ascending
                                     select c;
        foreach (FOWineGrappe foWineGrappe in dcLst)
        {
            FOWineGrappe grappe = new FOWineGrappe();
            grappe.GrappeId = foWineGrappe.GrappeId;
            grappe.GrappeName = foWineGrappe.GrappeName;
            grappe.Percentage = foWineGrappe.Percentage;
            grappe.WineGrappeId = foWineGrappe.WineGrappeId;
            grappe.WineId = foWineGrappe.WineId;
            lst.Add(grappe);
        }
        return lst.ToList();
    }
    catch (Exception ex)
    {
        LogManager.LogError("ProductData", MethodBase.GetCurrentMethod().Name, ex);
        throw;
    }
}

And profiled again the same previous scenario:
B-run1.jpg, B-run2.jpg and b-run3.jpg.

HUGE change now! :) "completely "detaching" the entities from the scope fix my weird issues.

But i still would like to understand why it does it on A-run2 and what should be the Best Practice for these types of situations: rad only one via OpenAccess and that adding it to a Memory Cache (WebApplication).

Regards,

Rafael

PS: is there a "smarter" way of detaching the entities ratter than doing it the way i did?

[Jan Blessenohl]

Hi Rafael,
The problem is the content of the collection. If you look at the generated SQL you will see that the collection content is loaded by single queries per grape. This seems to happen in the second run only, I am not sure why. Normally you can avoid this by setting a FetchStrategy at the context. In your detach code you are not touching the collection at all, that's why it is fast.

All the best,
Jan Blessenohl
the Telerik team