Bernie Cook's Blog

Azure, C#, .NET, Architecture & Related Tech News

Reviewing the T-SQL Generated by LINQ to SQL Within SQL Server Profiler

1 Comment

SQL Server ProfilerIf you’re interested in taking a look at the final T-SQL generated by your LINQ to SQL queries then you have a few options available:

  1. Utilise LINQPad which converts your C# LINQ database queries into T-SQL
  2. Execute an SQL Server Profiler trace against the database your application is querying while its running
  3. Understand how ADO.NET translates the LINQ to SQL expression tree into T-SQL so you know what it’s going to output

I thought I’d blog about the second option above given it’s the more common approach I adopt when I’m working with LINQ to SQL.

So first off I’ll provide a brief overview of SQL Server Profiler and what a “trace” is. Then I’ll show you how to configure and run a trace. Finally I’ll throw a few LINQ to SQL examples at a local SQL database and provide the final T-SQL generated.

SQL Server Profiler & Traces

SQL Server Profiler comes packaged with SQL Server so if you’re running SQL Server Management Studio chances are you’ll find a shortcut to this particular tool in amongst the SQL shortcuts, or via the Tools menu option in SQL Server Management Studio. Its primary aim is to analyse, and even replay SQL trace results, for the purpose of troubleshooting, diagnosis, benchmarking, monitoring, etc. As a developer you can imagine how helpful this can be when you want to identify bottlenecks, optimise your system during the testing and performing tuning phase, generate performance reports, etc.

Once you delve into examining SQL events you’ll start to notice that SQL generates a LOT of unique events (well over a hundred) and in order to help isolate the ones you’re looking for you have to create what’s called a trace. The trace defines which SQL events to capture as well as providing very handy filtering and output options.

The trace results are also returned in a tabular fashion which you can browse through within the tool or export for use elsewhere.

So how do you create a trace?

Creating a Trace

Start up SQL Server Profiler. The first screen you’ll see will hopefully look like this:
SQL Server Profiler
Click on “File” in the menu and select “New Trace…” then select the appropriate connection settings.
Connect To Server
You’ll then be presented with a fresh “Trace Properties” window from where you’ll be able to configure your trace.
New Trace
Leave everything as is on the “General” tab with the exception of the “Use the template:” option which you want to change to “Blank”. This essentially clears the events the trace is going to capture so that we can start from scratch and only add those we want. There are a lot of preconfigured templates but we want to avoid those for now.

Now click on the “Events Selection” tab and you’ll see an array of events all grouped accordingly. We want a specific event called “RPC:Completed” which is under the “Stored Procedures” category.
RPC Completed
Select the checkbox to the left of “RPC:Completed”. This tells our trace that we want to capture all events that are fired when a remote procedure call completes it’s execution.

One small but useful tip is to organise how the data will be returned so click on the “Organize Columns…” button and reorder the columns so the “StartTime”, “Duration” and “TextData” are at the top. This means we’ll have our trace results returned in chronological order and each will tell us how long they took to execute in milliseconds and what T-SQL was executed in the first few columns. See below:
Organize Columns
Click “OK” to save the column order then click “Run” to proceed.

Congratulations you just created a trace!

Reviewing the Trace for LINQ to SQL queries

Now that the trace is up and running we’ll start to see all stored procedure calls that are completed against any database associated with the connection you chose earlier.

If you fire up a Windows C# application that makes LINQ to SQL calls you’ll start to see them appearing in the trace output. What’s important to clarify at this point is that even if your LINQ to SQL queries aren’t calling a stored procedure the system stored procedure sp_executesql will be executing the queries, and that’s what the trace will be capturing.

See below for an example:
What I’ve selected is a simple LINQ to SQL insert into a table called “ExceptionLog”, and here’s the C# code that generated this call:

var exceptionLog = new ExceptionLog
    ExceptionType = exceptionType,
    Message = message,
    AddedDateTime = DateTime.UtcNow

using (var dataContext = GetDataContext())

