Bug with STATISTICS TIME?

I love the STATISTICS IO and STATISTICS TIME commands. They are such a powerful and easy way to be able to measure improvements when performance tuning (Measuring SQL Query Performance).

You have to be a little bit wary though, there are a few places where they don’t report figures correctly such as this bug (fixed from 2014):
https://connect.microsoft.com/SQLServer/feedback/details/767250/statistics-io-under-reports-logical-reads-for-parallel-plans

Also anything to do with a MSTVF (multi-statement table value function) is likely to be reported incorrectly (another reason not to use such functions!).

Today I was doing some testing to compare different methods of auditing data, and I came up against another (bug?) I hadn’t seen before. So I thought I’d share.

This is running on SQL 2016 – I haven’t checked it on earlier versions.

I’ll create two identical tables for comparison, identical except one has a trigger against it that inserts changes to an audit table.

CREATE DATABASE StatisticsBug;
USE StatisticsBug;
CREATE TABLE VanillaTable
(
Id INT IDENTITY(1,1) CONSTRAINT PK_VanillaTable PRIMARY KEY CLUSTERED,
SomeText VARCHAR(1000),
ModifiedBy VARCHAR(128),
ModifiedDate DATETIME
);
CREATE TABLE TableWithTrigger
(
Id INT IDENTITY(1,1) CONSTRAINT PK_TableWithTrigger PRIMARY KEY CLUSTERED,
SomeText VARCHAR(1000),
ModifiedBy VARCHAR(128),
ModifiedDate DATETIME
);
CREATE TABLE TableWithTrigger_Audit
(
Id INT,
SomeText VARCHAR(1000),
ModifiedBy VARCHAR(128),
ModifiedDate DATETIME,
AuditId INT IDENTITY(1,1) CONSTRAINT PK_TableWithTrigger_Audit PRIMARY KEY CLUSTERED,
AuditDate DATETIME
);
CREATE TRIGGER TableWithTrigger_trigger
ON dbo.TableWithTrigger
after INSERT, UPDATE, DELETE
AS
BEGIN
INSERT INTO dbo.TableWithTrigger_Audit(Id, SomeText, ModifiedBy, ModifiedDate, AuditDate)
SELECT Id, SomeText, ModifiedBy, ModifiedDate, GETDATE()
FROM deleted;
INSERT INTO dbo.TableWithTrigger_Audit(Id, SomeText, ModifiedBy, ModifiedDate, AuditDate)
SELECT Id, SomeText, ModifiedBy, ModifiedDate, GETDATE()
FROM inserted;
END;

Now I’m going to insert a bunch of rows into each table and capture the CPU output so we can compare. Obviously I expect the one with the trigger to have to do more work, I’m just demonstrating both to show that the first example works correctly, but the second one seems a bit more dubious.

First the table without the trigger:

--Insert a million rows into table without trigger, capture CPU
SET STATISTICS time ON;

INSERT INTO dbo.VanillaTable(SomeText, ModifiedBy, ModifiedDate)
SELECT TOP 1000000  'SomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeText', 'Matt', GETDATE()
FROM sys.objects a, sys.objects b, sys.objects c, sys.objects d;

Let’s look at the output:
SQL Server parse and compile time:
CPU time = 31 ms, elapsed time = 64 ms.
SQL Server Execution Times:
CPU time = 4766 ms, elapsed time = 5596 ms.

That all seems quite reasonable and what we’d expect to see.

Now let’s repeat the same test for our table with a trigger:

--Insert a million rows into table with trigger, capture CPU
SET STATISTICS time ON;

INSERT INTO dbo.TableWithTrigger(SomeText, ModifiedBy, ModifiedDate)
SELECT TOP 1000000  'SomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeTextSomeText', 'Matt', GETDATE()
FROM sys.objects a, sys.objects b, sys.objects c, sys.objects d

And look again at the CPU:
SQL Server parse and compile time:
CPU time = 31 ms, elapsed time = 31 ms.
SQL Server parse and compile time:
CPU time = 6031 ms, elapsed time = 8782 ms.
SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.
SQL Server Execution Times:
CPU time = 7266 ms, elapsed time = 9205 ms.

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

Overall the execution takes over twice as long, which I expect as – due to my trigger – I’m now inserting to two tables. This is represented by the last entry which is the total execution time.

I want to draw your attention though to the second set of parse and compile time figures (highlighted in bold). These seem to be saying that to compile the query took over 6 seconds of CPU. I find this highly suspect.

This is also highlighted by the fact that the final execution time is actually the sum of 6031 (which is reporting as parse and compile) and 7266.
So my belief was that the output was incorrectly reporting execution time as compile time.

I captured the actual execution plan for the query to check the compile time. In the plan XML you can find the element CompileCPU (measured in ms).

As there are three statements covered by the plan (the initial insert plus two more in the trigger) I find three values:

Statement 1:

CompileCPU1

Statement 2:

CompileCPU2

Statement 3:

CompileCPU3

28ms, 1ms and 1ms for a total of 30ms. That’s actually pretty close to the initial figure reported in the statistics output, any difference is probably just rounding:
SQL Server parse and compile time:
CPU time = 31 ms, elapsed time = 31 ms.

That seems double confirmation to me that the output should be reporting the 6031ms and 8782ms not as CPU and Elapsed for Parse and Compile, but rather CPU and Elapsed for Execution.

I’d be interested if anyone has any other explanation of this, or to know if you can repeat it. With a bit more confirmation I’ll raise a Connect item.

Thanks for reading!

Avoid “Constants” in T-SQL

Unlike some other languages, T-SQL doesn’t have the concept of a constant.

As good coders, we’ve all at some point tried to use a SQL variable to hold a constant value within a stored procedure, in order to make our code both more readable and maintainable.

I’ll give you an example. Here I’m querying a Task table, and I want all the rows where the TaskStatus is 0 (zero) which means the Task is Open:

