Statistics Parser

In the last post we looked at using the STATISTICS IO and STATISTICS TIME commands to measure query performance.

If you’ve started using these, you may notice that once you start to troubleshoot longer scripts or stored procedures that reference lots of tables or have multiple queries, you start getting lots of output. Sometimes it can sprawl across several screens worth. That can make it a a bit of a pain to total up the numbers, or to quickly see if a change you have made has had a positive effect.

Here’s the STATISTICS output from a troublesome query I was looking at recently:
SQL Server parse and compile time:
CPU time = 0 ms, elapsed time = 0 ms.
SQL Server parse and compile time:
CPU time = 140 ms, elapsed time = 140 ms.

SQL Server Execution Times:
CPU time = 0 ms,  elapsed time = 0 ms.
(188 row(s) affected)

Table ‘ParameterValue’. Scan count 14, logical reads 2350, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘ParameterDefinition’. Scan count 8, logical reads 456, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 8, logical reads 105600, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Workfile’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘ParameterDataType’. Scan count 0, logical reads 376, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

SQL Server Execution Times:
CPU time = 2371 ms,  elapsed time = 655 ms.

SQL Server Execution Times:
CPU time = 2511 ms,  elapsed time = 797 ms.

Now that’s not too bad, and it’s fairly simple for me to add up the numbers of reads. But you also can find yourself copying and pasting the output from several iterations of changes into notepad documents or query windows so you can compare them later, and it can become a bit of a pain to keep track of.

That’s what I used to do, until I discovered the STATISTICS parser tool.

This a free web-based tool to help you keep track of your STATISTICS output, which will also format the results nicely for you and produce totals. It’s very simple and easy to use:

http://statisticsparser.com/
StatisticsParser1
You simply paste the STATISTICS output into the big box and hit the “Parse” button. You can also enter a Page Title that will become the name of the Tab in your browser to make it easier to keep track of different sets of output.

The parser will turn the set of output for each query into an easy to read table and then will also provide a Totals table that shows you (not surprisingly) the totals across all your queries. Here’s the output above formatted via the tool (I am just showing the final totals):

StatisticsParser2

Personally I find that significantly easier to read!

Watch out though, the total CPU time can be double-counted. This is because the STATISTICS TIME output can sometimes include a total itself. If I look at just the TIME sections from the output above I have:

SQL Server parse and compile time:
CPU time = 0 ms, elapsed time = 0 ms.
SQL Server parse and compile time:
CPU time = 140 ms, elapsed time = 140 ms.

SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.

SQL Server Execution Times:
CPU time = 2371 ms, elapsed time = 655 ms.

SQL Server Execution Times:
CPU time = 2511 ms, elapsed time = 797 ms.

If you look carefully at that you’ll see that the last set of entries (CPU time = 2511ms, elapsed time = 797ms) are totals of the other numbers. If you then look at the Statistics Parser output above you’ll see that it has added those to the previous outputs to give a total CPU time of 5.022 seconds (5,022ms).

Still we’re mainly interested in getting the IO down so I ignore that for now. The main thing I’m interested in is the total number of reads:
108,782

I make my changes to the stored procedure, execute it and get the STATISTICS output again:

SQL Server parse and compile time:
CPU time = 0 ms, elapsed time = 0 ms.
SQL Server parse and compile time:
CPU time = 0 ms, elapsed time = 0 ms.

SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.

SQL Server Execution Times:

CPU time = 16 ms, elapsed time = 0 ms.

SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 1 ms.

(189 row(s) affected)

SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.

(188 row(s) affected)
Table ‘Workfile’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘ParameterDefinition’. Scan count 2, logical reads 396, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘ParameterValue’. Scan count 3, logical reads 708, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘#ParameterNames_____________________________________________________________________________________________________0000000000CB’. Scan count 2, logical reads 718, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘ParameterDataType’. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

SQL Server Execution Times:
CPU time = 78 ms, elapsed time = 80 ms.

SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.

