Sunday, November 30, 2008

Introduction to SQL Profiler

by David L. Penton via The Penton-izer on 11/30/2008 10:04:25 PM

Many times I see web developers using many tools to help them with their day to day duties. WebDevs use VS.Net, stripped down text editors, CSS tools, JavaScript tools, browser plug-ins…the list is never-ending. Not to mention the languages (ASP.NET, PHP, Ruby, etc.) One thing typically in common with all of the WebDevs is the usage of database technologies. In the Microsoft world, this more often means SQL Server. One of the most underrated (and perhaps underused) tools that WebDevs should use is SQL Profiler. This is because I find that SQL Profiler is an invaluable utility to ensuring appropriate database usage. In an age where data calls are cached, when technologies like LINQ and EF handle a good bit of the heavy lifting, it tends to hide what is happening in the database. This is the first in a series of blog posts geared towards the web developer – Introduction to SQL Profiler. I’ll begin with jumping right into tracing, explaining the options (with an emphasis on the defaults) as I go along.

Beginning with SQL Profiler

When you start SQL Profiler, you are greeted with an extremely simple GUI – hardly any buttons or menus to choose from.

Let’s get right into tracing something. There are three ways to start tracing:

1. Click on the leftmost icon (New Trace)
2. CTRL-N
3. File…New Trace…

You are presented with a very typical database connection dialog screen.

Of course, the preference is to use Windows Authentication rather than SQL Authentication. When I have to use SQL Authentication, I choose to not save the password.

This is where it gets good. We begin to define the trace properties at this point.

We start on the General tab first on the Trace Properties.

Trace Name – in some cases I might have several traces running, filtered on specific items. To make sure I know what is what, I’ll label each appropriately.

Trace Provider Name/Type/Version – this is not user definable and dependant on the type of service you are connecting to (SQL Server or Analysis Services)

Use the template – There are predefined templates that come with SQL Profiler, but if you have custom templates they will show up in this list. I’ll describe custom templates on another blog post.

Save to file – Checking this box allow you to persist the trace file to disk directly. This helps with the TEMP location on you computer, allowing you to choose the location of the trace files.

Save to table – Checking this will allow you to save a trace directly to a sql server table. I don’t normally do this, and wouldn’t dream of doing it on a production server. Ok, so if you check that, you’ll be prompted with a “Connect To…” dialog and then get this dialog

Choose your database, the owner, and the table. If it isn’t there, it will create it for you. You can always take a trace file and save it to a database table after you are done tracing. That is what I typically do. It makes it far easier to filter data and analyze the results.

Enable trace stop time – will cancel the trace at the specified time.

Now the Events Selection tab

We are looking as the server events and data columns that this trace will profile. By default there ends up being a lot more than is normally needed.

• Security Audit – Audit Login/Audit Logout – for .Net languages, this basically translates to Opens and Closes on connection objects. I wouldn’t say that it is a specific one-to-one, but it is pretty close. Note there would be no data for CPU, Reads, Writes, and Duration for the login event - and it does not make sense there would be. Nothing has occurred yet at that point. There are many audit events (to be described in future blog posts in this series)
• Sessions – ExistingConnection – shows the properties of the existing connections when the trace was started, such as SET properties. This is the only event in this category
• Stored Procedures – RPC:Completed – Occurs when a remote procedure call (RPC) has been completed. In other words, this is the event that fires when a stored procedure has finished its work. It must be called as a stored procedure for this event to fire (as in CommandType = CommandType.StoredProcedure). There are many other events in this category.
• TSQL – SQL:BatchStarting/SQL:BatchCompleted – These events mark the beginning and the ending of a batch of sql statements. Note there would be no data for CPU, Reads, Writes, and Duration for the BatchStarting event - and it does not make sense there would be. Nothing has occurred yet at that point. There are many other events in this category

I’ll be brief with the descriptions of the data columns