SELECT *
FROM dbo.Task 
WHERE TaskStatus = 0;

If someone else comes along to look at this code they don’t know what the value of zero means. My code’s not clear. Worse I might refer to the same value multiple times in my procedure, so if I need to change it later I have to change it in multiple places.

Good practice from other coding languages would say that I replace it with a meaningfully named constant. As mentioned, in T-SQL we don’t have constants so I’ll compromise and use a variable:

DECLARE @OpenTask tinyint = 0;

SELECT *
FROM dbo.Task 
WHERE  TaskStatus = @OpenTask;

Now that’s much more readable – right?

Unfortunately it’s also a bad idea in SQL . Let’s see why.

I’ll create the aforementioned Task table, add an index on TaskStatus. Then I’ll add million rows with status 1 (which we’ll call closed) and 1 row with the value 0 (zero) which is open:

CREATE TABLE dbo.Task
(
    Id INT IDENTITY(1,1) CONSTRAINT PK_Task PRIMARY KEY CLUSTERED,
    UserId INT,
    TaskType INT,
    Payload VARCHAR(255) NOT NULL,
    TaskStatus tinyint NOT NULL
);
GO

CREATE INDEX IX_Task_TaskStatus ON dbo.Task(TaskStatus);

INSERT INTO dbo.Task (UserId,TaskType,Payload,TaskStatus)
SELECT TOP 1000000 1,1,'This Shizzle Is Done',1
FROM sys.objects a, sys.objects b, sys.objects c;

INSERT INTO dbo.Task (UserId,TaskType,Payload,TaskStatus)
SELECT 1,1,'Do This Shizzle',0;

Once that’s completed I’m going to update the statistics just so we know SQL has the most up to date information to produce an optimal execution plan for our queries:

UPDATE STATISTICS dbo.Task WITH fullscan;

Now let’s go back to our original queries. Before I run them let’s think what we want them to do. We have an index on TaskStatus and we only have one row we are looking for, so we’d hope the query will use the index and go straight to the record. The index doesn’t contain all the columns, but that’s okay. We’re only going to have to output one record so if it has to look up the extra columns up in the clustered index that’ll be pretty damn quick.

Let’s run the first query, we’ll capture the execution plan and the STATISTICS output:

SET STATISTICS io ON;
SET STATISTICS time ON;

SELECT *
FROM dbo.Task 
WHERE TaskStatus = 0;

Here’s the execution plan:
Constants1

 

 

 

 

That’s doing exactly what we hoped for, it’s looked up the record in our index using a seek. Then it’s grabbed the rest of the columns from the clustered index using a key lookup.

Here’s the statistics output:
Table ‘Task’. Scan count 1, logical reads 7, 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 = 0 ms, elapsed time = 1 ms.

So that’s a nice small number of reads and less than a millisecond of CPU.

Now let’s run the “improved” version:

SET STATISTICS io ON;
SET STATISTICS time ON;

DECLARE @OpenTask tinyint = 0;

SELECT *
FROM dbo.Task 
WHERE TaskStatus = @OpenTask;

 

Here’s the execution plan this time:

Constants2

That doesn’t look so good. Let’s check the statistics:
Table ‘Task’. Scan count 1, logical reads 5341, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

CPU time = 109 ms, elapsed time = 96 ms.

Those figures tell us the query has got between 100 and 1,000 times worse. So much for the improved version.

So why is this happening?

The answer is simply that the optimizer doesn’t/can’t look at the values inside variables when a piece of SQL is compiled. Therefore it can’t use the statistics against the indexes on the table to get an accurate idea of how many rows to expect back in the results.

We can see that if we compare the properties of the Index Seek Operator from the first query:

Constants3

Against the properties for the Index Scan Operator from the second query:

Constants4

In the first one we can see that the Actual Number of Rows (at the top) exactly matches the Estimated Number of rows (at the bottom). SQL has been able to use the statistics on the index to get an accurate estimate.

In the second this is not the case. We have 500,000 rows estimate, but only 1 actual. This has led SQL down the route of choosing a plan that would have been more effective for 500,000 rows – but is much less effective for 1. In this case it didn’t know what value to optimize for. Lacking that information it used the density value in the statistics and multiplied that by the total number of rows to get the estimate. Or in other words, the statistics tell it that there are two distinct values (0 and 1) in the table. Not knowing which one has been supplied the optimizer figures than on average half the rows will be returned.

So what should do you to make your code clearer?

The simple answer is to use comments, the following is totally clear to its meaning, and will perform optimally:

SELECT *
FROM dbo.Task 
WHERE TaskStatus = 0 -- Open Task;

 

But what about the maintainability issue, where you may have to refer to the same value multiple times in a given procedure?

Unfortunately you’re just going to have to put up with maintaining the value in multiple places, but in general within a well designed application these should be static values (and hopefully integers) so it shouldn’t be too big a deal.

 

Note this is not the same for parameters passed to a stored procedure. In that case the queries inside the stored procedure will compile using the values passed the first time the procedure was executed – that can be really useful, but it can also cause its own set of issues to be aware of! Just remember parameters and variables – similar but not the same!

Setting up Change Data Capture (CDC)

As mentioned in my post Auditing Data Access in SQL Server for GDPR Compliance CDC can be a useful tool for capturing a change history for specific data – which is something we might be thinking about a bit more now the GDPR is heading our way.

It’s pretty straightforward to set up, and can be done easily against existing tables/data – which is handy.

As mentioned in the previous post though, you do need to be on Enterprise Edition or SQL 2016 SP1 or later to use it.

Let’s take a quick look at how you go about setting it up.

First let’s create a table that has some data we want to track:

IF OBJECT_ID('dbo.CDC') IS NOT NULL DROP TABLE dbo.CDC;
CREATE TABLE dbo.CDC 
(
    Id INT IDENTITY(1,1) CONSTRAINT PK_CDC PRIMARY KEY CLUSTERED, 
    SomeText VARCHAR(1000), 
    ModifiedBy VARCHAR(128), 
    ModifiedDate DATETIME
);

