Tracking execution stats of SQL Server 2014 natively-compiled sprocs

Haven’t had time to blog much lately. Finding out strange and interesting things about SQL Server 2014 to present at some seminars and conferences next year. “Shameless self-promotion” posts for those events will be forthcoming. 😉 A few days ago, an experiment with tracking compiled stored procedures turned up some “interesting” results. Thought I’d write about that.

You normally get information about query execution at a query level with sys.dm_exec_query_stats, and info at a stored procedure level sys.dm_exec_procedure_stats. However, with in-memory, OLTP the point is to make things run as quickly as possible and, as such statistics (such as worker_time and elasped_time) don’t get collected. By default *nothing* appears in these DMVs about compiled sprocs. Not even a count of the number of time it’s been executed.

However, Books Online mentions using sys.sp_xtp_control_query_exec_stats and sys.sp_xtp_control_proc_exec_stats to enable collection. Although sys.sp_xtp_control_proc_exec_stats controls a global setting, sys.sp_xtp_control_query_exec_stats controls collecting query information on a per-proc basis. That is, you can turn in on/off for individual compiled stored procedures.

I needed a test bed to try this out. Since there is a nice, new in-memory-OLTP sample on Codeplex that layers on top of the AdventureWorks2012 database, and being the lazy person I am, I decided to use this one. Shouldn’t have been so lazy, perhaps. I downloaded the sample, downloaded AdventureWorks2012 and found interesting behaviors right off. After attaching the data (mdf) file with ObjectExplorer, I found the the database had no owner (owner is blank). That ruined the sample setup, so I changed the database owner to ‘sa’. Then the sample setup ran. Next, I issued the statement:

select * from sys.sql_modules where uses_native_compilation = 1;

This produced output naming two stored procedures (good) and four triggers (not so good, triggers can’t be natively compiled). One for the Connect site.

Strangely the native procedures were named Sales.usp_InsertSalesOrder_inmem and Sales.usp_UpdateSalesOrderShipInfo_native. While I wondered why they both weren’t suffixed by _inmem or _native, I found additional stored procedures in the demo that ended in “_inmem” and WEREN’T compiled stored procedures, they just referenced in-memory tables. One for me to remember when looking at the results.

Started by clearing the procedure cache (DBCC FREEPROCCACHE, standard disclaimer not to do this on production) and inserting 10000 rows and updating additional rows with collection off (the default). Took 7 seconds. After this experiment there were no rows for those procedures/queries in the two DMVs. Good. Now turn global settings on for both types of collection, free proccache, and run again. Executes in 4 seconds. Something needed some “warmup” because I would have expected “with collection” to take longer. OK let’s look at the DMVs.

For query_stats, there are 5 queries in the two compiled sprocs. I get sql_handle (for the query), start/end offset, creation/last execution time, and the worker_time and elasped_time buckets. Nothing else. I don’t know what possessed me to think there’s be something in read/write counts, but these were zero, because of the way memory-optimized tables are stored. They’re not in stored in pages. Procedure_stats had the same sparse infomation, which I was used to by then.

In case you were wondering what the query plan looked like, there wasn’t one exposed. Plan_handle was zeros for those queries. In SQL Server 2014 CTP2 you still can’t get an actual query plan (with actual counts), but you can get an estimated plan. The estimated plans are really sparse as far as information goes, compared to what you’re used to.

One final surprise was that, I thought I’d run multiple iterations of the test, using DBCC FREEPROCCACHE in between to zero the numbers. Not only does turning off data collection not zero the numbers, but running DBCC FREEPROCCACHE doesn’t get rid of the rows, either. These rows remain in the DMV until I drop and re-create the natively compiled proc. Or restart SQL Server, of course. That’s something I wasn’t expecting, but logic-ing it out a bit, perhaps this information wasn’t retrieved from the plan cache. Sure enough, looking at sys.dm_exec_cached_plans yielded no rows for these plans, because they’re not traditional plans.

That’s enough fun for now, hopefully. More, on related topics, perhaps, coming…sometime.


Other articles

Imagine feeling confident enough to handle whatever your database throws at you.

With training and consulting from SQLskills, you’ll be able to solve big problems, elevate your team’s capacity, and take control of your data career.