SQL Server Execution Times:
CPU time = 94 ms, elapsed time = 83 ms.

You can see my output is getting longer and starting to become more challenging to read – I broke the original query down into a few simpler steps, but each produces its own output. No worries, I open up a new tab in my browser and go to a second instance of the Statistics Parser. I give this one the Page Title “After”. I paste in my output and I hit parse:

StatisticsParser3

You can now see I have a “Before” and an “After” tab so it’s easy to flick back and forth if I’ve forgotten my totals.

I can now easily see that my total number of reads – previously 108,782 – is down to 1,824. That’s about 50 times better. The CPU time is down by a factor of about 25, not as good as the reads, but I call that good enough and proclaim that tuning task complete!

Understanding Keys and Certificates with Always Encrypted

Always Encrypted on SQL 2016 is pretty easy to set up. There’s even a single wizard to guide you through the whole process. However, the best way to get into trouble with this technology is by not clearly understanding what is going on.

I personally find I understand things best when I am solid on the basics. It also means I can then usually logically extrapolate to answer any questions that come up.

So here we’ll go into a little detail about the keys and certificates involved…

To get up and running with Always Encrypted you need three things:

  • An Always Encrypted Certificate to store on your application server / client machine
  • A Column Master Key in your database
  • A Column Encryption Key in your database

You can actually create all of these through SQL Server Management Studio, in fact the first two items get created in the same step, so let’s run through that process, and we can look at what these items are, and what they get used for in more detail as we go along.

Creating the Certificate and the Column Master Key

You can find Always Encrypted Keys under the Security folder for your database. Right-click over column master keys and select to create a new one:

SSMS_AE

And up comes the GUI:

AE_ColumnMasterKey

The Name field is the name for the Column Master Key within your database – you can see I’ve decided to call mine “Wibble”.

Beneath that you can select – or create – the certificate to be associated with the Key. You can see I already have a couple in the selected key store as I’ve been through this process before, and the selected certificate is highlighted. If you don’t have one, you can select from the “Key Store” drop down where you want the certificate to be stored, and then click the “Generate Certificate” button to generate a new certificate in that store.

It’s worth noting at this point that the certificate is created on your local machine – not the server hosting SQL Server. We’re used to SSMS being the tool through which we interact with and do things at the server end, so this can be a bit counter-intuitive, but in terms of what we are trying to achieve it makes sense. We want to create a certificate that exists on the client – so in this case that’s your local machine.

Click okay and the Column Master Key and certificate get created. You can see your new key in SSMS:

AE_Wibble

To understand what this key actually is, I’m going to right-click and generate the SQL definition:

CREATE COLUMN MASTER KEY [Wibble]

WITH

(

KEY_STORE_PROVIDER_NAME = N'MSSQL_CERTIFICATE_STORE',

KEY_PATH = N'CurrentUser/My/D492BA86737FECDABB14D13476122C1E4BD217D2'

)

GO

We only have two values, KEY_STORE_PROVIDER_NAME and KEY_PATH. All this is telling us is where to find the certificate we just created. So you can see that the Column Master Key is just a pointer to a certificate stored on client machines.

Creating the Column Encryption Key

This is the last thing we need before we can set up encryption on our columns. You can find “Column Encryption Keys” underneath “Column Master Keys” in SSMS. Again, right-click and bring up the GUI:

AE_ColumnKey

You can see I’ve called mine MyColumnKey, and I’ve selected from the drop down that it should be created using the Column Master Key I created earlier – “Wibble”. Click okay and the key gets created.

Again I’m going to generate the SQL definition for my new Column Encryption Key so we can see what’s inside it:

CREATE COLUMN ENCRYPTION KEY [MyColumnKey]

WITH VALUES