Next you have to enable CDC for the database:

EXEC sys.sp_cdc_enable_db;

Then you have to tell SQL to track changes for the specified table:

EXEC sys.sp_cdc_enable_table 
   @source_schema = N'dbo', 
   @source_name = N'CDC', 
   @role_name = NULL;

Note the final parameter @role_name in the above stored procedure. This allows you to specify a database role that will be used to limit access the change history. I’ve just set to this to Null which means that there is no additional role required. There are also other parameters you can specify which you will find defined here:
https://docs.microsoft.com/en-us/sql/relational-databases/system-stored-procedures/sys-sp-cdc-enable-table-transact-sql

Once you’ve followed those few steps CDC is up and running. The change table can be found under system tables in your database, in the CDC schema, and has the name of the original table with “_CT” appended:

CDC_ChangeTable

You can see some additional columns. Rather than capturing the time of the change we have the Start LSN which is the Log Sequence Number associated with the change. This isn’t always that useful to us, which is why is it important for you to capture the time yourself – i.e. the ModifiedDate column.

Also of interest to us is the _$operation column which tell us what operation was logged:
1 = delete
2 = insert
3 = update (old values)
4 = update (new values)

As you can infer from the above, when we do an update we will have a record for both the before and after value.

_$update_mask could be of use to us in some scenarios as it contains a bit mask based on the column ordinals of the table to show us which columns have changed.

Let’s quickly insert and update some data so we can see an example of what we get in the change table:

INSERT INTO dbo.CDC(SomeText, ModifiedBy, ModifiedDate)
SELECT 'SomeText', 'Matt', GETDATE();

UPDATE dbo.CDC 
SET 
SomeText = 'ANewValue', 
ModifiedBy = 'StillMatt', 
ModifiedDate = GETDATE();

SELECT * FROM cdc.dbo_CDC_CT;

Here’s the output from the select:

CDC_ChangeTable_data

You can see we have one row showing the initial insert (_$operation = 2), one row showing the values before the update (_$operation = 3) and one row showing the values after the update (_$operation = 4).

If you run this test yourself you might find it takes a few seconds for the changes to populate as there can be a lag.

So how does it work?

CDC works by parsing your transaction log. It looks for changes relating to the tables is it enabled for and then writes those changes off to the change tracking table. Doing things this way means that it doesn’t have to be a synchronous operation, i.e. it can process the transaction log well after your transaction has committed. So your DML (update/insert/delete) operation is not delayed.

The downside of that is that it does have to go through the whole log (though just the part since it last ran) and work out what has occurred, when we look at performance we’ll see that this seems to create additional work over other synchronous change capture operations. However that work happens in the background and can be limited by the settings you use to configure the CDC jobs, so it may be acceptable or even preferable to a direct increase in the transaction time for your data modifications. Like anything in life it’s a trade-off and you’ll need to decide what works best for you.

Other issues can be around log activity and size. Implementing CDC means that you will get increased read activity on your I/O subsystem where the log is stored for the given database(s). So if implementing CDC it will be good to monitor this to make sure your disks can cope. Also the logfiles themselves are likely to get bigger. This latter point is for two reasons, one is that the CDC capture is itself a logged process, the other is that operations that would normally truncate the log or allow space to be re-used cannot do so until CDC has processed that section of the log. So if latency builds up in the CDC capture operations log entries are likely to be retained for longer.

CDC is actually managed by a couple of SQL Agent jobs. Two for each database that has CDC enabled. It’s useful to understand these for a few reasons. First of all, obviously if SQL Agent is not enabled then CDC is not going to work. Also you don’t want someone wondering what these jobs are and disabling them. Finally you may find you want to perform additional configuration – either for performance or data retention.

The jobs are:

cdc.{DatabaseName}_capture

This does the actual work by calling a series of system stored procedures that do the heavy lifting. The job doesn’t have a schedule, rather it is set running when you enable CDC and then generally continues based on the configuration.

There are 4 parameters that can control the capture:

@continuous – This is a bit value. 0 specifies that the capture will run once and then the job will terminate – this is only really useful in testing scenarios. 1 means that the job will run continuously which is the normal operation.

@maxtrans – This determines how many transactions will be read from the log and written to the change tables. This process is referred to as a scan cycle. Note this is done in a single transaction.

@maxscans – This sets how many scan cycles will be carried out before the job pauses.

@pollinginterval – This is the amount of seconds the job will pause before running through the specified number of scan cycles once more.

When you enable CDC these parameters get set to defaults – @continous = 1, @maxtrans = 500, @maxscans = 10 and @pollinginterval = 5.

You can change any of these setting using the sys.sp_cdc_change_job stored procedure. Changes will be made for the job that relates to the current database context. You need to specify that you want to change the capture job, and new values for the parameters you want to change.

So, if I wanted to change @maxtrans to 1000 and increase the polling interval to 10 seconds I would run the following:

EXECUTE sys.sp_cdc_change_job   
    @job_type = N'capture',  
    @maxscans = 1000,  
    @pollinginterval = 10;

The job must be restarted before the new settings take effect. You can do that using two more system stored procedures:

EXEC sys.sp_cdc_stop_job @job_type = 'capture';
EXEC sys.sp_cdc_start_job @job_type = 'capture';

Here is a Microsoft Whitepaper that goes into detail on tuning CDC using these parameters:
https://technet.microsoft.com/en-us/library/dd266396(v=sql.100).aspx

cdc.{DatabaseName]_cleanup

This is the other job involved in CDC that manages retention of the change data for you. If you are monitoring data that changes a lot then the change table can get large quickly so you need to consider this. This job runs on a schedule – the default is to execute every morning at 2AM. You can change this in the SQL Agent job itself.

