Plan Cache – Page 6 – Darling Data

How SQL Server’s Query Plan Cache Lies: Triggers

Posted on April 23, 2019May 16, 2022 by Erik Darling

Simpler Times

Let’s say we’ve got a simple update query. When we run it, it finishes instantly, and the query plan has no surprises.

BEGIN TRAN
UPDATE u
SET u.Reputation = 2147483647
FROM dbo.Users AS u
WHERE u.Id = 22656;

ROLLBACK

Then one day DevOps comes along and says that every time Reputation gets updated in the Users table, we have to check a bunch of conditions and then do a bunch of stuff based on the value.

One of those checks is to see if anyone has the ?INT MAX? and then insert a row into Badges.

Because I’m lazy (Agile?), I’m going to stick a waitfor in the trigger to simulate all the other checks and actions.

CREATE OR ALTER TRIGGER dbo.one_time
ON dbo.Users
AFTER UPDATE
AS
BEGIN
    
    IF EXISTS ( SELECT 1/0 
                FROM Inserted 
                WHERE Inserted.Reputation = 2147483647 )

    INSERT dbo.Badges ( Name, UserId, Date )
    SELECT N'INT MAX OMG', Id, GETDATE()
    FROM Inserted

    WAITFOR DELAY '00:00:10.000'

END;
GO

Less Simpler Times

Now when we run our update, the plan looks like this.

What’s important here is that we can see the work associated with the triggers.

What sucks is when we look at the plan cache.

Back To Easy

I’m gonna stick that update in a stored procedure to make life a little easier when we go looking for it.

CREATE PROCEDURE dbo.update_reputation 
AS
BEGIN
    BEGIN TRAN
    UPDATE u
    SET u.Reputation = 2147483647
    FROM dbo.Users AS u
    WHERE u.Id = 22656;
    
    ROLLBACK    
END;

After running the proc, here’s what we get back from the plan cache.

    SELECT OBJECT_NAME(deps.object_id) AS proc_name, 
           deps.last_elapsed_time / 1000. / 1000. AS last_elapsed_time_seconds,
           deqp.query_plan,
           dest.text
    FROM sys.dm_exec_procedure_stats AS deps
    CROSS APPLY sys.dm_exec_query_plan(deps.plan_handle) AS deqp
    CROSS APPLY sys.dm_exec_sql_text(deps.plan_handle) AS dest
    WHERE deps.object_id = OBJECT_ID('dbo.update_reputation');

We have a procedure reporting that it ran for 10 seconds (which it did, sort of…).

But no mention of the trigger. Hm.

Of course, we can get this information from trigger stats, but we’d have to know to go looking:

    SELECT OBJECT_NAME(object_id) AS trigger_name,
           dets.last_elapsed_time / 1000. / 1000. AS last_elapsed_time_seconds,
           deqp.query_plan,
           dest.text
    FROM sys.dm_exec_trigger_stats AS dets
    CROSS APPLY sys.dm_exec_query_plan(dets.plan_handle) AS deqp
    CROSS APPLY sys.dm_exec_sql_text(dets.plan_handle) AS dest
    WHERE OBJECT_ID = OBJECT_ID('dbo.one_time');

Lying Liars

When seemingly simple modification queries take a long time, things may not be as simple as they appear.

Blocking, and triggers might be at play. Unfortunately, there’s not a great way of linking any of that together right now.

Thanks for reading!

Going Further

If this is the kind of SQL Server stuff you love learning about, you’ll love my training. I’m offering a 75% discount to my blog readers if you click from here. I’m also available for consulting if you just don’t have time for that and need to solve performance problems quickly.

Why Selects That Cause Writes Can Mean Performance Trouble In SQL Server

Posted on April 9, 2019May 16, 2022 by Erik Darling

Answer Time

While answering a question on dba.se, I got to thinking about if there would be a good way to detect SELECT queries that cause writes.

In newer versions of SQL Server, sys.dm_exec_query_stats has columns that show you spills.

That’s a pretty good start, but what about other kinds of writes, like the ones outlined in the Q&A I linked to?