(

COLUMN_MASTER_KEY = [Wibble],

ALGORITHM = 'RSA_OAEP',

ENCRYPTED_VALUE = 0x016E000001630075007200720065006E00740075007300650072002F006D0079002F006400340039003200620061003800360037003300370066006500630064006100620062003100340064003100330034003700360031003200320063003100650034006200640032003100370064003200A6296213760796AA271152F6D1F1D8C5B4B84ADDB660EC700936B010918CF62FA63C9F716BCB4337D4D48E7F5ABB879F09EA0ABF2ABFDB54E4740DCD88631C533BE530A1CF491A63B0A334FBBA1971C4B22C18E7B8DFCB9975754F9232E47C5DED5857B6032D4BB95B3C1232D3168366B6A1DA4FFC637849FBC3226FFB78981BD1596DE0CD3ED894B127855FD93F3F40E6DB9602482A9AD69CE96C3D879F544534135FFCCA789CB69E3C52C3A7CCB3AFC55850DA7DD82BE963A36A3AC77ECB26CE77A01F3CC43CEA26757548785A4C5A538250C325CEB106495211A625CDAFF5E9EED96EDE3AFFC8E6518E0E29C4F796209EE5ED35B04257844E6ACF74B0EEF907F667D699FE01BCF29BDA275BC9260E03130DA7008F30CD6CBB12F60AD6B47E1B5338D18FAF50DD6EBE3712FC4E814E71CA1E4F605F97F6DB51B1BBB6819E5BF5E8DBB6EB453B268173DB0B69B6CE78A57BC7C98FBBC34BA205B7DB59FEECCEB235A38B089D31C4892FB870A305D5FB1FC69A91C009B9F9D2B572C0DA2DCAC76C6AF48DF54B3C84D7110BD903F06817FD9BC100773028F357966F029B89DF49B8564DD901349F1304124B3DC691A626568C30224766C18B631CD42097DCE0B927A9A401A51EFE05BD5DC6CB9F7F2F3166A5D2A1DECC7D060C26B41D42BF2EF9ACA5919568979F713EFA655EEEF2A4280060D0D73553633B0BEA4925E595805C

)

GO

We can see it tells us what Column Master Key this is based on, what Algorithm has been used, and a long binary Encrypted Value. So what is this?

What has happened is that in the background a value has been created that will act as the Column Encryption Key when MyColumnKey is used to encrypt (or decrypt) data in a column. That value has then itself been encrypted using the certificate that the Master Column Key is based on. The encrypted value of the Column Encryption key is what then gets actually stored in the database.

That might seem overcomplicated. If we can encrypt data using the certificate, then why do we need a separate key in the database?

It actuality it’s very important that we have both. Imagine the scenario where we just use a certificate as the key (or just a single key in another form) and that expires, or worse there is a breach and it gets copied. In this case we are going to have to change our certificate or key. But if we change the key, how are we going to read the existing data in the table?

There is only one way, which is to decrypt all the existing data, and then re-encrypt it with the new key. Let’s say you have tens of millions of records, this might take a while, and will certainly require the application to be taken offline. Also, while this process is being undertaken, the data is unencrypted and at risk.

With the approach taken by Always Encrypted, we have a way around this. Let’s say we have to replace our certificate. All we need to do is create a new COLUMN MASTER KEY based on the new certificate, then we can decrypt our COLUMN ENCRYPTION KEY, ENCRYPTED_VALUE using the old certificate and re-encrypt that value with our new certificate. Because the actual Key value itself hasn’t changed then we can continue to read the existing data using the new certificate.

In practice this is done for you in the background through a process called “Key Rotation”. A given COLUMN ENCRYPTION KEY can actually support having two COLUMN MASTER KEYS at the same time – each of which would have it’s own encrypted version of the same underlying key. This allows the process to add a new master key and associated encrypted value, before removing the old one – which allows the key rotation process to occur fully online.

There is (understandably) a performance overhead to having two Keys at once so avoid doing this for any other reason.

I’m not going to go any further into the process of Key Rotation here, but it is generally seen as good practice to retire and refresh your certificates regularly – when you create them through SSMS they get a default expiry data one year in the future. So if you are implementing Always Encrypted, it is important to be confident you know how you will approach things when your certificate expires.

So how do the keys get used in practice?

