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/
What does "LOB" stand for, as in "LOB reads"?
ReplyDeleteLOB reads is number of large object pages that was read. Data that is too big to fit in-row is stored in LOB pages. This includes columns of data type text, ntext, image, and columns of datatype varchar(max), nvarchar(max), varbinary(max) that contain a large value.
Delete