So uh, I wrote this script to find them.

Downsides

The downsides here are that it’s looking at the plan cache, so I can’t show you which operator is spilling. You’ll have to figure that out on your own.

The source of the writes may be something else, too. It could be a spool, or a stats update, etc. That’s why I tried to set the spill size (1024.) kind of high, to not detect trivial writes.

You may be able to loosely correlate spills to IO_COMPLETION or SLEEP_TASK waits.

Thanks for reading!

WITH 
XMLNAMESPACES 
    ('http://schemas.microsoft.com/sqlserver/2004/07/showplan' AS x),
writes AS
(
    SELECT TOP (100)
        deqs.statement_start_offset,
        deqs.statement_end_offset,
        deqs.plan_handle,
        deqs.creation_time,
        deqs.last_execution_time,
        deqs.total_logical_writes,
        deqs.last_logical_writes,
        deqs.min_logical_writes,
        deqs.max_logical_writes,
        deqs.query_hash,
        deqs.query_plan_hash
    FROM sys.dm_exec_query_stats AS deqs
    WHERE deqs.min_logical_writes > 1024.
    ORDER BY deqs.min_logical_writes DESC
),
plans AS
(
    SELECT DISTINCT
        w.plan_handle,
        w.statement_start_offset,
        w.statement_end_offset,
        w.creation_time,
        w.last_execution_time,
        w.total_logical_writes,
        w.last_logical_writes,
        w.min_logical_writes,
        w.max_logical_writes
    FROM writes AS w
    CROSS APPLY sys.dm_exec_query_plan(w.plan_handle) AS deqp
    CROSS APPLY deqp.query_plan.nodes('//x:StmtSimple') AS s(c)
    WHERE deqp.dbid > 4
    AND   s.c.value('@StatementType', 'VARCHAR(100)') = 'SELECT'
    AND   NOT EXISTS 
          (   
              SELECT      
                  1/0 --If nothing comes up, quote out the NOT EXISTS. 
              FROM writes AS w2
              CROSS APPLY deqp.query_plan.nodes('//x:StmtSimple') AS s2(c)
              WHERE w2.query_hash = w.query_hash
              AND   w2.query_plan_hash = w.query_plan_hash
              AND   s2.c.value('@StatementType', 'VARCHAR(100)') <> 'SELECT' 
          )
)
SELECT      
    p.creation_time,
    p.last_execution_time,
    p.total_logical_writes,
    p.last_logical_writes,
    p.min_logical_writes,
    p.max_logical_writes,
    text = 
        SUBSTRING
        (
            dest.text, 
        	( p.statement_start_offset / 2 ) + 1,
            (( 
        	    CASE p.statement_end_offset 
        		     WHEN -1 
        			 THEN DATALENGTH(dest.text) 
        	         ELSE p.statement_end_offset 
                END - p.statement_start_offset 
        	  ) / 2 ) + 1
        ),
    deqp.query_plan
FROM plans AS p
CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS dest
CROSS APPLY sys.dm_exec_query_plan(p.plan_handle) AS deqp
ORDER BY p.min_logical_writes DESC
OPTION ( RECOMPILE );

Going Further

Troubleshooting THREADPOOL Waits In SQL Server With A Plan Cache Query

Posted on March 4, 2019May 14, 2022 by Erik Darling

You Come And Go

When THREADPOOL strikes, even the best monitoring tools can have a bunch of blank spots hanging around in them.

If you’re on SQL Server 2016 or better, there are some helpful columns in sys.dm_exec_query_stats.

WITH threads
    AS
     (
         SELECT   TOP (10)
                  deqs.sql_handle,
                  deqs.plan_handle,
                  deqs.total_reserved_threads,
                  deqs.last_reserved_threads,
                  deqs.min_reserved_threads,
                  deqs.max_reserved_threads,
                  deqs.total_used_threads,
                  deqs.last_used_threads,
                  deqs.min_used_threads,
                  deqs.max_used_threads,
                  deqs.execution_count
         FROM     sys.dm_exec_query_stats AS deqs
         WHERE    deqs.min_reserved_threads > 0
         ORDER BY deqs.max_reserved_threads DESC
     )