When you run a query over a connection with column encryption enabled, the following steps occur:

  1. The client sends a preliminary call to the SQL Server Instance containing the query text. In this call it is asking for details of potential encryption on any columns involved in the query and what keys may be involved.
  2. If there are encrypted columns involved, SQL supplies that information, as well as the Column Master Key (which tells the client where to find the relevant certificate locally), and the encrypted value of the Column Encryption Key for each encrypted column.
  3. Using the information and keys, the client can then encrypt any values it needs to before sending to the database. For instance, if it is inserting data into, or looking for a particular value, in an encrypted column.
  4. The modified query is now sent to SQL for execution.
  5. SQL returns any results – with values in encrypted columns remaining in their encrypted form.
  6. If a resultset is returned, the client uses the information and keys supplied in step 2 in order to decrypt any encrypted values.

So you can see there are a few extra steps over and above your normal query execution, and that does create some performance overhead.

Final thoughts

Once you get into the business of having encryption keys then the process by which you manage them is going to be critical. If they are too easy for anyone in your organisation to access, then you may sabotage your efforts in encrypting the data in the first place.

You are going to want to have different keys in your production environments to those you have in test and development as a minimum.

Think about how you are going to manage that through your deployment processes. Do you want to generate new keys and certificates with fresh deployments? In which case where are they backed up, and who has access to them? You want to be absolutely sure you can recover the certificate your Master Column Key is based on if it is lost from your production environment. Otherwise your encrypted data is gone for good.

If you are shipping a product to a client with Always Encryption enabled – do they have the knowledge and processes to manage the keys moving forward?

And what is your plan for key rotation? How will the right people be reminded before certificates expire that they need to do something about it?

This is a great technology, and Microsoft has made it as simple as possible to use in practice. Nonetheless, it does need to be used with care.

Tuning Parallelism on SQL Server

Parallelism and MAXDOP

There’s no doubt that parallelism in SQL is a great thing. It enables large queries to share the load across multiple processes and get the job done quicker.

However it’s important to understand that it has an overhead. There is extra effort involved in managing the separate streams of work and synchronising them back together to – for instance – present the results.

That can mean in some cases that adding more threads to a process doesn’t actually benefit us and in some cases it can slow down the overall execution.

We refer to the number of threads used in a query as the DOP (Degree of Parallelism) and in SQL Server we have the setting MAXDOP (Maximum Degree of Parallelism) which is the maximum DOP that will be used in executing a single query.

Microsoft generally recommend caution setting MAXDOP above 8:

https://support.microsoft.com/en-gb/help/2806535/recommendations-and-guidelines-for-the-max-degree-of-parallelism-configuration-option-in-sql-server

Here’s a nice post here from Kendra Little talking about how having higher settings can actually slow down your query execution time:

https://www.brentozar.com/archive/2013/12/q-can-high-maxdop-make-a-query-slower/

Out of the box, MAXDOP is set to 0, which means there is no limit to the DOP for an individual query. It is almost always worth changing this to a more optimal setting for your workload.

CXPACKET waits

Often in tuning a SQL Server instance we will look at wait stats – which tell us what queries have been waiting for when they run. CXPACKET waits are usually associated with parallelism and particularly the case where multi-threaded queries have been stuck waiting for one or more of the threads to complete – i.e. the threads are taking different lengths of time because the load hasn’t been split evenly. Brent Ozar talks about that here:

https://www.brentozar.com/archive/2013/08/what-is-the-cxpacket-wait-type-and-how-do-you-reduce-it/

High CXPACKET waits can be – but aren’t necessarily – a problem. You can cure CXPACKET waits by simply setting MAXDOP to 1 at a server level (thus preventing parallelism) – but this isn’t necessarily the right solution. Though in some cases in can be, SharePoint for instance is best run with MAXDOP set to 1.

What you can definitely deduce from high CXPACKET waits however is that there is a lot of parallelism going on and that it is worth looking at your settings.

Cost Threshold for Parallelism

