sp_blitzfirst/sp_blitzcache not showing queries with duration that exceeds @minutesBack setting

[rrankins]

Version = '7.95', VersionDate = '20200506'

We have sp_blitzfirst setup via SQL Agent to run every 15 minutes.
While testing query performance for a really slow query that would run for 15-20 minutes, we went and checked the sp_blitzcache table to get the query plan and performance statistics on it and it wasn't in there, but other, less long running and less expensive queries were there.
The problem appears to be that sp_blitzcache uses @minutestback to look at the last Execution time for the queries in the cache, but the Execution time doesn't get saved until the query completes. So if the query starts before sp_blitzcache is run and completes after, it doesn't get captured because it's not available in sys.dm_exec_query_stats yet. When it does complete, the next run of sp_blitzcache doesn't include it because the execution time was more then 15 minutes ago, even though it completed within the last 15 minutes.
Here's an example:
The query stated executing at 5:36 PM
At 5:45 when the sp_Blitzfirst job ran, the query was still running, so it wasn’t captured
The query finished at 5:52 PM
When the sp_Blitzfirst job ran at 6 PM, the query had finished, but the last execution time stored for the query was more than 15 minutes prior (5:36 PM) so sp_blitzcache didn’t capture it.

This seems like a bug to me, or at the least, an unexpected "feature"
I would expect sp_blitzfirst/sp_blitzcache to include queries that completed within the last 15 minutes ( or whatever the @minutesback threshold is).
I'd especially want it to be capturing queries running longer than 15 minutes as those are probably queries that really need to be looked at, but they are not being collected.
I Took a look at the code, and I think it's a matter of calculating the last completion time and using that to compare against the @minutesback value instead of last execution time
sys.dm_exec_query_stats has the last_elapsed_time in addition to last_execution_time.
So instead of the current filter
AND x.last_execution_time >= DATEADD(MINUTE, @min_back, GETDATE())
It could be this:
AND dateadd(ms, (x.last_elapsed_time/1000.), x.last_execution_time) >= DATEADD(MINUTE, @min_back, GETDATE())

Along with this change, add a column LastCompletionTime to the ##BlitzCacheProcs so later in the proc, the filter on ##BlitzCacheProcs can be changed to:
SET @insert_sql += N' AND LastCompletionTime >= DATEADD(MINUTE, @min_back, GETDATE() ) ';
instead of:
SET @insert_sql += N' AND LastExecutionTime >= DATEADD(MINUTE, @min_back, GETDATE() ) ';

I've already worked up a version of sp_blitzcache with this code change and I've tested it out and it appears to work as intended. I've attached a copy of the modified version for review.

This was all tested on SQL Server 2017

-Ray Rankins

sp_blitzcache_fix.txt

[erikdarlingdata]

@rrankins I've done my best to take your changes and apply them to the latest dev branch. There's a pull request for it here. Can you please review and test? I don't have things set up to write off to tables and also repro your issue.

Thanks,
Erik

[rrankins]

Thanks Erik, looks like you did a great job incorporating my proposed changes. I tested this version #2385 and the changes worked fine except when they got to the point to insert into a table. If you already had the table created before this version of sp_blitzcache, it didn't have the LastCompletionTime column and was failing (that's why I didn't add this column to the output in my proposed fix ;-) )
I added a comment to #2385 with what I think the proc needs to check for this new column and add it if it doesn't exist (Similar to #2162 when it had to add JoinKey to the output tables).

Thanks,
Ray

[BrentOzar]

Looks great! Thanks folks. Merged in, and will be in the June release. Getting one out early for June, will be dropping it June 1.