Query Profiling for LLBLGen Pro-based applications

When I introduced the first release of the Huagati Linq-to-SQL Profiler back in August, I mentioned that there would be additional profiler runtime logging providers besides the initial one for Linq-to-SQL; "Additional logging providers; if there is enough interest I may extend the runtime logging component to also support Entity Framework, plain ADO.NET, or other data access technologies such as 3rd party OR/Ms.".

The profiler's log file format and the profiler log viewer is not tied in any way to Linq-to-SQL specifically. Although the choice of name for the tool may not be ideal, it was designed to be used with other OR mappers and data access technologies as well.

A few weeks ago I contacted Frans Bouma, author of the popular LLBLGen Pro O/R Mapper Generator. LLBLGen Pro has been around for six years and is packed with great functionality; no doubt the market leading OR mapper for .net. Frans was enthusiastic about the idea, so we exchanged a couple of emails to determine the best approach to integrate profiler logging into LLBLGen based projects without requiring too much of an effort of work by end-users. Frans suggested using a partial class implementation of LLBLGen's DataAccessAdapter class, so that's the direction I went.

Due to some time constraints in other projects I had to suspend work on the LLBLGen profiler logging component for a couple of weeks, but it is now ready for release.

To enable query profiling in a LLBLGen based project, some minor additions are needed in the application to be profiled. A reference to the profiler logging assembly must be added, and a new partial class implementation of the LLBLGen Pro DataAccessAdapter containing calls to the profiler logger need to be included in the same project as the LLBLGen generated code.

The following screenshots shows step-by-step how to enable query profiling in the LLBLGen Northwind Adapter sample project (downloadable from http://www.llblgen.com/pages/files/Example_NorthwindCS1_Adapter_06062008.zip ). Click on the individual screenshots for a full-size version.

Step 1: Add a reference to the profiler logging assembly (HuagatiLLBLGenProfiler.dll) (A), include LoggingAdapter.cs (B) (both are installed together with the profiler itself under C:\Program Files [(x86)]\Huagati Systems Co Ltd\Huagati Linq-to-SQL Profiler\redist ). Next, change the namespace in LoggingAdapter.cs to match the namespace of the application's own DataAccessAdapter class (C).


Step 2: Add a call to one of the InitializeLogging methods in the DataAccessAdapter's constructor(s). There are a few different overloads of InitializeLogging, depending on what logging features, filters, etc that you want to use.


Step 3: Compile and run the application.


Step 4: Start the Huagati Linq-to-SQL Profiler Viewer, open the logging directory used, and have fun with the logs:


Just as when profiling a Linq-to-SQL application, the top part of the window shows log entries and the bottom part shows details such as I/O statistics, timings, call stack etc pertaining to the selected log entry. All blue underlined links are clickable and will bring up additional details; clicking on the execution plan link will open the execution plan diagram in SSMS, clicking on the source code links in the call stack will open up the source file linked to in Visual Studio and so on.

Database-side I/O statistics and timings are shown in easy-to-spot bars indicating the relative cost. Each one has a tooltip containing more detailed information from the database engine:


The call stack portion shows the call stack that led to a certain query being executed, with hyperlinks directly to the source code (whenever debug information and source code is available):


In short, it is as easy to get started with profiling LLBLGen based applications as it is to profile Linq-to-SQL based applications.

The filters available in the LLBLGen logging component are the same as the filters available in the Linq-to-SQL logging component. This means that after adding profiling to a LLBLGen app as in the steps above, the examples shown in "A walkthrough of the newest filters and visual cues in the Huagati Linq-to-SQL Profiler", and "Profiling Linq-to-SQL Applications" will work with the LLBLGen profiler logging component as well. Custom logging filters can of course also be added the same way; by creating a new class inheriting from the ProfilerFilter base class or from one of the pre-defined filters.

The profiler logging component for LLBLGen Pro is included in Huagati Linq-to-SQL Profiler version 1.20 (scheduled for release on Oct 12 2009).

Code sample: Search and replace in Linq expression trees

I recently had the need* to do a 'search and replace' of a parameter in a linq query. It would have been nice to have a set of .Replace methods on the expression object to achieve this, but unfortunately there is no such thing. Instead I had to write a new expression tree visitor to clone the tree, and in the process replace the expression I want replaced with its' replacement.

I figured it would make sense to post it here in case anyone else need a search-and-replace for expression trees. This sample will replace all occurences of one ParameterExpression with another one but can easily be changed to replace any other type of expression.

* = And as for the 'why would I ever need to do that' - my specific need was to take a linq query and switch around portions of the projection it was doing without having to define an entirely new projection. I will get to the details of that in a follow up post - to keep this one short and simple... :)