There are two additional parameters that control this job:

@retention – the number of minutes that change rows are retained. The default is 4320 which is only 72 hours so if you are using this for audit then you need to up this considerably. The maximum is 100 years.

@threshold – the maximum number of rows that will be deleted in a single statement on cleanup

You configure these using the same stored procedure as before, just specifying the cleanup job. So if I want to change the retention to 1 year I’d call:

EXECUTE sys.sp_cdc_change_job   
    @job_type = N'cleanup',  
    @retention = 525600;

Again you need to stop and start the job before changes take effect.

If you want to check the current parameters for either job then the easiest way is to query the system table msdb.dbo.cdc_jobs:

EXECUTE sys.sp_cdc_change_job   
    @job_type = N'cleanup',  
    @retention = 525600;

 

And that’s about it. There is of course deeper you can go to understand CDC, but this should give you a good grounding to get started in confidence.

Auditing Data Access in SQL Server for GDPR Compliance

In relation to the GDPR, I’ve recently been looking at the tools available within SQL Server to support auditing our databases. Many of you out there will already has full-scale auditing solutions in place. For others though, the prompting of GDPR could be the first time you’re really thinking about it.

This post is a brief overview and comparison of the SQL features that might help you out, with some suggestions of what you might want to think about in terms of auditing.

The GDPR has clear requirements that we must be able to provide detail of changes to personal data. That means being able to say who changed an item of data, when they changed it, and what was the before and after value.

The regulation also states that we must ensure that data is only accessed by appropriate parties, and for the explicit purposes that the person the data relates to has consented. We may feel that this latter requirement is satisfied by our security processes, but in practice, if we wish to prove this then we may also want to audit all data access – including when data is simply read but not changed.

For auditing we need to consider all personal data held, whether that is data provided by an individual or data about an individual that supplements this. Auditing should therefore not be limited to the definition of “personal” within GDPR, namely Personally Identifiable Information (PII). We may also, for our own purposes outside of the GDPR requirement, wish to audit other information related to our business process – for instance where approvals are required.

In terms of individuals accessing or changing data there are several contexts of which we need to be aware:
Application users

  • Support access via specific tooling
  • Support access direct to the database
  • Illegitimate access via an application or tooling
  • Illegitimate access direct to the database

Summary of Tools available within SQL Server

The table below lists the technologies we will look at as well as in what versions/editions of SQL Server they are available. Some versions are omitted where the availability of features is the same as in the previous version:

Audit

Profiler Trace

SQL Server traces allow you to capture information about all access to the database/server. As such this technology is sometimes used as part of an auditing solution – in fact both the C2 Auditing and Common Compliance Criteria features utilise it in one way or another.

It is more useful, however, for capturing instance level security events (such as Logons and failed Logins) than for monitoring changes to individual data items.

There can also be quite an overhead to running traces, though this can be minimised if they are created as server-side traces

Extended Events

Introduced in SQL 2008, Extended Events were intended as a lightweight replacement for Profiler Traces. Still, however, they would be more appropriate for capturing security events than for monitoring data access and change – although SQL Server Audit which we’ll look at later is implemented via Extended Events.

C2 Audit

This feature is supported in all versions and editions of SQL Server up to 2017, though it has been marked as deprecated for some time.
C2 was a rating established by the US Department for Defence applicable to security levels of computer systems, mainly focusing on access to resources. The C2 Audit within SQL server is implemented via server-side traces and captures events such as:

  • Server shutdowns and restarts
  • Successful and failed logins
  • Successful and failed use of permissions when accessing database objects
  • Successful and failed use of permissions when running any command against the database server

It can be seen from the events captured that while this sort of data capture may be useful as part of an overall audit strategy, it won’t cover the audit of individual data required by the GDPR.

If implementing C2 Auditing on an instance, it is important to be aware that it will have some performance impact on a server as each event must be written to the audit file before the operation can complete. In fact, if the audit file cannot be accessed (or disk space runs out) then SQL Server will stop completely until that is resolved. However, it is a limited set of items being audited so the performance impact in general should not be too considerable.

Common Criteria Compliance

Available from SQL 2005 SP1 Enterprise, and in standard edition from SQL 2008, Common Compliance Criteria is described by Microsoft as the replacement for C2 Audit.

Enabling this option configures a couple of other behaviours within SQL server to comply with the “Common Criteria for Information Technology Evaluation” International Standard.

From an auditing point of view, it enables a level of login auditing which can be viewed by querying sys.dm_exec_sessions for currently connected users.

This information includes:

  • Last Successful login time
  • Last unsuccessful login time
  •  Number of Unsuccessful login attempts since last successful login

Triggers

Available in all editions/versions from SQL 2005. Triggers were also available before that, but additional events were added in 2005.

It is a common usage of Triggers to perform some level of database auditing, for instance to capture a modified datetime for a record, or even the identity of the logged-on user. They can also be used to capture more information about changes – for instance to maintain Audit tables as data is inserted, updated or deleted.

The main potential disadvantage of triggers for Auditing is performance. Technologies designed specifically for the purpose may be more lightweight.

Change Tracking (CT)

Available in SQL Server 2008 standard edition onward, CT is not designed to be used for Audit. Rather it is intended to support ETL processes by identifying changes to tables.

When enabled Change Tracking simply identifies that a given row has been inserted, updated or deleted. It doesn’t capture the content of the change, for instance that a given column was changed from value ‘A’ to value ‘B’. It doesn’t maintain a change history, so if I insert a record, update it five times, then delete it, when I check change tracking it will only tell me that it was deleted.

Change Data Capture (CDC)

Available in SQL Server 2008 Enterprise Edition onward, from 2016 SP1 CDC is also available in Standard Edition. Like CT, CDC is not intended as an audit technology – however due to the level of information captured it can be useful in that context.

