4

I have a stored procedure that takes about 15 seconds to run the first time, and the subsequent runs take 1 to 2 seconds. If I wait for an hour and run it again then it takes 15 seconds again.

I'm guessing that it's using the cached data in the buffer pool on the subsequent runs, whereas the first time it has to load data from the disk to the buffer pool. I'm trying to tune this stored procedure, but after the first run I'm not able to test my changes since it takes only 1 to 2 seconds.

I know that I can use the DBCC DROPCLEANBUFFERS command to free the cache and run my stored procedure, but I'm not allowed to clear the cache at my work. I tried WITH RECOMPILE as well, but that only creates a new plan, but still uses the cached data. Is there another way of forcing the stored procedure to not use the cached data?

2 Answers 2

8

No. Save the CPU and wait stats from the actual execution plan where you're seeing the 15sec duration. Then work to minimize CPU and Reads. If you see that X reads = 15sec of PAGEIOLATCH waits, then you can get a reasonable estimate of the impact of reducing reads.

The important thing is to discover and remediate the queries that are causing the buffer pool to churn. Your query is probably at least partially to blame, but you need to discover why this query's data is not sticking in the cache. May be other queries, may need more memory, or better compression, or to avoid table scans, etc.

1
  • 7
    It may also be worth looking at queries that ask for large memory grants that evict useful data from the buffer pool. Commented Aug 19, 2022 at 21:11
2

Four comments. First, if you must do this, arrange to have a backup of the database restored onto a test system where you can use DBCC DROPCLEANBUFFERS.

Second, use logical reads instead of physical reads. I don't like to rely upon physical reads and just duration for query optimization in most cases. If you focus on the logical reads and reduce them, then the physical reads will normally follow. In some cases, you really must read a lot of data and reducing the logical reads is not an option. Sometimes a gut check will help. If you are doing 10000 logical page reads on a 1000 page table to get 1 record, something is very wrong. (Seen bad stuff like this.) If you have a report on all the data, then 1000 logical reads on a 1000 page table is great.

Third, measure the performance. You can use the following SET statements on the connection used to test the query. It will give CPU time used and IO use for each table. These SETs only need to be executed once. They remain active until the connection closes or they are set OFF. This is fine for 1 or a few queries, but will be very noisy for some code.

SET STATICS IO ON
SET STATISTICS TIME ON

It will look something like below.

Table 'Workfile'. Scan count 0, logical reads 0, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'Worktable'. Scan count 1, logical reads 22693, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'syssingleobjrefs'. Scan count 1, logical reads 2, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'sysschobjs'. Scan count 1, logical reads 51, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'syspalnames'. Scan count 1, logical reads 2, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'sysobjvalues'. Scan count 1, logical reads 3, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'syscolpars'. Scan count 1, logical reads 9, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.

 SQL Server Execution Times:
   CPU time = 859 ms,  elapsed time = 913 ms.

If all you need is a summary of the total performance, something like the flowing might be good enough. SQL Server 2014 or later is required; otherwise, the elapsed time needs to be replaced with something that works (e.g., datediff). BTW, the request_id is included just in case MARS is enabled. Don't leave the above SET statements enabled for this one unless you want a good example of noise. (The results here and above are for different queries and will not match.)

DECLARE @time int, @cpu int, @logical bigint, @reads bigint, @writes bigint

SELECT @time = -total_elapsed_time, @cpu = -cpu_time, @logical = -logical_reads, @reads = -reads, @writes = -writes
FROM sys.dm_exec_requests WITH (NOLOCK) WHERE session_id = @@SPID AND request_id = CURRENT_REQUEST_ID()
    
    WAITFOR DELAY '00:00:01.234';-- code to measure - wait
    DECLARE @t1 int=0, @t2 float=0; while @t1<1000000 begin set @t2=@t2+.5*power(.5,@t1) set @t1+=1 end;-- code to measure - cpu
    SELECT TOP 1000000 t1.*, t2.name as [x] INTO temp_xxxx FROM [sys].[all_objects] t1 CROSS JOIN [sys].[all_columns] t2; SELECT COUNT(*) FROM temp_xxxx; DROP TABLE temp_xxxx;-- code to measure - logical reads and writes

SELECT @time += total_elapsed_time, @cpu += cpu_time, @logical += logical_reads, @reads += reads, @writes += writes
FROM sys.dm_exec_requests WITH (NOLOCK) WHERE session_id = @@SPID AND request_id = CURRENT_REQUEST_ID()

RAISERROR('time %d ms, cpu %d ms, logical %I64d pages, reads %I64d pages, writes %I64d pages', 10, 1, @time, @cpu, @logical, @reads, @writes) WITH NOWAIT
(1000000 rows affected)
(1 row affected)
time 3228 ms, cpu 1964 ms, logical 71094 pages, reads 56 pages, writes 18303 pages

Fourth, if the code is already optimized there might be other issues. If you have 100GB of active data and only 8 GB of RAM.... (The past 20 years, I remember one case it was HW. The query really sucked too, but a vCPU issue pushed it over the edge. A performance issue is going to be likely an optimization issue with your query. However, that would be a separate topic.)

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.