This is another setting available to us in SQL Server and defines the cost level at which SQL will consider a parallel execution for a query. Out of the box this is set to 5 which is actually a pretty low number. Query costing is based on Algorithm’s from “Nick’s machine” the box used by the original developer who benchmarked queries for Microsoft.

Nicks_Machine

(Nick’s Machine)

Compared to modern servers Nick’s machine was pretty slow and as the Cost Threshold hasn’t changed for many years, it’s now generally considered too low for modern workloads/hardware. In reality we don’t want all our tiny queries to go parallel as the benefit is negligible and can even be negative, so it’s worth upping this number. Advice varies but generally recommendations say to set this somewhere in the range from 30 to 50 (and then tuning up and down based on your production workload).

There are many articles in the SQL Server community about how the out of the box setting is too low, and asking Microsoft to change it. Here’s a recent one:

http://www.scarydba.com/2017/03/13/change-the-cost-threshold-for-parallelism/

Tuning Parallelism

In tuning parallelism we need to think about how we want different sized queries to act on our server.

Small Queries

In general we don’t want these to go parallel so we up the Cost Threshold to an appropriate number to avoid this. As discussed above 30 is a good number to start with. You can also query your plan cache and look at the actual costs of queries that have been executed on your SQL Instance to get a more accurate idea of where you want to set this. Grant Fritchey has an example of how to do that here:

http://www.scarydba.com/2017/02/20/estimated-costs-queries/

As he mentions in the post, this assessment can be quite expensive to run – so do it when things are quiet.

Medium to Large Queries

This is where we want to take advantage of parallelism, and do so by setting MAXDOP to an appropriate level. Follow the guidelines from the Microsoft article referenced above. Here it is again:

https://support.microsoft.com/en-gb/help/2806535/recommendations-and-guidelines-for-the-max-degree-of-parallelism-configuration-option-in-sql-server

Often the answer is going to be simply to set it to 8 – but then experiment with tuning it up and down slightly to see whether that makes things better or worse.

Very Large Queries

If we have a mixed workload on our server which includes some very expensive queries – possibly for reporting purposes – then we may want to look at upping the MAXDOP for these queries to allow them to take advantage of more processors. One thing to consider though is – do we really want these queries running during the day when things are busy? Ideally they should run in quieter times. If they must run during the day, then do we want to avoid them taking over all the server power and blocking our production workload? In which case we might just let them run at the MAXDOP defined above.

If we decide we want to let them have the extra power then we can over-ride the server MAXDOP setting with a query hint OPTION(MAXDOP n):

https://docs.microsoft.com/en-us/sql/t-sql/queries/hints-transact-sql-query

You will want to experiment to find the “best” value for the given query. As discussed above and as shown in Kendra Little’s article, just setting it to the maximum number of cores available isn’t necessarily going to be the fastest option.

Closing Thoughts

Parallelism is a powerful tool at our disposal, but like all tools it should be used wisely and not thrown at every query to its maximum – and this is often what happens with the out of the box settings on SQL Server. Tuning parallelism is not a knee-jerk reaction to high CXPACKET waits, but something we should be considering carefully in all our SQL Server implementations.

I personally have seen numerous instances where a server is going crazy, timing out all over the place, where changing the parallelism settings has instantly brought everything back to earth, operating smoothly and quickly once more.

Measuring SQL Query Performance

When running workshops on the subject of SQL Query Performance the first question I always ask is how do we measure the performance of a query? Or to look at it another way  – how do we measure the resources it consumes?

Attendees have come up with a range of answers from “With a stopwatch” (which I like a lot) to the slightly more technical “Using Profiler”. I like the first answer just because that’s where we all start. We run something from an application and we literally time how long it takes, or we run something in SSMS and we use the counter near the bottom right of our query window to tell us how long it took. We may even run something 100 times in a loop and capture the overall time so we can take an average.

SQL Server Profiler is also good when trying to capture what is actually happening in a given environment.

But there is a better way…

Using STATISTICS commands