As well as identifying that data has changed, CDC captures the actual changes and maintains the history in a separate table. Unlike a similar hand-cranked solution using triggers, it manages this asynchronously so has only light performance overhead.

One of the key things missing from CDC from an Audit perspective is that while it captures the data change, it doesn’t also record the Login identity making the change or the datetime for the change.

A Connect item was raised to change this, however the Microsoft response was to reject by design as CDC “is not designed to be an auditing feature”. Microsoft’s recommendation is to use SQL Server Audit instead:

https://connect.microsoft.com/SQLServer/feedback/details/283707/cdc-options-to-capture-more-data-username-date-time-etc
Despite this, if the table itself has columns to capture the user identity and the modified datetime, and the application ensures these are set, then these columns will be included in the change data capture in which case a meaningful Audit of changes to data is provided.

CDC can be enabled on a per table basis, and you can configure which security role(s) have access to the change log. You can also define the retention period which avoids you having to implement a separate solution for cleaning up old audit data.

One thing to bear in mind is that due to the asynchronous process involved to log changes (which uses SQL Server Agent) there is no transactional guarantee that changes will reach the capture log, though the risk of data loss is likely to be minimal.

SQL Server Audit

Available in SQL Server 2008 Enterprise edition, Server level auditing came to Standard edition in 2012 and all features are available in all editions from 2016 SP1.

SQL Server Audit is the out of the box feature that is intended for the purposes of Audit, so logically we may think it is the best one for us to be using. Certainly, it is what Microsoft would recommend for auditing within the database.

Auditing is implemented using Extended Events and there are many Audit events you can enable it to capture. Events are either logged to a file, or to the Windows Security log where it is more difficult to tamper with them. You can then either view the events directly in that destination or through a GUI within SSMS.

Depending on the scope of the events monitored, you can choose to Audit either at an object level (for instance table by table) or at schema or database level.
In the context of GDPR we may choose to Audit data access – insert, select, update and delete. What this sort of Audit will give us is not, as we might expect, the ability to view who accessed or changed specific data. Rather it captures the queries being executed against the objects monitored.

As such it’s probably not the best method for being able to track a change history for a piece of data, though that could be done in theory by analysing the individual queries. Equally, if we want to know who read a specific record, this would require analysis of the queries executed.

Because of that, while SQL Server Audit may form an important part of an overall Audit strategy, it may not, on its own, give us what we need.

It does however allow us to capture all queries that have, for instance, touched certain tables. As such it is the only technology available to use within SQL Server that may allow us to monitor for abuse of privileges. For instance, I may be the DBA and require admin rights over the SQL Server instance, with SQL Server Audit the queries I execute against tables containing personal information would be captured and any dubious querying patterns could be identified.

An important part of the use of SQL Server Audit is going to be proactively monitoring the logs to make sure data access is being carried out appropriately.

Temporal Tables

Temporal tables were introduced in SQL Server 2016 and are a way of easily tracking changes to data – as well as being able to easily query what the value was at a given point in time.

Like CDC they do not capture the user context making the data change, so this must be handled by additional application logic if we require it.

The logging of change data for temporal tables is a synchronous operation performed as part of the transaction that changes data in the main table. Microsoft documentation however states that this creates negligible overhead for inserts, and while there is greater overhead for updates and deletes this is still significantly less than a custom solution (for instance using triggers).

Temporal tables work by having two user tables for each table being tracked. One is the original table – known as the current table, and the other is the history table which includes start and end times for which a given version of the data was current. New commands for querying the state of data at a given point in time make this a seamless operation.

Application Audit

One issue with any auditing that we perform at the database level is that any well designed application, from a security context, is likely to be accessing the database via a service account, rather than application users being granted direct database access. As such it is not possible for pure database auditing to capture a meaningful user context where operations are conducted through the application.

For instance, it may be quite legitimate from the application for a user to update details relating to a customer. We need to maintain a record of those changes so we require the application to log the user context – usually into an “UpdatedBy” column.

There may also be the case where semi-structured, or unstructured data is stored in blob forms, such as XML, JSON or other document formats. In these cases, a database level audit could capture the before and after states of the data, but it would require additional analysis to identify what actual elements of the data within the document had changed. If we want to provide an easily digestible change history then we need to consider implementing this at an application or tooling level.

Finally, we may want to record user access and activities from the application. For instance, the date and time of connections as well as what was accessed.

What might a best practice SQL Data Access Audit solution look like?

Which (if any) of these technologies we use is going to depend very much on the versions and editions of SQL Server we have installed. In an ideal world, to make our lives easy we would all have Enterprise edition – or be on SQL 2016 SP1 or later – and have an extensive choice. In some cases, it may be that the access to additional security and audit components becomes the compelling reason for choosing Enterprise over Standard edition, or for upgrading to a later version of SQL Server.

C2 or Common Compliance

It makes sense to implement one of these, ideally Common Compliance where this is available, as this gives us increased security within SQL Server at little cost and minimal effort to implement. Common Compliance is preferable both as C2 is deprecated and that C2 poorly managed (losing disk access) can create additional risks to application availability. Both offer additional levels of logging connections to our SQL Server boxes that may be useful in identifying those logging onto the server for nefarious purposes.

Change Capture

In particular for GDPR we will want to make sure we have some form of capture and logging of changes to personal data. We have a choice of technologies here.

Triggers

Triggers can provide a serviceable solution but the performance overhead is high so it may be better to use a built-in technology where one is available.

CDC

CDC provides a low overhead tool for managing change capture. However, it is only available in Enterprise Edition until SQL 2016 SP1.

Temporal Tables

These are the latest and greatest, so it may make sense to use where we are using SQL Server 2016, although as it is a synchronous operation it may have more of an immediate performance impact than CDC.

I hope to look at a performance comparison between these different methods of data capture in a later post.

Application Auditing

Whatever tool is used for change capture, application auditing is required to make sure the relevant user context is captured. It’s also worth considering logging user activity.