You can use the Pause/Start buttons to halt the trace if need be so you don’t find SQL Server Profiler auto-scrolling to the bottom of the list every time a new procedure is completed.

Here’s another example of a simple LINQ to SQL select:

var query =
        from el in dataContext.ExceptionLogs
        where el.AddedDateTime.Year == 2012
        orderby el.AddedDateTime ascending
        select new ExceptionLog
            ExceptionLogId = el.ExceptionLogId,
            ExceptionType = el.ExceptionType,
            AddedDateTime = el.AddedDateTime

And in the trace window we’ll see:

exec sp_executesql N'SELECT [t0].[ExceptionLogId], [t0].[ExceptionType], [t0].[AddedDateTime]
FROM [dbo].[ExceptionLog] AS [t0]
WHERE DATEPART(Year, [t0].[AddedDateTime]) = @p0
ORDER BY [t0].[AddedDateTime]',N'@p0 int',@p0=2012

You can see the exact SQL output. More information is displayed above as well so you can get an idea for what other data is associated with the trace; duration in milliseconds, DatabaseName, RowCounts etc. All very useful.

Here’s another example where I’ve employed the SQL IN operator to retrieve a collection of authorised users. The LINQ to SQL:

var authorisedUserRoleIds = new List
    1, // 1 = System Administrator
    2, // 2 = Regional Manager
    3 // 3 = County Manager

var query =
        from u in dataContext.Users
        join ur in dataContext.UserRoles on u.UserId equals ur.UserId
        where authorisedUserRoleIds.Contains(ur.RoleId)
        orderby u.Surname ascending
        orderby u.FirstName ascending
        select new User
            UserId = u.UserId,
            FirstName = u.FirstName,
            Surname = u.Surname,
            EmailAddress = u.EmailAddress

And the resulting SQL:

exec sp_executesql N'SELECT [t0].[UserId], [t0].[FirstName], [t0].[Surname], [t0].[EmailAddress]
FROM [dbo].[User] AS [t0]
INNER JOIN [dbo].[UserRole] AS [t1] ON [t0].[UserId] = [t1].[UserId]
WHERE [t1].[RoleId] IN (@p0, @p1, @p2)
ORDER BY [t0].[FirstName], [t0].[Surname]',N'@p0 int,@p1 int,@p2 int',@p0=1,@p1=2,@p2=3

If you look closely you can see the JOIN, WHERE  clause and ORDER BY  just as you’d expect.

What Next?

This is really a starting point and there is a lot more that can be achieved with SQL Server Profiler further. Some examples being:

  • If you want to edit your running trace you’ll have to pause it, select the properties option to edit it then get it running again – “File > Properties”.
  • Another useful event under the SQL group is SP:StmtCompleted. SP:StmtCompleted returns every single statement completed whereas RPC:Completed only returns the last remote procedure executed. So if you called a stored procedure which contained five individual queries from your LINQ to SQL you’d see five SP:StmtCompleted events and one RPC:Completed.
  • Save the trace you’ve created as a template so that you can reuse it again – “File > Save as Template“. You can even save it into the list of templates that appears in “New Trace” window for easier access or share it amongst your development team.
  • Apply filters to the trace in the “Events Selection” tab. See the “Column Filters…” button. Useful if you want to identify queries taking longer than 10 milliseconds or just target a given database.
  • Look into the Database Engine Tuning Advisor tool and how it can analyse trace outputs to help create indexes to boost performance.

Good luck.

Author: Bernie

I currently live and work in the UK, just outside of London. I've been working in IT for 15+ years and in that time have solved many technical problems via blogs, forums, tutorials etc. and feel like I should be giving something back. This blog post is my way of contributing and I hope it proves just as useful to others as their contributions have to me.

One thought on “Reviewing the T-SQL Generated by LINQ to SQL Within SQL Server Profiler

  1. Bernie:

    Nice, very detailed.
    I am writing a post on sp_executeSQL and SQL Profiler and wanted to see the best way to filter out noises. Did not really get much in that area.

    But, really enjoyed your coverage of Entity Framework/LINQ.

Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s