SELECT      t.execution_count,
            t.total_reserved_threads,
            t.last_reserved_threads,
            t.min_reserved_threads,
            t.max_reserved_threads,
            t.total_used_threads,
            t.last_used_threads,
            t.min_used_threads,
            t.max_used_threads,
            CASE WHEN (t.min_reserved_threads * 2) < t.max_reserved_threads 
                 THEN 'maybe'
                 ELSE 'maybe not'
            END AS [sniffy?],
            d.query_plan
FROM        threads AS t
CROSS APPLY sys.dm_exec_query_plan(plan_handle) AS d
ORDER BY    t.execution_count DESC, t.max_used_threads DESC;

On My Laptop

Which doesn’t have anything terribly interesting on it at the moment, I get this back.

I have my results weighted towards what’s executed the most, then by how many threads they wanted to reserve.

This could give you a good idea about which queries contributed to THREADPOOL problems.

Keep in mind that, regardless of how many threads the queries end up using, they’ll reserve as many as they want (unless DOP is downgraded due to CPU pressure).

If they get blocked, they hold onto those threads.

If those threads aren’t available when they start running, they’ll either wait for them to show up, or run at a lower DOP.

What Should You Do Here?

Take a look at the query plans: Are there any home dunk missing indexes?
Take a look at the query text: Is there some obvious problem, like a non-SARGable predicate that you can fix?
Take a look at your server: Are MAXDOP and CTFP set correctly?
Take a look at the predicates: Is there some bad parameter sniffing going on (check the sniffy column for swings in threads)

Thanks for reading!

Going Further

SQL Server’s Not Very Mighty IF Branch

Posted on February 1, 2019May 14, 2022 by Erik Darling

Falling For Rome

Okay, so like, an IF branch in a stored proc can be helpful to control logic, but not to control performance.

That’s the most important line in the blog post, now lemme show you why.

All Possible Permutations Thereof

Let’s say for our stored procedure, we want to use a different plan for different TOPs, and our tipping point is 10,000.

That’s the tip of our TOP, if you will. And you will, because my name’s on the blog, pal.

CREATE OR ALTER PROCEDURE dbo.top_sniffer (@top INT, @vtid INT)
AS
BEGIN

    IF @top <= 10000
    BEGIN
    SELECT   TOP (@top) 
             v.Id, 
             v.PostId, 
             v.UserId, 
             v.BountyAmount, 
             v.VoteTypeId, 
             v.CreationDate
    FROM     dbo.Votes AS v
    WHERE    v.VoteTypeId = @vtid
    ORDER BY v.CreationDate DESC;
    END
    
    IF @top > 10000
    BEGIN
    SELECT   TOP (@top) 
             v.Id, 
             v.PostId, 
             v.UserId, 
             v.BountyAmount, 
             v.VoteTypeId, 
             v.CreationDate
    FROM     dbo.Votes AS v
    WHERE    v.VoteTypeId = @vtid
    ORDER BY v.CreationDate DESC;
    END

END;

Soup Sandwich

This goes quite poorly. If we just get estimated plans, here’s that they produce.

/*Run me*/
EXEC dbo.top_sniffer @top = 1, @vtid = 2;

/*Run me*/
EXEC dbo.top_sniffer @top = 5000000, @vtid = 2;

Contestant Number One

A SQL Server query plan — Why are there two with the same plan?

Contestant Number Two

The optimizer explores both paths, and the plan cache concurs.

If you were to run it with the higher value first, you’d see the same thing for the parallel plans.

Logic, Not Performance

Making plan choices with IF branches like this plain doesn’t work.

The optimizer compiles a plan for both branches based on the initial compile value.

What you end up with is a stored proc that doesn’t do what it’s supposed to do, and parameter sniffing times two.

For a lot more information and examples, check out this Stack Exchange Q&A.

Thanks for reading!