SQL Server Audit

For a best practice solution, where this is available to us it makes sense to use it. We can use it to capture data access even though the format is not going to be the most easy to analyse . We should also use it to capture events that could relate to anyone making changes to our Change Capture. If anyone makes changes to the Audit itself then this gets captured by the audit so we can detect tampering. We should make sure the Audit is saved to the Security log then that is also tamperproof. We can’t guarantee that we will capture all events, but we can reasonably guarantee that we will detect it if someone prevents us from doing so (e.g. turning off Auditing or Change Capture).

Conclusions

There are a number of components you may want to implement in order to deploy an effective data access auditing solution. In some cases your choices may be limited by the versions and editions of SQL your platforms currently sit on.
In some cases though, where the version and edition of SQL we use supports these technologies, then there is not a great deal of effort required to implement them.

In subsequent posts I’ll hope to show some simple examples in practice, as well as look briefly at the impacts on server performance.

When Deadlocks Become Art

We’ve all had to solve deadlock issues. Identify the two conflicting pieces of code, work out an appropriate change to one of them to avoid the issue. Job done.

Occasionally you see a deadlock that has three nodes. Okay, a little bit more analysis and head scratching before the solution presents itself

What if you have 10 nodes, though, twenty, thirty…

Sometimes the best thing to do might be just to sit back and appreciate the deadlock graph as a piece of art.

Here’s one we found related to an attempted DACPAC (SSDT) deployment in a continuous integration environment:

deadlock1

I found something quite satisfying in that picture. Was tempted to print it out and stick it up by my desk.

Later another colleague was asking for advice on solving deadlocks, I shared him the above as a fun example but also to reassure him “at least the one you’re looking at isn’t that bad”.

About a month later he came back with “I take your deadlock graph and raise you…”:

deadlock2

Now that’s what I call a deadlock!

Can anyone do any better? Either in the realms of the more elegant or the more extreme.

Unfortunately my blogging platform doesn’t allow images in the comments so tweet me if you have one you want to share @MattMcGiffen #whendeadlocksbecomeart

 

Setting the Sample Rate for Auto Stats updates

SQL Server functionality can move on pretty quickly sometimes, and it’s not always all about the big features but the many little enhancements the SQL team implements to make the product better and easier to use.

I’d barely published my post about Automatic Sample Sizes for Statistics Updates when I saw that Microsoft had enhanced the functionality in the latest cumulative update for SQL Server.

From SQL 2016 CU4 you can manually update a statistics object specifying a given sample rate, and you can specify that the sample rate you specified is what will be used for any subsequent automatic updates on the same object.

You can’t change the default sample rate globally, but this functionality is actually more useful. It means that if you find that you have a particular statistics object where the automatic sampling rate is too low, and that has a negative effect on query performance, then you can choose a sampling rate specific for that object.

Let’s take a quick look at doing this in practice.

Here’s some reused SQL from the previous post to create a table and throw in a million rows:

--Create table for Testing
CREATE TABLE dbo.Test(
   Id INT IDENTITY(1,1) CONSTRAINT PK_Test PRIMARY KEY CLUSTERED, 
   TextValue VARCHAR(20) NULL
);

--Create index on TextValue
CREATE INDEX IX_Test_TextValue ON dbo.Test(TextValue);

--Insert a bunch of rows
INSERT INTO dbo.Test(TextValue) 
SELECT TOP 1000000 'blah'
FROM sys.objects a, sys.objects b, sys.objects c, sys.objects d; 

I haven’t updated the stats yet. As we can see if I view them:

--View the statistics
DBCC SHOW_STATISTICS('dbo.Test', IX_Test_TextValue) WITH STAT_HEADER;

SetStatsSampleRate1

The stats haven’t any information yet but there is still one thing to notice. See that final column Persisted Sample Percent? That’s new.

The stats will only get updated by the auto stats mechanism when I run a query against the table and the optimiser is interested in them but sees they’re stale. From zero to a million rows should be stale enough. Let’s run a quick query:

--Random Query
SELECT * 
FROM dbo.Test
WHERE TextValue = 'not blah’;'

And view the stats again:

SetStatsSampleRate2

We can see the stats got updated and the table was big enough that SQL decided to sample rather than scan the whole index. About 42% of the rows got sampled. Persisted Sample Percent is set to zero, i.e. it is not set.

Let’s say that I want to make sure that this statistics object always updates with a full scan.

What I can now do is manually update the statistics and specific that the sample percentage should be persisted:

--Update the stats and persist the sample rate
UPDATE STATISTICS dbo.Test IX_Test_TextValue 
WITH FULLSCAN, PERSIST_SAMPLE_PERCENT = ON;

Let’s check that did what we wanted by viewing the stats:

SetStatsSampleRate3

Great, we can see all the rows were sampled and the Persisted Sample Percent is now set to 100.

Now let’s see what happens when another auto update kicks in. I insert another million rows with the same SQL from above. Then I run the select query again. The optimiser notices the statistics are now stale and so it updates them and recompiles the plan for the query. We can see this when we check the stats yet again:

SetStatsSampleRate4

SQL has done exactly what we wanted, it performed the auto stats update in the background and it used the 100% persisted sample rate.

Thanks Microsoft!

Viewing the Statistics Objects Used to Create an Execution Plan

A while ago now I was running some Performance Tuning workshops and was asked how you can find out which Statistics objects SQL Server has used in the generation of an execution plan (for cardinality estimation). My answer was: “As far as I know – you can’t.”

Some time later I came across the undocumented traceflag 8666 which is used to save internal debugging info into the plan XML – including details of the Statistics objects used. Winner!

There are actually a few other trace flags that do similar things but this seems the simplest and the one that works across the most versions of SQL Server. It looks like it was introduced in SQL 2008 and works on all versions up to and including SQL 2016 – but it doesn’t work on SQL 2005.

