What is calling my T-SQL scalar function (millions of times)?

In this post we look at a method using Extended Events (XE) to identify what parent objects are calling a given SQL function and how often.

The background is that I was working with a team where we identified that a certain scalar function was being executed billions of time a day and – although lightweight for a single execution – overall it was consuming significant CPU on the server. We discussed a way of improving things but it required changing the code that called it. The problem was that the function was used in about 700 different places across the database code – both in stored procedures and views – though the views themselves would then be referenced by other stored procedures. Rather than update all the code they’d like to target the objects first that execute the function the most times.

The method I show here will identify the root calling object in each case and calculate the number of executions of the function that are instigated. It comes with a few caveats, I have to capture an event for all calls made on the database – as I don’t know which ones will result in a call to the function – that means there’s likely to be CPU overhead and if you have a large amount of calls occurring there could be a fair amount of disk consumption. In my test the Extended Events (XE) session consumed about 130MB of disk space for a million calls captured. In my case I’m talking billions of calls a day so that will be hundreds of GB. As such I plan to only run it for a small interval, starting with a minute to see what I get and will prefer to run it in a test environment with a representative load.

The method is going to use the module_start extended event and the causality tracking feature that allows you to track how events are related to each other. Let’s go ahead and create the session. First I click on Extended Events Sessions in SSMS then right-click and select “New Session”.

In the first page that comes up I just give the session a name and select to turn Causality Tracking on:

Then I click on events and select the event I want. In this case it is just the module_start event and I’m not applying any filters:

Final I configure my data storage. For this example I’ve just added a ring_buffer (memory) and an event_file allowing up to 10G of storage. When I run this for real I may need to allow quite a bit more storage.

Now we’re done and I can just click OK.

Then I can go the the XE session in SSMS, right-click and select “Start Session”.

In my test database I’m now going to run a few stored procedures that execute my function a number of times. The idea is that I’ll then be able to use the XE data to work out which stored procedure called it the most and that therefore (in a real scenario) I might want to focus on fixing first.

Having run my tests I can then stop the XE session and export the results to a table. I show the method for that in a previous post:

https://matthewmcgiffen.com/2018/08/08/exporting-extended-events-session-data-to-a-table/

I’ve exported the results into a new table called FunctionExecution in the same database. I show the structure of the table you get here:

The columns I’m interested in for this analysis are object_name (the name of the code object), attach_activity_id.guid (this comes from the causality tracking and will be the same for all objects in the same call stack) and attach_activity_id.seq (which shows the order in which objects were called).

In order to make the analysis quicker I also want to add couple of indexes. The object_name column is an nvarchar(max) which won’t support indexing, so first I create a new column with a better datatype and copy the values over:

ALTER TABLE dbo.FunctionExecution ADD ObjectName sysname;
UPDATE dbo.FunctionExecution SET ObjectName = CAST([object_name] AS sysname);

Then I create my indexes:

CREATE INDEX IX_ObjectName ON dbo.FunctionExecution(ObjectName) INCLUDE ([attach_activity_id.guid]);
CREATE INDEX IX_GUID ON dbo.FunctionExecution([attach_activity_id.guid]) INCLUDE (ObjectName,[attach_activity_id.seq]);

Finally I am ready to run a query to get the results. I search for the name of the function I am interested in, use attach_activity_id.guid to find other calls in the same call stack, then use attach_activity_id.seq to find the top parent (with a value of 1):

SELECT parent.ObjectName, COUNT(*) AS NumberOfExecutionsOfFunction
FROM dbo.FunctionExecution func
INNER JOIN dbo.FunctionExecution parent
ON func.[attach_activity_id.guid] = parent. [attach_activity_id.guid]
WHERE func.ObjectName = 'NonInlinable'
AND parent.[attach_activity_id.seq] = 1
GROUP BY parent.ObjectName;

Here are the results against the test procedures I executed while the XE session was running:

For this example we can see that I have stored procedure called ProcedureCallingFunctionALotOfTimes that is responsible for most of the calls to my function – so in theory I’d focus my development efforts there first.

Use this method with caution though, as mentioned at the start there may be a lot of overhead in capturing all these events of your server – be it on your own head if that causes problems!

Got a problem or embarking on a SQL Server project and want some help and advice? I’m available for consulting – please get in touch or check out my services page to find out what I can do for you.

One thought on “What is calling my T-SQL scalar function (millions of times)?

Leave a Reply