Enjoy:

internal static class ExpressionExtensions
{
    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">Tree to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static Expression ReplaceParameter(this Expression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        Expression exp = null;
        Type expressionType = expression.GetType();
        if (expressionType == typeof(ParameterExpression))
        {
            exp = ((ParameterExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(MemberExpression))
        {
            exp = ((MemberExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(MethodCallExpression))
        {
            exp = ((MethodCallExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(NewExpression))
        {
            exp = ((NewExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(UnaryExpression))
        {
            exp = ((UnaryExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(ConstantExpression))
        {
            exp = ((ConstantExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(ConditionalExpression))
        {
            exp = ((ConditionalExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(LambdaExpression))
        {
            exp = ((LambdaExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(MemberInitExpression))
        {
            exp = ((MemberInitExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else if (expressionType == typeof(BinaryExpression))
        {
            exp = ((BinaryExpression)expression).ReplaceParameter(oldParameter, newParameter);
        }
        else
        {
            //did I forget some expression type? probably. this will take care of that... :)
            throw new NotImplementedException("Expression type " + expression.GetType().FullName + " not supported by this expression tree parser.");
        }
        return exp;
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">LambdaExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static LambdaExpression ReplaceParameter(this LambdaExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        LambdaExpression lambdaExpression = null;
        lambdaExpression = Expression.Lambda(
            expression.Type,
            expression.Body.ReplaceParameter(oldParameter, newParameter),
            (expression.Parameters != null) ? expression.Parameters.ReplaceParameter(oldParameter, newParameter) : null
            );
        return lambdaExpression;
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">BinaryExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static BinaryExpression ReplaceParameter(this BinaryExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        BinaryExpression binaryExp = null;
        binaryExp = Expression.MakeBinary(
            expression.NodeType,
            (expression.Left != null) ? expression.Left.ReplaceParameter(oldParameter, newParameter) : null,
            (expression.Right != null) ? expression.Right.ReplaceParameter(oldParameter, newParameter) : null,
            expression.IsLiftedToNull,
            expression.Method,
            (expression.Conversion != null) ? expression.Conversion.ReplaceParameter(oldParameter,newParameter) : null
            );
        return binaryExp;
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">ParameterExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static ParameterExpression ReplaceParameter(this ParameterExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        ParameterExpression paramExpression = null;
        if (expression.Equals(oldParameter))
        {
            paramExpression = newParameter;
        }
        else
        {
            paramExpression = expression;
        }
        return paramExpression;
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">MemberExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static MemberExpression ReplaceParameter(this MemberExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        return Expression.MakeMemberAccess(
            (expression.Expression != null) ? expression.Expression.ReplaceParameter(oldParameter, newParameter) : null,
            expression.Member);
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">MemberInitExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static MemberInitExpression ReplaceParameter(this MemberInitExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        return Expression.MemberInit(
            (expression.NewExpression != null) ? expression.NewExpression.ReplaceParameter(oldParameter, newParameter) : null,
            (expression.Bindings != null) ? expression.Bindings.ReplaceParameter(oldParameter, newParameter) : null
            );
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">MethodCallExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static MethodCallExpression ReplaceParameter(this MethodCallExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        MethodCallExpression callExpression = null;
        callExpression = Expression.Call(
            (expression.Object != null) ? expression.Object.ReplaceParameter(oldParameter, newParameter) : null,
            expression.Method,
            (expression.Arguments != null) ? expression.Arguments.ReplaceParameter(oldParameter, newParameter) : null
            );
        return callExpression;
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">NewExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static NewExpression ReplaceParameter(this NewExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        return Expression.New(
            expression.Constructor,
            (expression.Arguments != null) ? expression.Arguments.ReplaceParameter(oldParameter, newParameter) : null,
            expression.Members);
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within a ReadonlyCollection of ParameterExpressions with another ParameterExpression, and return as an IEnumerable
    /// </summary>
    /// <param name="expression">ReadOnlyCollection&lt;ParameterExpression&gt; to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A IEnumerable returning the passed in set of ParameterExpressions, with occurences of oldParameter replaced with newParameter</returns>
    public static IEnumerable<ParameterExpression> ReplaceParameter(this System.Collections.ObjectModel.ReadOnlyCollection<ParameterExpression> expressionArguments, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        if (expressionArguments != null)
        {
            foreach (ParameterExpression argument in expressionArguments)
            {
                if (argument != null)
                {
                    yield return argument.ReplaceParameter(oldParameter, newParameter);
                }
                else
                {
                    yield return null;
                }
            }
        }
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within a ReadonlyCollection of Expressions with another ParameterExpression, and return as an IEnumerable
    /// </summary>
    /// <param name="expression">ReadOnlyCollection&lt;Expression&gt; to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A IEnumerable returning the passed in set of Expressions, with occurences of oldParameter replaced with newParameter</returns>
    public static IEnumerable<Expression> ReplaceParameter(this System.Collections.ObjectModel.ReadOnlyCollection<Expression> expressionArguments, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        if (expressionArguments != null)
        {
            foreach (Expression argument in expressionArguments)
            {
                if (argument != null)
                {
                    yield return argument.ReplaceParameter(oldParameter, newParameter);
                }
                else
                {
                    yield return null;
                }
            }
        }
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within a ReadonlyCollection of ElementInits with another ParameterExpression, and return as an IEnumerable
    /// </summary>
    /// <param name="expression">ReadOnlyCollection&lt;ElementInit&gt; to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A IEnumerable returning the passed in set of ParameterExpressions, with occurences of oldParameter replaced with newParameter</returns>
    public static IEnumerable<ElementInit> ReplaceParameter(this System.Collections.ObjectModel.ReadOnlyCollection<ElementInit> elementInits, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        if (elementInits != null)
        {
            foreach (ElementInit elementInit in elementInits)
            {
                if (elementInit != null)
                {
                    yield return Expression.ElementInit(elementInit.AddMethod, elementInit.Arguments.ReplaceParameter(oldParameter, newParameter));
                }
                else
                {
                    yield return null;
                }
            }
        }
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within a ReadonlyCollection of MemberBindings with another ParameterExpression, and return as an IEnumerable
    /// </summary>
    /// <param name="expression">ReadOnlyCollection&lt;MemberBinding&gt; to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A IEnumerable returning the passed in set of ParameterExpressions, with occurences of oldParameter replaced with newParameter</returns>
    public static IEnumerable<MemberBinding> ReplaceParameter(this System.Collections.ObjectModel.ReadOnlyCollection<MemberBinding> memberBindings, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        if (memberBindings != null)
        {
            foreach (MemberBinding binding in memberBindings)
            {
                if (binding != null)
                {
                    switch (binding.BindingType)
                    {
                        case MemberBindingType.Assignment:
                            MemberAssignment memberAssignment = (MemberAssignment)binding;
                            yield return Expression.Bind(binding.Member, memberAssignment.Expression.ReplaceParameter(oldParameter, newParameter));
                            break;
                        case MemberBindingType.ListBinding:
                            MemberListBinding listBinding = (MemberListBinding)binding;
                            yield return Expression.ListBind(binding.Member, listBinding.Initializers.ReplaceParameter(oldParameter, newParameter));
                            break;
                        case MemberBindingType.MemberBinding:
                            MemberMemberBinding memberMemberBinding = (MemberMemberBinding)binding;
                            yield return Expression.MemberBind(binding.Member, memberMemberBinding.Bindings.ReplaceParameter(oldParameter, newParameter));
                            break;
                    }
                }
                else
                {
                    yield return null;
                }
            }
        }
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">UnaryExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static UnaryExpression ReplaceParameter(this UnaryExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        return Expression.MakeUnary(
            expression.NodeType,
            (expression.Operand != null) ? expression.Operand.ReplaceParameter(oldParameter, newParameter) : null,
            expression.Type,
            expression.Method);
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree. Note: this version of ReplaceParameter exists just for conformity - there can't be a parameter expression hiding under a constant expression so this could really be skipped.
    /// </summary>
    /// <param name="expression">ConstantExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static ConstantExpression ReplaceParameter(this ConstantExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        //return Expression.Constant(expression.Value, expression.Type);
        return expression;
    }

    /// <summary>
    /// Replace all occurences of a ParameterExpression within an expression tree with another ParameterExpression, and return a cloned tree
    /// </summary>
    /// <param name="expression">ConditionalExpression to replace parameters in</param>
    /// <param name="oldParameter">Parameter to replace</param>
    /// <param name="newParameter">Parameter to use as replacement</param>
    /// <returns>A cloned expression tree with all occurences of oldParameter replaced with newParameter</returns>
    public static ConditionalExpression ReplaceParameter(this ConditionalExpression expression, ParameterExpression oldParameter, ParameterExpression newParameter)
    {
        return Expression.Condition(
            (expression.Test != null) ? expression.Test.ReplaceParameter(oldParameter, newParameter) : null,
            (expression.IfTrue != null) ? expression.IfTrue.ReplaceParameter(oldParameter, newParameter) : null,
            (expression.IfFalse != null) ? expression.IfFalse.ReplaceParameter(oldParameter, newParameter) : null
            );
    }
}

A walkthrough of the newest filters and visual cues in the Huagati Linq-to-SQL Profiler

Some useful new features were added to the latest two versions of the Huagati Linq-to-SQL Profiler. First up in version 1.14 was a handful of new runtime filters in the redistributable DLLs that takes care of logging profiler data; among the new filters are the MissingIndexFilter and the MissingIndexAndPageReadsFilter . As the names suggest, these two new filters use the SQL Server optimizer's ability to detect and recommend indexes for queries when it is unable to find a suitable index. The SQL Server optimizer include that information in the generated execution plans as well as store it temporarily in distributed management views from where it can be extracted at runtime.

The new filters enables profiling of Linq-to-SQL based applications based on this information; with these filters we can tell the Linq-to-SQL Profiler to log only queries where the optimizer detect missing indexes, optionally filtered by a minimum number of page reads to avoid logging queries that have a low I/O cost anyway, and to avoid extracting execution plans for low cost queries.

The following is a quick walkthrough showing how to use the new filters together with the new visual cues added to the profiler's log viewer in version 1.15 to analyse the logs.

First of all, I created a test database with a decent amount of records and both indexed and unindexed columns that can be used in joins and where clause criteria. The test database contains three identical tables with a guid primary key and two nvarchar(100)'s - one indexed and one not indexed. To have some data to play with the creation script also adds 999,999 records to all three of the tables:



...next, I created a new project in Visual Studio 2008 with a Linq-to-SQL datacontext pointing to the new test database. Of course, I used my other Linq-to-SQL tool, Huagati DBML/EDMX Tools, to fix up the class and member names and to add inline xml documentation to the generated classes.



...after creating the datacontext, I added a new partial class containing a new constructor overload and new dispose method to the datacontext class. The new constructor contains the logic to enable profiling and to instruct the profiler to use the MissingIndexAndPageReadsFilter to only log queries that do more than 10k page reads, and where the SQL Server execution plan contain alerts for missing indexes.

In a test app like this one the runtime filter is not really necessary, but in a real world app containing hundreds of queries using runtime filters is a great way to ensure that only real 'offender' queries are logged.



...so with a test database set up, a Linq to SQL datacontext pointing to it, profiler logging enabled, time to write a test query. For this demonstration I do a simple three-table join with the first join done on indexed columns, the second join on columns with no covering indexes, and the where clause criteria using a non indexed column. This should result in two missing index alerts from the optimizer as well as a decent amount of page reads since we will do full table scans on two of the 999,999 record tables.



...and just to highlight a feature in Huagati DBML/EDMX Tools that could help catching this kind of mistakes already when writing the query in the code editor - the 'update documentation' feature in the add-in added information about what indexes exist (and don't exist) in the XML documentation for the entity classes and their members. Hovering over a member will show what index(es) (if any) exist on the underlying column in the database:



Next, I ran the test app once to generate some log data. After that I opened up the log directory I was interested in (I could go for the root log directory if I want to see everything stored in my logs, or I can - as in the screenshot below - use the directory structure generated by the logging component to filter down by date and time):



Since I ran the test app only once, there is only one entry in the log folder I opened. Now, look in the lower left corner of this screenshot of the log viewer:



The new part is the two little alerts in the lower left corner. One of them says that this log entry contain missing index alerts, and the other one says that there was a table scan on more than 10k rows. Had the scan been on between 1k and 10k rows that alert would have been yellow rather than red. Hovering over the table scan alert shows which table(s) was scanned, as well as estimated and actual number of rows that were scanned:



...and hovering over the Missing Index(es) alert brings up a floating window showing the indexes that the SQL Server optimizer would like to see in the database to execute this query in the most efficient way.



Now, it is worth mentioning that these are recommendations (or rather a wish list) generated by the SQL Server optimizer. That doesn't mean that it is always a good idea to generate the indexes it would need. In real life there is of course a balance; over indexing can be as bad as not having enough indexes since it increases I/O when writing as well as (if there are too many indexes covering the same column(s)) increasing the number of possibilities that the SQL Server optimizer must consider when compiling an execution plan. In other words, review the index recommendations carefully, edit as necessary, and create indexes thereafter. Blindly creating everything the optimizer asks for is a sure way to get into trouble. (Did I mention the database I recently reviewed for a customer where they had a large table with 70+ columns and 56 indexes? Don't do that....)

Despite my caution above, I will go ahead and just follow the optimizer generated recommendations blindly, just for the purpose of demonstration. So I clicked the "copy" link next to the "Missing index(es)" alert in the profiler log viewer to get the new indexes onto the clipboard, jumped right over to SSMS and created the indexes as they were:



Next, suspecting that the new indexes will result in the profiler not logging anything with the previous runtime filter, I removed the MissingIndexAndPageReadsFilter filter from the test app and replaced it with a null. This means 'no filtering at all, please' and will ensure that the profiler logging component writes all queries to the log:



...and after re-running the test app, I refreshed the profiler's log viewer window to see the new entry. The new entry shows significantly less reads (although there's still room to optimize this query additionally, but that's another story for another day), and both the table scan and missing index alerts are gone from the log entry details at the bottom of the screen:




So, that was a quick walkthrough of what the new runtime filters can do. Of course, there are plenty of other runtime filters and other goodies in the profiler - some covered in a previous blog entry ( Profiling Linq-to-SQL applications ). Also not mentioned above is the PrePlanPostPlanFilter that allows two filters to be combined together; one not relying on execution plans and one relying on execution plans. This is useful from a profiling performance perspective; the profiler will not extract the execution plans for a query unless it passes the first (non-execution-plan-dependant) filter and will then apply the execution plan dependant filter as the last step to determine what queries should be logged or not logged.

If you want to try out any of the above, or test the profiler with your own Linq-to-SQL based apps, go ahead and download it and get a trial license (free for 45 days) over at http://www.huagati.com/L2SProfiler/

Model first in Entity Framework v1.0

Every now and then people ask in forums etc how to do model first with Entity Framework version 1 (.net 3.5 SP1 / Visual Studio 2008 SP1). In other words, how to create a model using the Entity Framework designer in Visual Studio and then generate a database from that model. The simple answer is that it is not supported out of the box. However, since one of my tools has supported that for quite some time I figured it was about time to repost a tutorial on how to do model first with EFv1 (for those who don't want to wait until Visual Studio 2010 where it will be supported out-of-the-box).

So... here are the steps. Requires Visual Studio 2008 (not express edition, but any higher SKU will work), and Huagati DBML/EDMX Tools to be installed. (Huagati DBML/EDMX Tools is free to use for the first 45 days, if you want to continue using it after that please buy a license to support continued development).

Step 1: Create a new EDMX file (Entity Framework model file).

Step 2: Choose "empty model" if you start from scratch, or "generate from database" if you have an existing database that you want to use as a base.

Step 3: Add entities, entity members, associations etc. In other words, create a model.

Step 4: Review the model...

Step 5: Generate SSDL (Entity Framework's storage layer description) from the CSDL generated by the designer:

Step 6: After generating SSDL, the VS2008 output window shows a summary of the SSDL generation process (what was generated etc). Just as a FYI thing...

Step 7: Generate SQL-DDL for the database.

Step 8: Review the SQL-DDL that was generated, change data types as necessary, add precision/length where needed etc.

Profiling Linq-to-SQL applications

Profiling - why?

When developing database driven applications - especially apps with many users and different usage patterns - database performance is key to application performance and the database is often the 'resource bottleneck' when it comes to scaling applications to cope with a larger number of users.

If a certain operation spends a bit more time, CPU, and other resources client side it is often not as big of a matter scalability-wise as if it spends time or resources database-side/server-side. As the number of users in a large system grow, the impact of query costs - and savings of reducing it - is often the single most important factor to look at to improve performance and scalability, and the cheapest way to improve scalability.

Additionally, a production environment will often differ from test/development in ways that can affect how queries behave:

• Applications are often used different in a production environment than what developers and designers envisioned; users may refresh 'screen x' twice as often as was envisioned during design and development, or use search filters in search screen differently than anyone thought.
• SQL Server will often execute queries differently on different systems; depending on data volumes, available resources, system load, system and db configuration, and many other factors.

Because of this, runtime profiling live production systems can sometimes reveal bottlenecks and/or room for improvements/optimization that would not show up during development/test/QA, or on dev/test systems.

Profiling tools

There are many great tools available for investigating database performance at runtime / in production environments. The Microsoft tool stack offer some nice stuff for Linq-to-SQL and SQL Server based apps:

• SQL Server Profiler is a really great tool that comes with the management tools for SQL Server (Standard edition and up, unfortunately it not available in Express edition).
• Linq-to-SQL has a built in logging feature that allows executed queries to be written to log files by simply attaching a textwriter to the datacontext object.

To take this a step further, I have decided to throw a new tool onto the stack for L2S developers: a brand new profiler specifically targeting Linq-to-SQL applications.

But before we take a look at the L2S Profiler, a brief look at what comes out-of-the-box with SQL Server and Linq-to-SQL, and then what the L2S Profiler brings to the table compared to the existing tool stack.

SQL Server Profiler

Although SQL Server Profiler goes a long way when it comes to pinpointing what queries are causing the most stress db-side, it provides information from the SQL Server side of things only. It is built as a generic tool for all kinds of SQL Server profiling - not only queries but targeting other kinds of database activity as well. But a missing part is the application side of it: where did that query come from, what [user actions/calls] led to it being executed etc. In a large application with many developers involved this can make it time consuming to determine another important aspect who's code is responsible for hitting the database too frequently, or with too heavy queries, etc.

Add to that that SQL Server Profiler is made for DBAs, sys-admins, developers, and must be manually set up in a production environment. It can't be controlled from within applications, and it requires the person using it to know what they're looking for. It requires access to and privileges on the database server which is not always available in hosted environments, or in locked-down customer environments. It won't record execution plans so if you're reviewing a profiler log from a customer's system on your own system there is no way of determining what execution plan SQL Server used when it was executed.

Don't get me wrong: SQL Server profiler is an invaluable tool that I use on almost a daily basis, but there are some things it won't do that I would want it to.

Linq-to-SQL's DataContext.Log

So what about the built-in logging in Linq-to-SQL? It is a great feature as it stands, with a few lines of code you can get all SQL statements and queries generated by Linq-to-SQL written to a log file. Unfortunately you will then need to sort through them and manually determine which ones are a cause for concern and which ones are not. Time consuming to say the least as soon as query volumes creep up, and finding what queries can/need to be optimized quickly becomes a forest vs trees situation. Great for debugging locally, but beyond that at least I need more data and more filtering options.

Getting more into details

What if we are just interested in the where/what/who aspects of say...

• Queries that hit a specific table?
• Queries that do more than n I/O operations / page reads?
• Queries that take longer than n milliseconds to execute?
• Queries that generate specific SQL Server warning messages?
• Queries that result in scans?

Finding those queries by hand in a large text file isn't going to be easy. Spotting them in SQL Server Profiler is easier provided that all the requirements for using it in the first place are satisfied. On the other hand, SQL Server Profiler won't give us the where/what/who; where in the application it came from, what caused it to run, or who'se code generated it.

Add to that that we may want to control the profiling/logging from within the application by for example app settings. If we want to profile just a specific part of an application in a runtime environment, and filter out only queries that are costly then the combination of SQL Server Profiler, SQL Server Management Studio and the out-of-the-box logging capabilities of Linq-to-SQL can add quite a bit of manual work to map the logs together.

Introducting the Huagati Linq-to-SQL Profiler

So, to bring the .net application side together with the database performance side of things, I put together the Linq-to-SQL Profiler. It consists of two main components:

• A runtime component that is referenced from within an application and that can be distributed with your applications. It hooks into a combination of the Linq-to-SQL built in logging, the underlying database connections, and SQL Server's own features for retrieving I/O information, timings, execution plans etc, and combines that information into log files. It also has some advanced (and customizable) filtering options so you can instruct it to log only queries that fulfill certain criteria.
• A log viewer that read the log files generated by the runtime component, provides additional filtering, sorting (which is not available in SQL Server Profiler), and shows not only what query was executed by also the managed call stack that caused to to run, SQL Server I/O and timings etc. If execution plan logging was enabled in the runtime component it also provides quick links to bring up the execution plan as it stood on the machine where the query was executed, from when it was executed.

The runtime component

The runtime component is a small DLL that you add as a reference in your Linq-to-SQL application. It won't do anything just by being referenced, but it adds some new capabilities to the Linq-to-SQL DataContext. It can be distributed freely together with your app, provided that you have a license for the profiler.

Using it is very simple; it has two methods (with a couple of overloads) that can be used to instruct it to start profiler logging (datacontext.BeginProfiling), and to end profiler logging (datacontext.EndProfiling). Depending on your usage scenario you can either call those methods inline from your app code or you can extend the partial DataContext class generated by the Linq-to-SQL designer to call the profiler logging methods whenever a datacontext is created/used.

The following code samples shows a couple of usage scenarios which can be used to use for example app settings to determine if logging should be enabled or not, and what logging options to use.

Example 1: A profiler enabled datacontext partial class in C#

Example 2: Inline profiling with C# as an alternative to profiling-enabled DCs

Example 3: A profiling enabled datacontext in VB.NET

Example 4: Inline profiling in VB.NET as an alternative to profiling-enabled DataContexts

If you want to read more about the profiler runtime component API, check out the online help over at http://www.huagati.com/L2SProfiler/runtimehelp

The profiler viewer

The profiler viewer is a windows application that read the log files generated by the Linq-to-SQL Profiler runtime component. It has filter options and sorting to make it easier to find the 'worst offenders' or log entries that match more specific criteria than was used during the runtime logging.

The profiler's screen is divided into two parts; the upper part shows all queries from the log (minus those filtered out by any filters set in the viewer) and the lower part shows the details; the query itself, the managed call stack, I/O and timings etc. The I/O and timing data is accompanied by visual indicators showing the relative impact of a query. The thresholds used by the visual indicators can be configured in the application settings.

The lower part of the screen can also be customized; the log files contain a lot more information than what is shown in the default view and the rendering of the lower part is done using XSLT style sheets that can be switched in the application settings dialog. This allows developers to create their own detail views focusing on the specific information they're interested in.

The profiler settings dialog

Additional details such as the execution plan diagram, the source code involved, parameterized and 'sp_execute'-wrapped versions of the queries etc are available as hyperlinks in the detail view, but the same information can of course be visualized directly in a customized detail view template.

Taking it for a test spin

If you would like to take the profiler for a test spin, head over to the product page over at http://www.huagati.com/L2SProfiler/ , where you can download it and get a free 45-day trial license. After the trial expires I hope you're happy with it and want to continue using it. If so, please support continued development by purchasing a license (or a pile of licenses for your team :) ).

If you have any questions or concerns about the profiler, feel free to send an email to support@huagati.com, ask a question in the support forum (http://forum.huagati.com/forum4-huagati-linqtosql-profiler-support.aspx ), or drop a comment here on my blog.

Future features

There are of course new features are planned for the profiler, these will be made available as they're completed:

• A centralized logging server that you can run to write logs to a database. It will have a web-based frontend very similar to the windows version of the profiler logger but is better suited for team environments where many people may want to access and work with the same logs.
• More templates for the detail view in the profiler viewer
• Additional filters; both runtime- and design time filters to help keep the log files focused on the interesting bits only.
• Additional logging providers; if there is enough interest I may extend the runtime logging component to also support Entity Framework, plain ADO.NET, or other data access technologies such as 3rd party OR/Ms.

Fin.

Developing against Windows Azure table storage - my first stumbling steps

Anyone who has been following my rants for some time know that I am a fan of relational databases, and a bit sceptical over the whole Cloud Computing / Windows Azure hype. However, that could just be that I don't fully understand the good sides of 'cloud', so I am going to give it a try just to get a better understanding of how developing for Azure differs from developing normal n-tier .net applications against relational databases, and what are the real strengths and weaknesses in some of the services currently offered by the Windows Azure platform.

Now, this is completely new to me so I am sure there will be things that I completely misunderstand and other things that I use the wrong way. When that happens, please correct me and point out my errors. Don't take anything I say about Azure as facts or advice just yet - this is just me documenting my learning process as I take my first stumbling steps starting to develop against the Windows Azure SDK.

My first Azure experiment will be to convert some select parts of the HuagatiRes data model and use with Azure table storage. My first gripe with table storage is how it differ from relational databases. Although table storage uses strongly typed classes and Linq for querying the tables it feels a bit like going back in time to mainframe flat-file databases and not the modern next-big-thing in enterprise software.

So what is the big difference between Azure tables and the tables we're used to from relational dbs? Some of the basics: Azure tables are flat tables with a string based key pair, no foreign keys, no alternate indexes etc. At a first glance very limited. Or wait, is it really? After all, what is for example the difference between an index and a table? The lack of indexes can be worked around by modelling indexes as as their own tables with just a reference back to the original 'main' record, after all that's the abstraction that relational dbs provide out of the box. With Azure tables it just has to be maintained manually / in code.

The lack of foreign key constraints is probably more difficult to work around without a performance impact. Referential integrity is nice for avoiding 'bad data' generated by bad code but at the same time it should be perfectly fine to live without it. Not to mention no support for transactions. That will be an interesting one but that could maybe be worked around with a separate 'commit' table where sets of data are marked as committed (or rolled back) at the end of a 'transaction'.

So my plan of attack is to try to achieve some relational db-like functionality with Azure tables by simulating some of the basics; simulate indexes with mini-tables, simulate transactions with separate 'commit/rollback' tables etc.

On top of that, I think I will have to denormalize some parts heavily to be able to do meaningful queries without resorting to client-side joins.

Wow, this will be an interesting experiment... ...to be continued...

New blog

Welcome to my new blog.

I recently took my old blog offline, for a number of reasons:

• It was becoming unstructured; lots of content that didn't fit the title of the blog etc.
• It was a huge spam magnet (comment spam)
• I didn't feel comfortable having the whole wordpress/php/mysql thing running on my server.

Some of the old content will probably be reposted here but I'll focus more on new content. Let me know if you miss something from the old blog and I'll look into migrating it.