Michael J. Swart

January 27, 2016

Sneaky Non-Determinism in Column Defaults

Filed under: SQLServerPedia Syndication — Michael J. Swart @ 8:00 am

Remember that functions – including those found in default constraints – are not executed simultaneously. This can sneak up on you whenever you have multiple function calls in a single statement or multiple default constraints in a single table.

mvp5

I recently found a flaky unit test that involved datetime columns. And as Martin Fowler says “Few things are more non-deterministic than a call to the system clock.”

But the cause can be subtle. Two columns with the same default of SYSDATETIME can have different values in the same row. To demonstrate, consider this example.

USE tempdb
GO
-- Create a table
CREATE TABLE #Account
(
  AccountId BIGINT NOT NULL IDENTITY
    CONSTRAINT PK_Account PRIMARY KEY,
  AccountDeets NVARCHAR(100),
  Created DATETIME2 NOT NULL
    CONSTRAINT DF_Account_Created DEFAULT SYSDATETIME(),
  LastModified DATETIME2 NOT NULL
    CONSTRAINT DF_Account_LastModified DEFAULT SYSDATETIME()
)
GO

Now create a procedure that inserts a single row into the table.

-- Create a procedure
CREATE PROCEDURE #CreateAccount
  @AccountDeets NVARCHAR(100)
AS
 
INSERT #Account (AccountDeets)
VALUES (@AccountDeets);
 
RETURN SELECT SCOPE_IDENTITY();
GO

Insert rows by executing the procedure several times and look for differences between the two datetime columns.

SET NOCOUNT ON;
 
--Create 10000 rows in #Account
declare @i int = 0;
 
while (@i < 10000)
begin
   exec #CreateAccount N'details';
   set @i+=1;
end
 
select Created, LastModified
from #Account 
where Created <> LastModified;

This gives something like:

Created LastModified
2016-01-18 09:18:15.271 2016-01-18 09:18:15.272
2016-01-18 09:18:15.380 2016-01-18 09:18:15.381
2016-01-18 09:18:15.387 2016-01-18 09:18:15.388
2016-01-18 09:18:15.480 2016-01-18 09:18:15.481

If I want to depend on these values being exactly the same, I can’t count on the default values. The procedure should look like this:

ALTER PROCEDURE #CreateAccount
  @AccountDeets NVARCHAR(100)
AS
 
DECLARE @Now DATETIME2 = SYSDATETIME();
 
INSERT #Account (AccountDeets, LastModified, Created)
VALUES (@AccountDeets, @Now, @Now);
 
RETURN SELECT SCOPE_IDENTITY();
GO

January 24, 2016

Two Scripts That Help You Monitor Deadlocks with Extended Events

I want to use extended events to store recent deadlock graphs. And I want to create an asynchronous file target instead of using the existing system_health session. I don’t like the system_health target for a couple reasons. It’s too slow to query and it rolls over too quickly and it disappears after server restarts.

So I searched the web for a solution and when I couldn’t find one, I wrote my own solution, I tested it and I decided to blog about it.

Guess what? Apparently I “reinvented the wheel”. The extended events session I created is equivalent to one that Jeremiah Peschka wrote two years ago in Finding Blocked Processes and Deadlocks using SQL Server Extended Events. The embarrassing thing is that in Jeremiah’s article, he references a tool I wrote. And the first comment was written by yours truly.

So go read Jeremiah’s article, it’s really well written. What follows is my solution. The only difference is that mine only focuses on deadlocks. Jeremiah’s focuses on both deadlocks and blocked processes.

Create The Session

Here’s the session that I use. It

  • has five rollover files so that a couple server restarts don’t lose any recent deadlock graphs
  • uses an asynchronous_file_target which I prefer over the ring buffer,
  • and it cleans itself up over time. I don’t need a maintenance job to remove ancient data
DECLARE @ExtendedEventsTargetPath sysname = 'Change this string to something like "D:\XEvents\Traces"';
 