Note that this technique only works for plans generated once the trace flag is on, so you can’t view the additional information for existing plans in your cache:

Here’s a quick example using it against the AdventureWorks2012 database. You need to make sure you’ve selected the option to show the actual plan, then run the query as below:

--Turn the trace flag on
DBCC traceon (8666);

--Run the query
SELECT *
FROM Person.Person
WHERE LastName LIKE 'Smith%';

--Turn the trace flag off again
DBCC traceoff (8666);

This query produces the following plan:

optimizer_stats_plan

If you right-click over the SELECT operator and select properties you see the following:

optimizer_stats_plan_props

You’ll notice an extra field “Internal Debugging Information” which contains a bunch of unformatted XML. Rather than grabbing that string and formatting it to make it readable, you can right-click back on the plan itself and select “Show Execution Plan XML…” to view the same information in a more friendly format.

If you scroll down through the XML generated you will get to the following section:

<ModTrackingInfo>

   <Field FieldName=“wszStatName” FieldValue=“_WA_Sys_00000007_693CA210” />

   <Field FieldName=“wszColName” FieldValue=“LastName” />

   <Field FieldName=“m_cCols” FieldValue=“1” />

   <Field FieldName=“m_idIS” FieldValue=“2” />

   <Field FieldName=“m_ullSnapShotModCtr” FieldValue=“19972” />

   <Field FieldName=“m_ullRowCount” FieldValue=“19972” />

   <Field FieldName=“ullThreshold” FieldValue=“4494” />

   <Field FieldName=“wszReason” FieldValue=“heuristic” />

</ModTrackingInfo>

<ModTrackingInfo>

   <Field FieldName=“wszStatName” FieldValue=“IX_Person_LastName_FirstName_MiddleName” />

   <Field FieldName=“wszColName” FieldValue=“LastName” />

   <Field FieldName=“m_cCols” FieldValue=“1” />

   <Field FieldName=“m_idIS” FieldValue=“7” />

   <Field FieldName=“m_ullSnapShotModCtr” FieldValue=“19972” />

   <Field FieldName=“m_ullRowCount” FieldValue=“19972” />

   <Field FieldName=“ullThreshold” FieldValue=“4494” />

   <Field FieldName=“wszReason” FieldValue=“heuristic” />

</ModTrackingInfo>

Each ModTrackingInfo node displays the information about one statistics object that has been referenced. The wszStatName shows us the name of the Statistics object. We have two in this case, _WA_Sys_00000007_693CA210 and IX_Person_LastName_FirstName_MiddleName. The first is an auto-generated one on the LastName column (I happen to know this was generated before I created the index referenced). Interestingly SQL has looked at both – even though they contain pretty much the same info and one isn’t really required.

Why is this useful?

Well, apart from simply the interesting aspect of seeing some of what is going on in the background when SQL decides what plan to use for your query, it is often the case with poor performing queries that there is bad cardinality estimation going on. Sometimes this might be because the statistics aren’t accurate and would benefit from being updated. You can use this technique to see what statistics objects are being used for the estimation (where it is not just obvious) and then you can look at the objects themselves and see whether they might want refreshing.

 

I see growing opinion in the SQL world that the refreshing of statistics is often more important than rebuilding indexes to reduce fragmentation – the latter operation will also refresh the statistics but is a lot more resource intensive. You also will commonly have statistics on columns that are not indexed, and the threshold for them to be refreshed can be pretty large when you have a lot of data. You can see more information about manually refreshing statistics in my previous posts on the subject:

When do Distribution Statistics Get Updated?

Manually updating Statistics

Automatic Sample Sizes for Statistics Updates

SQL Puzzle 3: Knights and Queens

I thought I’d do another chess puzzle this month. This one is a variant on the Eight Queens problem:

SQL Puzzle 2: Eight Queens

 

Given the standard 8×8 chessboard, place an equal number of Knights and Queens such that no piece is attacked by another. What’s the maximum number of Knights and Queen’s you can place? Obviously you should use SQL to find the answer!

 

I’m sure you all know how a knight moves and attacks in chess, but just in case here’s a diagram:

 

 knight_move

 

The white circles show each possible move for the knight, i.e. it can move two squares in one direction and then 1 square perpendicular to that (or vice-versa). An “L” shape.

 

Have fun!

Automatic Sample Sizes for Statistics Updates

I mentioned in my previous post about manually updating statistics that you can specify whether they’re updated using a full scan, or you can specify an amount of data to sample, either a percentage of the table size, or a fixed number of rows. You can also choose not to specify this, and SQL Server will decide for you whether to do a full scan, or to sample a certain amount of data.

I thought it would be interesting to look at what the sample sizes are that SQL will choose to use, depending on the amount of data in your table. Note that this occurs if you update statistics without specifying how they should be sampled as below:

UPDATE STATISTICS dbo.Test _WA_Sys_00000002_3AD6B8E2;

This is also the behaviour you will get when SQL updates statistics through the auto-stats mechanism. The fact that auto-stats may sample at a lower rate than is optimal for a given table and the queries against it is another reason you may choose to perform manual statistics updates.

To test this, I created a table and progressively pumped data in. Then after I inserted each batch of rows:

  • I Ran a stats update capturing the CPU time taken
  • Checked the statistics to see what sample size was used in the update
  • Checked the size of the index

Here’s some of the code I used for the test:

--Drop table if exists
IF (OBJECT_ID('dbo.Test')) IS NOT NULL DROP TABLE dbo.Test;

--Create table for Testing
CREATE TABLE dbo.Test(
   Id INT IDENTITY(1,1) CONSTRAINT PK_Test PRIMARY KEY CLUSTERED, 
   TextValue VARCHAR(20) NULL
);

--Create index on TextValue
CREATE INDEX IX_Test_TextValue ON dbo.Test(TextValue);

