Starting SQL: A Little More Fun With Logging Dynamic SQL

Jammin Two

---

In case you missed it, because you probably missed it, a long time ago I wrote a post about logging dynamic SQL to a table to track execution history.

And while I still like that post, I wanted to give it another go with a little more chutzpah. It’s a little bit more complicated too, but hey.

To avoid doing version control in blog posts, I’ve got this script up on GitHub. If there are any issues, please raise them over there. Remember the last sentence about not doing version control in blog posts? Thanks for playing along.

I full admit this is mostly a bad idea, but it was a fun one to go on with.

Half The Battle

---

See, and see very very well. Getting the proc to put stuff in the table was easy, but… I also wanted the query plan.

Why? The plan cache is an unstable wreck on a lot of servers I look at, and a lot of people are still totally unaware of, or totally not on a version of SQL Server that supports Query Store. And besides, I enjoy forms of self-torture.

Of course, getting the query plan was an exercise in limitations. It’s uh. Well, you’ll see.

Here’s what I ended up having to do: I had to get the query plan inside the dynamic SQL.

DECLARE @sql NVARCHAR(MAX) = N'';
SET @sql += N'
SELECT COUNT_BIG(*) AS records
/*dbo.logging_test*/
FROM dbo.Badges AS b
JOIN dbo.Users AS u
    ON b.UserId = u.Id
WHERE u.Reputation > @i;

SELECT @query_plan = detqp.query_plan
FROM sys.dm_exec_requests AS der
CROSS APPLY sys.dm_exec_text_query_plan(der.plan_handle, 0, -1) AS detqp
WHERE der.session_id = @@SPID;
';

See, the dynamic SQL executes in a separate context, but the same SPID. If I try to do this outside of the dynamic SQL, I get the wrong plan. I get the plan for the outer proc, which doesn’t tell me anything. But now I have to pass the query plan out of the dynamic SQL, too.

EXEC sys.sp_executesql @sql, 
                       N'@i INT, @query_plan XML OUTPUT', 
                       @i, 
                       @query_plan = @query_plan OUTPUT;

And what really sucks? It also gives me back the plan for the DMV query to get the plan.

So we gotta modify XML. What a treat.

SET @query_plan.modify('
declare namespace p = "http://schemas.microsoft.com/sqlserver/2004/07/showplan";
delete //p:StmtSimple[2]')

If you have more than one statement in there, you’d have to change the number in the bracket. Of course, if you’re executing more than one query inside the dynamic SQL, you’ve got worse ideas than me.

This Is Not A Great Post

---

So if you really wanna do this, you’ll have to call everything like so:

DECLARE @guid  UNIQUEIDENTIFIER;
DECLARE @query_plan XML;
EXEC dbo.logging @spid = @@SPID, @sql = @sql, @query_plan = NULL, @guid_in = NULL, @guid_out = @guid OUTPUT;

EXEC sys.sp_executesql @sql, 
                       N'@i INT, @query_plan XML OUTPUT', 
                       @i, 
                       @query_plan = @query_plan OUTPUT;

SET @query_plan.modify('
declare namespace p = "http://schemas.microsoft.com/sqlserver/2004/07/showplan";
delete (/p:ShowPlanXML/p:BatchSequence/p:Batch/p:Statements/p:StmtSimple[last()])[1]')

EXEC dbo.logging @spid = @@SPID, @sql = @sql, @query_plan = @query_plan, @guid_in = @guid, @guid_out = NULL;

Sure, I probably could have done something with SCOPE_IDENTITY() here, but why miss an excuse to use a GUID and alienate most right-thinking people?

Thanks to a comment from Charlie for pointing me to towards a more flexible way to delete only the last chunk of plan XML!

End Result

---

Making sure it works:

EXEC dbo.logging_test @i = 0;
GO

SELECT * FROM dbo.logger AS l ORDER BY l.run_date;
GO

I can hear you asking yourself: why is this in a series of posts called “Starting SQL” when it seems like a bunch of advanced techniques?

It’s because I want to show you that not all good ideas have good implementations, and it can be genuinely difficult to get good information without a lot of changes and overhead. A lot of times, it’s just not worth it, and this is a great example of that.

A valuable lesson to anyone getting started with SQL Server: sometimes it’s just not worth it.

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.