• TextData – this is the information passed on the event
• ApplicationName – Name of the client application. The application dictates this name
• NTUserName – Windows user name
• LoginName – SQL Server Security login or windows user name (in DOMAIN\user form)
• CPU – Amount of CPU time in milliseconds used by the event
• Reads – Number of logical disk reads performed by the server on behalf of the event
• Writes – Number of physical disk writes performed by the server on behave of the event
• Duration – Amount of time taken by the event. Measured in microseconds, but displayed in milliseconds by default (can be changed in the options dialog)
• ClientProcessID – process ID of the application. Basically the PID you would find in Task Manager.
• SPID – Server process ID as assigned by SQL Server
• StartTime – start time of the event, when available
• EndTime – end time of the event, when applicable
• BinaryData – binary value dependent on the event class captured

For filter the events you have the Column Filters dialog.  This is a simple way to prevent data from being traced. Let’s look at it

The left column is the columns that are enabled in the trace. You get a nice description in the client tool for what the column contains. You also have an area that for textual types you get a LIKE and NOT LIKE filter. This works just like in a SQL statement. So, if you selected TextData and wanted to see all data that had the text myStoredProc in it you would use %myStoredProc% - note the percent signs. For numerical types, you get

• Equals
• Not equal to
• Greater than or equal
• Less than or equal

One that I normally filter is

TextData Not Like exec sp_reset_connection%

I am not particularly interested in this specific line (for my purposes) and in a connection/session pooling environment like .Net this is called often.

Another item to mention is how to Organize Columns in your trace.

It allows one to either group data together in a trace or to rearrange columns in the trace. I hardly use this at all. Why? Because I tend to import my trace data into tables and analyze from there.

What does this all mean?

The average developers doesn’t care so much about all of these things, but I think it is important to know the basics of the “defaults”. So what would a developer look for here? Let me just list out a few things that I think is important

Writing data calls from code

You can use SQL Profiler to know what is actually being sent to the database. Now, I am a huge proponent of stored procedures, but now many people use data access layers (some contain logging utilities, some may not) it is important to know what is actually being sent to the database. With some data layers (like LINQ to SQL and others) you are not normally directly writing SQL. So, SQL Profiler is a great tool to show you what you are doing and in turn how it is behaving in your database.

Monitoring CPU, Reads, Writes and Duration

There are many times when a developer notices that a page may be taking “too long” to load. Now, there can be many explanations for this, but the first inclination that most developers have is that ‘the database is taking too long’. With regular use of SQL Profiler during development (and a development environment consistent with production in terms of data) you can see the queries that might be problems in the future. Considering that performance numbers can and will vary based upon the hardware you have, the other services running on your machine, server/database configuration, and amount of data, some specific numbers are relative. Keeping that in mind, I’ll group some comments together

SELECT

• Lower numbers for CPU, Reads, and Duration is better
• Writes should be zero (may not be, depends on what is in the statement, such as UDFs)
• If you have high numbers for CPU, consider what kind of JOINs you may be doing, keep GROUP BYs to indexed/keyed columns, reduce sorts if possible

UPDATE

• Lower numbers for CPU, Reads, Writes and Duration
• Try to use PKs or indexed columns for the search predicates

INSERT

• For basic inserts, lower numbers for CPU, Writes, and Duration
• Reads should be close to zero (may not be if it is an INSERT/SELECT)
• If these numbers are increasing, consider the FILL FACTOR on your PK and indexes

DELETE

• Lower numbers for CPU, Reads, Writes and Duration
• Try to use PKs or indexed columns for the search predicates
• If clearing out a table, consider TRUNCATE TABLE (minimally logged operation)

In general, if a statement’s duration is over 100 ms or over 50 ms of CPU time I at least review it. For reads and writes that is a little more difficult. High reads might indicate a problem like unoptimized GROUP BYs or possibly incorrect indexes, incorrect search predicates, or worse index or table scans.

Caching

Not caching from a database perspective, but from a client application perspective. When you are implementing code that does cache results or has possibly multiple calls to the same stored procedure from a single web request, it is important to know what is being sent to the database. SQL Profiler can help

Conclusions

Simply put, using SQL Profiler just with default settings can help you along with the basics of monitoring what is being sent to your SQL Server. In my next couple of blog post on SQL Profiler, I’ll discuss some command line options so you can quickly start profiling and the basics of trace templates and what I use for certain types of tracing.

Posted to SQL Server

Similar Posts

1. SSMS Custom Keyboard Shortcuts
2. Event Calendar for GraffitiCMS
3. philly.net Code Camp 2008.3 Presentation and Code