--Insert a bunch of rows
INSERT INTO dbo.Test(TEXTValue) 
SELECT TOP 100000 'blah'
FROM sys.objects a, sys.objects b, sys.objects c, sys.objects d;  

--Update statistics without specifying how many rows to sample
SET STATISTICS TIME ON;
UPDATE STATISTICS dbo.Test IX_Test_TextValue;
SET STATISTICS TIME OFF;

--View the statistics
DBCC SHOW_STATISTICS('dbo.Test', IX_Test_TextValue) WITH STAT_HEADER;

--Check the size of the index
SELECT
    i.name                  AS IndexName,
    SUM(s.used_page_count)   AS Pages
FROM sys.dm_db_partition_stats  AS s 
JOIN sys.indexes                AS i
ON s.[object_id] = i.[object_id] AND s.index_id = i.index_id
WHERE i.name = 'IX_Test_TextValue'
GROUP BY i.name

 

The results of my testing are shown in the below table:

StatisticsSamplingRates

You can see that we have a full sample being taken for the statistics updates up to 4000,000 records (896 pages) but that once the table size hits 500,000 sampling is happening. If you look at the number of pages you will see we now have over 1,000 pages, 1000 pages being about 8MB of data, which is the threshold that sampling kicks in.

I wasn’t able to find a nice neat formula to determine the sampling rate based on table size, but if we look at the above figures there are still some insights to be gained. The main one is that you’ll notice that even as we double the table size, the number of rows sampled doesn’t go up by much. For instance from 500,000 to a million rows, only 10,000 more rows are sampled. This also means that even for pretty large tables, the update isn’t taking long – another reason why it’s worth leaving auto stats updates enabled and running synchronously with queries – they’re generally not going to take that long.

Another insight is that the percentage of rows sampled drops off very quickly. As the sample size doesn’t really increase that much even when the table size doubles – the percentage sampled has almost halved each time.

How to be a bad interviewer

tsql2sday150x150

In the monthly SQL blogging party that is T-SQL Tuesday (brainchild of Adam Machanic), Kendra Little has invited us this month to talk about interview patterns/anti-patterns.
https://littlekendra.com/2017/08/01/tsql-tuesday-93-interviewing-patterns-anti-patterns/?utm_campaign=twitter&utm_medium=twitter&utm_source=twitter

Before my current role which I’ve been in for just over 5 years, I spent most of my career as a contractor, performing shorter roles that lasted from 2 weeks to 2 years. As such I was frequently interviewing several times a year and I’ve often sat on the other side if the table as well.

In my experience it’s been far more often to find bad, arrogant or disrespectful interviewers than the other way round. My biggest advice to candidates is to know your worth, realise that the interview process is as much for you to find out whether this is going to be a decent place to work as the other way round.

You’re not obligated to accept a job once it’s offered, and if you’ve had to put up with a lot of rubbish during the application process then seriously consider if it’s just going to get worse once you’re in the role.

As an employer, you want the best people, particularly in IT where people are the company’s biggest asset. You need to make sure that your recruitment process is not just about assessing the candidates, but also showing them that your company is going to be a great place to work.

If you do want to put people off then here’s some of the interviewer “anti-patterns” I’ve experienced over my career that made me ask the question “Would I really want to work at this place?”

Maybe hitting one or two is okay, but beyond that you need to consider your self respect.

Expecting a candidate to fill in a lengthy application form

What’s wrong with a CV? Why is your company so special that I need to sit there for hours with some awful form in Word? You know what? I don’t think I’m that bothered.

Not responding to my application

I sent you my CV and you didn’t even acknowledge it. Or you did and said I’d hear whether I’d been selected by next week, a month and a half passes and then suddenly you decide you want to interview me. You know what, I’ve probably already found something else and even if I haven’t you’re not coming across as massively competent.

Turning up late for the interview

I’ve taken time out of my busy schedule to come see you guys. I arrive at the interview on time – actually I make sure I’m early – but you keep me waiting half an hour. Obviously your time is more important than mine. Okay there may have been a crisis you had to deal with, or is it just chaos all the time? Not sure I’m getting inspired to work here. Oh, and how would you have reacted if I was that late?

Prove how much better than the candidate you are by asking overly specific questions that few people know the answer to

You get your technical boffin in to review my technical skills, but rather than trying to find out what I know they ask me the most specific esoteric technical questions possible – “What sampling algorithm does SQL use when updating statistics?” Clearly their main interest is in trying to prove they know more than me. Is the rest of the team like this? Not sure I want to work with them. You know what, we all know different things and no-one knows everything. How about discussing some technical scenarios and seeing what I come up with.

Asking standard/stupid questions

“What’s my biggest weakness?” No-one is going to tell you they’re a lazy alcoholic. Of course we’re all perfectionist workaholics. All you learn from asking this sort of question is whether someone has learnt the standard answers. It’s just wasting everyone’s time.

Requiring visit after visit for subsequent interviews and tests

You got me in for technical test, then you asked me to come back for an interview. Then come back again for an interview with HR, then yet again to meet a member of the senior management team. Why couldn’t you at least do it all on one day? Apart from the fact that my time is precious too, by the time we get to the end of this long drawn out process I’ve already found a better job.

Expecting candidate to provide free work

Before the interview you’d like me to prove my technical skills by creating some functionality for you. I’ll just need to give up my weekend to do this free work for you. I’m not even got the job yet and you want me to do unpaid overtime. Goodbye!

Not giving a response or feedback when you said you would

We had the interview on Monday and you said I’d hear either way by the end of Wednesday. It’s Friday now and I’ve had no response. Once again you’re not inspiring me to believe this is going to be a great place to work when you don’t honour your basic promises.

This last one is a bit specific, but it did happen to me…

Give someone a C# test when they come for a SQL job, and then when challenged on it insist that they attempt it anyway as you think “it will still have some value.”

I’m ashamed to this day that I didn’t just walk out at that point!