DECLARE @SQL nvarchar(max) = N'
CREATE EVENT SESSION [capture_deadlocks] ON SERVER 
ADD EVENT sqlserver.xml_deadlock_report( ACTION(sqlserver.database_name) ) 
ADD TARGET package0.asynchronous_file_target(
  SET filename = ''' + @ExtendedEventsTargetPath + N'\capture_deadlocks.xel'',
      max_file_size = 10,
      max_rollover_files = 5)
WITH (
    STARTUP_STATE=ON,
    EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
    MAX_DISPATCH_LATENCY=15 SECONDS,
    TRACK_CAUSALITY=OFF
    )
 
ALTER EVENT SESSION [capture_deadlocks] ON SERVER
    STATE=START';
 
exec sp_executesql @SQL;

Query the Results

Oh great. Now I’ve got to dig through several files. That’s a lot of work.
… but not if you have this query:

declare @filenamePattern sysname;
 
SELECT @filenamePattern = REPLACE( CAST(field.value AS sysname), '.xel', '*xel' )
FROM sys.server_event_sessions AS [session]
JOIN sys.server_event_session_targets AS [target]
  ON [session].event_session_id = [target].event_session_id
JOIN sys.server_event_session_fields AS field 
  ON field.event_session_id = [target].event_session_id
  AND field.object_id = [target].target_id	
WHERE
    field.name = 'filename'
    and [session].name= N'capture_deadlocks'
 
SELECT deadlockData.*
FROM sys.fn_xe_file_target_read_file ( @filenamePattern, null, null, null) 
    as event_file_value
CROSS APPLY ( SELECT CAST(event_file_value.[event_data] as xml) ) 
    as event_file_value_xml ([xml])
CROSS APPLY (
    SELECT 
        event_file_value_xml.[xml].value('(event/@name)[1]', 'varchar(100)') as eventName,
        event_file_value_xml.[xml].value('(event/@timestamp)[1]', 'datetime') as eventDate,
        event_file_value_xml.[xml].query('//event/data/value/deadlock') as deadlock	
  ) as deadlockData
WHERE deadlockData.eventName = 'xml_deadlock_report'
ORDER BY eventDate DESC

January 20, 2016

Cursor Statistics Are Missing in dm_exec_query_stats

Filed under: SQLServerPedia Syndication — Michael J. Swart @ 8:00 am

The dmv dm_exec_query_stats doesn’t track stats for OPEN CURSOR statements. This is a problem because the OPEN statement is the one that “runs” your query and if you rely on these stats to monitor performance, then cursor performance is hidden from you.

Cursors have a bad reputation, probably well-deserved. When I see a cursor, I see someone trying to use SQL as a programming language. It’s not what SQL is good at and there’s often a better way.

mvp5

The pragmatist in me doesn’t care too much. If a cursor is performing well and not causing too much trouble, then fixing will not be a priority. But my monitoring solution doesn’t show me how expensive those cursors are! I realize I have no idea what my cursors are doing or how expensive they are.

Cursor Statements

Developers use a number of SQL Statements when writing cursors: DECLARE, OPEN and FETCH. Performance-wise, the DECLARE CURSOR statement takes no time. The OPEN statement runs the query and puts the results in a temporary table. And the FETCH statement reads the next row from the table.

If a cursor’s query is untuned, it’s the OPEN statement that consumes the most resources.

Example

The OPEN statement is missing from sys.dm_exec_query_stats. I want to demonstrate that. Run the following on a dev box.

-- fresh start:
DBCC FREEPROCCACHE
SET STATISTICS IO ON
SET NOCOUNT ON;
GO
 
-- declare a cursor with an arbitrary query that reads a little bit
DECLARE @ChecksumValue int;
 
print 'declare cursor:'
DECLARE FiveRows CURSOR LOCAL FAST_FORWARD FOR
  SELECT TOP 5 CHECKSUM(*)
  FROM INFORMATION_SCHEMA.COLUMNS
  ORDER BY CHECKSUM(*)
 
-- this statement actually runs the query that was just declared
print 'open cursor:'
OPEN FiveRows
 
-- fetch the five rows one at a time
DECLARE @i INT = 0;
WHILE( @i < 5 )
BEGIN
    print 'fetch cursor:'
    FETCH NEXT FROM FiveRows INTO @ChecksumValue
 
    SET @i += 1;
END
 
CLOSE FiveRows
DEALLOCATE FiveRows;
 
GO
 
-- Now look at dm_exec_query_text to see what's in there
SELECT 
    qs.query_hash as QueryHash,
    qs.total_logical_reads + total_logical_writes as TotalIO,
    qs.execution_count as Executions,
    SUBSTRING(
        st.[text],
        qs.statement_start_offset / 2,
        (qs.statement_end_offset - qs.statement_start_offset) / 2
        ) as SQLText    
FROM sys.dm_exec_query_stats qs
OUTER APPLY sys.dm_exec_sql_text(qs.[sql_handle]) st
ORDER BY qs.total_logical_reads + total_logical_writes DESC
OPTION (RECOMPILE)

The results of that last query show that the OPEN statement is missing from dm_exec_query_stats:

CursorResults

And the messages tab shows that the OPEN statement did in fact read from tables.

declare cursor:
open cursor:
Table 'Worktable'. Scan count 0, logical reads 21, ...
Table 'syscolpars'. Scan count 1, logical reads 15, ...
Table 'sysschobjs'. Scan count 1, logical reads 38, ...
Table 'sysscalartypes'. Scan count 1, logical reads 2, ...
fetch cursor:
Table 'Worktable'. Scan count 0, logical reads 2, ...
fetch cursor:
Table 'Worktable'. Scan count 0, logical reads 2, ...
fetch cursor:
Table 'Worktable'. Scan count 0, logical reads 2, ...
fetch cursor:
Table 'Worktable'. Scan count 0, logical reads 2, ...
fetch cursor:
Table 'Worktable'. Scan count 0, logical reads 2, ...

Workarounds

If your cursors are defined inside a procedure, you can inspect dm_exec_procedure_stats. This is not an option when cursors are run as ad-hoc SQL (outside a procedure). Remember that you’ll only get the performance numbers for the entire execution of the procedure. This view doesn’t tell you which statements inside the procedures are expensive.

There’s good news if your monitoring solution is based on extended events or SQL Trace. You’ll be able to monitor cursors correctly.

If you plan to use Query Store, the new feature in SQL Server 2016, then you’ll be able to see statistics for the OPEN query. Query Store doesn’t store statistics for the DECLARE statement. But that’s acceptable because DECLARE statement don’t use any resources.

Summary

Use the following to keep everything straight.

DECLARE
CURSOR
OPEN
CURSOR
FETCH
CURSOR
dm_exec_query_stats
(queryhash = 0x0)
dm_exec_procedure_stats
(if run as sproc)
(aggregated)
SQL Trace (e.g. Profiler)
SET STATISTICS IO ON
Show Plan *
Query Store (2016) *

* This is acceptable because we don’t care about the performance of DECLARE statements.

January 13, 2016

My Work Autobiography

Filed under: SQLServerPedia Syndication — Michael J. Swart @ 8:00 am

8 years at D2L and counting

8 years at D2L and counting

Some years ago, a friend of mine told me I should check out the company he worked for. There was a position that was focused solely on SQL Server. At the time I didn’t think of myself as a database developer, I was a software developer with a knack for SQL. But I applied and it wasn’t long before I signed on.

It’s been over eight years and I still work for D2L, a vendor best known for its Learning Management System educational software.

I get to show up to a different job every day. The variety is amazing. Officially though I’ve only had positions with four distinct teams.

Job 1: In House Consultant

When I started at D2L my position was Senior Software Developer, but really I just wanted to be know as the database guy. The first couple years were about learning SQL Server and building reputation. A number of things helped with my reputation at D2L.

  • A friend of mine, Richard, left D2L leaving a sort of gap behind. Richard was known by many as the developer to talk to for answers. After he left, people began wondering who to talk to and I saw that was an opportunity for me. I tried to fill those shoes, at least for database issues.
  • Firefighting. Unfortunately, putting out a fire is more visible than preventing one in the first place. But I had enough opportunities to do both.
  • The SQL Server technical community. You guys had my back. If I didn’t know an answer immediately, I could find out. You guys were a tremendous resource. See 3 Problem Solving Resources That Make You Look Like A Genius.

Eventually I felt some sort of obligation to give back to the database community and so I started this blog. The act of blogging can actually help clarify fuzzy ideas.

As D2L grew, so did the separation of duties. DBAs do DBA work and developers develop. But as a vendor, developers retain a lot of the control and responsibilities typically associated with DBAs. For example, at D2L, developers are responsible for indexing a table properly. It’s part of the product. We also have a large say in deployment, performance, scalability and concurrency.

So I had several years of fantastic on-the-job training facing new scalability challenges gradually. And as time went on, I worked on more preventative and proactive efforts.

Job 2: Business Intelligence

Then I chose to work with an analytics team. Everyone was talking about “Big Data” which was the new buzzword and I was excited about the opportunity to learn how to do it right.

BigData

It was a project based in part on Kimball’s approach to data warehousing. I worked with a great team and faced a number of challenges.

My reputation as the database guy still meant that I was getting asked to tackle problems on other teams. But I didn’t see them as interruptions. Eventually those “distractions” just showed me that I missed the world of relational data. So a year later, I changed jobs again.

Job 3: Project Argon*

So I joined a team called Argon. Our job was to overhaul the way we deliver and deploy our software. It was exciting and we enjoyed a lot of successes. One friend Scott MacLellan writes a lot more about what we did on his own blog. For example “Deploys Becoming Boring”

For my part I had fun writing

  • A tool that asserted schema alignment for any given database for some expected version of our product.
  • A tool that could efficiently cascade deletes along defined foreign keys in batches (giving up atomicity for that privilege).

I still found myself working as an internal consultant. Still helping out with production issues and still having a blast doing it.

*Fun fact, Argon is the third project in my career with a noble gas for a codename, the other two being Neon and Xenon

Job 4: Samurai Team

Then at the end of 2015 I changed jobs again. This is where it gets good. All that internal consulting I’ve been doing? That’s my full-time job now.

A couple months ago I joined a brand new team with an initial mandate to “make our product stable”. We’re given the autonomy to determine what that means and how best to carry it out. I’m focused on the database side of that and I’m having a great time.

It’s still mainly technical work, but anything that increases software stability is in scope.

  • If internal training is needed, we can provide that. That’s in scope.
  • If increased Devops is needed (blurring the lines or increasing collaboration between devs and DBAs) we do that too.

What’s fun and what’s effective don’t often overlap, but at the moment they do.

Continued Blog Writing!

And I get to write and draw about it as I have been for over five years! Speaking of which, I got some news January 1st:

mvp5

January 6, 2016

Some Changes for 2016

Filed under: SQLServerPedia Syndication — Michael J. Swart @ 8:00 am

So 2016 is going to be fantastic.

Regular Blog Posts

You’re going to see more content coming out of this site. Most of my posts are technical and they’re based on SQL lessons learned in a very busy OLTP SQL Server environment. I do my best to make each one accessible for everyone without shying away from tricky topics.

If the posts come too frequently, you’re going to be tempted to “mark all as read”. But I think most readers will easily be able to keep up with one post a week.

calendar

In 2016, you can count on a blog post every Wednesday. But how do you want to get them?

Via Twitter
If you found my site via twitter, consider subscribing if you want to keep up with this site.

Via RSS
If you’ve already subscribed to the RSS feed, you’re going to continue to get them as you always have, but the world seems to be moving away from RSS.

Via email (new!)
And if you want to get these posts in your inbox, I’ve set up a mailing list. There’s a link at the top of my web site for that. (The mailing list is new, I set it up with tips from Kendra Little).

Continued Illustrations

Those familiar with this site know that I like to draw. It’s fun to combine that hobby with the blog. And I’m going to continue to include illustrations when I can.

Now Using SVG
One change is that I’m going to start including the photos as svg files instead of png. Basically I’m switching from raster to vector illustrations. The file sizes are slightly larger, but they’re still measured in KB. If you do have trouble looking at an illustration, let me know (include device and browser version).

Have fun zooming! If you do, you get to see lots of detail (while I get to notice the flaws).

Talking About Parameter Sniffing

I wrote a talk on parameter sniffing called “Something Stinks: Avoiding Parameter Sniffing Issues & Writing Consistently Fast SQL”.

I gave the talk to work colleagues and I’m really happy with how it went. One No-SQL colleague even told me afterward “I miss relational data.”

You get to see it if you come to Toronto next Tuesday (January 12, 2016) where I’ll be giving the talk for the user group there. Register here.

Or you get to see it if you come to Cleveland for their SQL Saturday (February 6, 2016). Register for that here.

Cheers! And Happy New Year!

Powered by WordPress