When we’re working on a query in SSMS there is an easier, more accurate, and more detailed approach than any of the others available, which is to use the following two commands:
SET STATISTICS TIME ON;

This command tells SSMS to capture the consumed CPU time and elapsed time related to any queries you subsequently run in that query window. The output is sent to the Messages tab.

SET STATISTICS IO ON;

This command tell SSMS to capture the amount of data read from disk or memory by any subsequent queries in that window. Again the output is sent to the Messages tab.

Let’s look at some quick examples. For these I’ll use the StackOverflow database (here’s a post from Brent Ozar on how you can download this database for your own use https://www.brentozar.com/archive/2015/10/how-to-download-the-stack-overflow-database-via-bittorrent/):

SET STATISTICS TIME ON;
SELECT COUNT(*) FROM dbo.Users;

Output:
SQL Server parse and compile time:
CPU time = 0 ms, elapsed time = 1 ms.
(1 row(s) affected)

SQL Server Execution Times:
CPU time = 422 ms,  elapsed time = 2296 ms.

You can see we now have a fairly accurate measure of how long that query took to run (and how long to parse and compile). The CPU time is how much CPU is used, the elapsed time is how much time the query took overall. You’ll see the elapsed time is much longer the the CPU time, this generally means SQL is waiting for something the rest of the time, perhaps for data to be read from disk or memory, or perhaps something else (like locking and blocking).

Now let’s look at STATISTICS IO for the same query.
SET STATISTICS IO ON;
SELECT COUNT(*) FROM dbo.Users;

Output:
Table ‘Users’. Scan count 5, logical reads 24914, physical reads 1, read-ahead reads 24770, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

You’ll see that there’s a bit more info here, let’s run through each piece in order:

  • Table – First we have the name of the table the reads are being generated from – when we have a bunch of tables referenced this can help us to work out where to focus our tuning efforts.
  • Scan Count – In simple terms this is the amount of times the table was accessed. This isn’t always a massively useful metric. In can also be Zero in some specifics scenarios such as searching for one specific value in a  clustered index.
  • Logical Reads – this is the number of data “pages” read from memory. A data page is 8KB in size, so this query has read about 200MB from the User table (which is basically the whole table).
  • Physical Reads – This is the number of data pages read from disk.
  • Read-Ahead Reads – These are also physical reads. In this case pages read from disk, but in theory read ahead of time e.g. while the processor is doing something else and doesn’t need them yet. In practice SQL has started to read these before it needs them, but is still reading them as the query is consuming them so we do end up waiting for the disk to supply most of the data. If we look back at the CPU time and elapsed time above, it is a pretty reasonable assumption that the time taken up waiting for these physical reads accounts for much of the difference between the CPU time and elapsed time.
  • LOB – The columns are repeated for LOB data, which is “Large Object” data such as varbinary(max) columns and other such “blobs”. These get stored outside of the main data page. We’re not going to worry about these too much for the moment.

Physical vs Logical Reads

It is worth knowing that SQL (in general) will try to retain data it has read in memory for as long as possible. This is because Logical Reads (from memory) are much much faster than Physical Reads (from disk). You may have heard people saying that SQL Server is very aggressive about using memory, or heard complaints like “SQL is consuming all the memory on the server”. This is why. SQL want to do as much querying as possible from memory and save on those expensive physical reads. We allocate a maximum amount of memory to SQL Server and over time it will use as much of that allowance as it can. This is also one of the reasons why querying slows down after you restart SQL Server, all your queries are going to go back to reading from disk until SQL has that data in memory once more.

It’s also good to understand that in the numbers above SQL is not reading one set of data from disk and another set from memory. Rather it is a two stage process, required data is read from disk into memory (the physical/read-ahead reads) and then the whole set is read from memory (the logical reads). So the number of logical reads includes the number of pages read first from disk.

We can see that effect if we run the query again. This time I’ll include both commands:

SET STATISTICS TIME ON;
 SET STATISTICS IO ON;
 SELECT COUNT(*) FROM dbo.Users;

Output:
Table ‘Users’. Scan count 5, logical reads 24982, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

SQL Server Execution Times:
CPU time = 546 ms,  elapsed time = 164 ms.

You’ll see our physical reads ( including read-ahead reads) have now dropped to zero. This is because we’ve already read this data from disk the first time we ran the query and SQL has retained the data in memory. Logical reads have stayed about the same. You’ll hopefully also see that our CPU time is reasonably similar at around 500ms, but our elapsed time has dropped dramatically as we no longer had to wait for slow reads from disk.

You might also notice that the elapsed time is now actually shorter than the CPU time which can be a bit confusing. The query has consumed 546ms of CPU time, but only took 164ms from beginning to end. How than this be? The answer is that our query has gone parallel over several CPU cores. Counting all the records in a large table is actually a pretty resource hungry operation as you can see, so SQL has decided to save time by breaking the task into pieces and running those sub tasks concurrently.

I should probably add a caveat here in that I have actually seen STATISTICS TIME return results where the elapsed time is marginally shorter than the CPU time even when the query is single-threaded. I queried this with a performance tuning specialist from Microsoft  who I was working with at one of our clients and he admitted that these figures weren’t always 100% accurate – they are however the most accurate you’ll get.

Flushing Data From Memory

You might sometimes want to see how your query would perform if it’s having to read all its data from disk. This might be more appropriate to how it is likely to be working in the wild. In that case you can run the following command which will flush all the data from memory (so don’t run it on a production environment!).
DBCC DROPCLEANBUFFERS;

If you execute this and then were to re-run the above query and capture the IO you’d see that the physical/read-ahead reads are back.

In SQL Server the area of memory where data is stored is referred to as the Buffer Cache. Within that Cache we have clean pages where the data in memory is the same as the data on disk, and dirty pages which are pages that contain modifications that have yet to be written to disk. The above command only flushes (or drops) the clean pages (or buffers). Just in case you were wondering why it was called DROPCLEANBUFFERS…

A Slightly More Complex Example

The above example with just the one table should make it clear what these commands do, but let’s look at a query that goes across a couple of tables and does a bit more work so you can see the sort of output you’ll get:

SET STATISTICS TIME ON;
SET STATISTICS IO ON;
SELECT TOP 10
u.Id
,
   u.DisplayName,
   COUNT(p.Id) AS NumberOfPosts
FROM dbo.Users u
INNER JOIN dbo.Posts p
   ON u.Id = p.OwnerUserId
GROUP BY u.Id, u.DisplayName
ORDER BY NumberOfPosts DESC;

Output:
SQL Server parse and compile time:
CPU time = 0 ms, elapsed time = 54 ms.
(10 row(s) affected)

Table ‘Posts’. Scan count 5, logical reads 51352, physical reads 1, read-ahead reads 51192, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Users’. Scan count 0, logical reads 94, physical reads 45, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 336, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Workfile’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

SQL Server Execution Times:
CPU time = 8002 ms,  elapsed time = 5597 ms.

You can see here that the IO for both tables referenced in the query has been captured. This is very useful in telling us where the bulk of the work is being done.

Notable here also are the references to “Worktable” and “Workfile”. These often appear in the output to STATISTICS IO for more complex queries. In general it is worth thinking of these as internal objects SQL uses to store temporary resultsets while processing your query. The difference between the two is the type of resultsets they store and for which particular operations. This can make it a bit more challenging to work out which part of your query is generating the most work when the highest number of reads appear against these. You end up needing to look at the execution plan and trying to work out what operations these could be related to. We may get to more of that in a later post.

Using this information to Tune your Queries

To close, I just want to mention how you should use this information to focus your efforts when tuning queries. Intuitively we all think in terms of time when we think in terms of query performance, but in practice it is much better to focus on the output of STATISTICS IO when you are trying to make improvements.

The IO gives you much more information, and while figures for both CPU and IO will vary depending on what is going on on the server, the IO figures are more static and therefore you can have more confidence that changes you see are the results of your tuning efforts. It also allows you to focus on tables one at a time as you tune multi-table queries.

Both IO and TIME are measures of work being done on a server. If you can reduce the number of reads generated by your query then that is generally the best measure of improvement and will likely have similar benefits to the overall time taken by the query.

So in your tuning efforts, focus on the logical and physical reads and try to get the totals for these down as low as possible. Generally you’ll start with operations on the table that generates the highest number of reads and go on from there.

SQL Server 2016 SP1 – A significant change to licencing

Myself of all people am probably least likely to get excited by licencing changes in a product, but with the SP1 release of SQL Server 2016 there are some significant changes to benefit ISVs. I had to look up that acronym and apparently it’s Independent Software Vendors – which is the type of organisation I work for.

The change has brought many features that previously were only available in Enterprise Edition into the Standard version of the product – and something that has been mentioned less – even into the Express version in most cases.

This is fantastic where we are delivering software to clients, some of whom who may wish to use Enterprise, some Standard (or even Express). We no longer have to keep usage of these features out of our core product, which means we are able to maintain a single codebase. I can think immediately of Table Partitioning, Database Snapshots and Data Compression as things we might like to be able to use as standard in our products – but which were previously only available in Enterprise Edition (or Expensive Edition as it’s otherwise known).

On top of those, the new security features in SQL 2016, including AlwaysEncrypted (more on that in a later post) are now available in all the versions. These features are likely to become critical to us as the GDPR comes into effect (the European General Data Protection Guidelines) and we need to start making sure the Personal Identifiable Information in our products is protected to the highest levels. Having these features available in standard edition is going to make our lives one hell of a lot easier.

Here’s the breakdown of features available in the different versions of SQL 2016, contrasting what was available in the RTM version to what is now available in SP1 (picture taken from MSDN):

sql2016sp1licensing

There are still a bunch of Enterprise features not included in that list, but as a generalisation, most things that are configured at the level of database code (rather than server level and HADR) are included. The change is being sold as primary targeted at software organisations like ourselves and giving us the ability to have consistent database code for all our deployments.

On top of that, in Standard edition you can now have up to 24 processor cores and 128GB of memory (plus a bit more if you use memory optimised tables or columnstore indexes). That makes it fairly viable for even enterprise level workloads.

All in all, this change is great news for us software vendors in terms of what we can offer to our clients, and another good reason to upgrade to 2016.

Splitting Strings on SQL Server 2016

A small change, but a great one, in SQL 2016 is native support for splitting strings.

This has to be about the most common user defined function that people write in SQL Server. I’ve certainly seen it across many companies and clients that I’ve worked for over the years. From use in SSRS, or passing multiple values to stored procedures it’s been fairly ubiquitous.

There are countless blog posts about the best way to do this, it’s virtually a competition amongst the best and brightest SQL minds.

From Jeff Moden’s Tally versions:
http://www.sqlservercentral.com/articles/Tally+Table/72993/

To Adam Machanic’s CLR one:
http://sqlblog.com/blogs/adam_machanic/archive/2009/04/28/sqlclr-string-splitting-part-2-even-faster-even-more-scalable.aspx

Aaron Bertrand has a great post here that outlines many of these methods and does a performance comparison.
https://sqlperformance.com/2012/07/t-sql-queries/split-strings
(SPOILER : Adam Machanic wins)

With SQL 2016 we have a new way, and apparently it’s even substantially faster that Adam M’s CLR. Figures from Aaron again:
https://sqlperformance.com/2016/03/sql-server-2016/string-split

STRING_SPLIT

This couldn’t be simpler, but I’ll detail it here briefly. The syntax is:
STRING_SPLIT (string, separator)
So in a basic example:
DECLARE @SplitMyString VARCHAR(255) = 'Value1,Value2,Value3,Value4';
SELECT *
FROM STRING_SPLIT(@SplitMyString,',');

And the results:

SplitMyString.png

Easy Peasy!