sp_BlitzLock - Fix time searches to make them UTC compatible

[erikdarlingdata]

Is your feature request related to a problem? Please describe.
I recently did a lot of work on sp_QuickieStore to make date/time searches UTC-friendly. This isn't as big a deal if you're leaving the start and end date parameters NULL, because I already adjust those.

For some reason I never adjusted the times for when those parameters aren't NULL. Blame it on Vegas.

The fixes in QuickieStore are a little less friendly to older-version support, since I used AT TIME ZONE, which is 2016+ only. In these, I'm just gonna add time to them as passed in.

Describe the solution you'd like
In the section of code that checks for start and end dates being null, add another line of adjustment code to push them to UTC for more accurate searching.

Describe alternatives you've considered
Doing math.

Are you ready to build the code for the feature?
Yeah it's basically done.

[mike-hodgson]

Actually, it's not quite right when you leave @EndDate NULL.

My server is in Brisbane (Australia), so is UTC+10 (local). If I don't specify an @EndDate parameter then the results exclude the last 10 hours of deadlock XEvents (regardless of whether I pull from system_health or from my own XEvent session). You have to specify @EndDate = current_timestamp (or some other suitable value) to get all the XEvents up to now.

In theory, you should get the same results with these 2 queries (unless I misunderstood your intent in your @EndDate parameter comment (line 59)):

exec sp_BlitzLock;

declare @End datetime = current_timestamp;
exec sp_BlitzLock @EndDate = @End;

But the first one (on my busy prod server that produces tons of deadlocks) returns 300 deadlocks, most recent 2023-07-20T08:50:50 (i.e. 10 hours ago):

And the second one returns 373 deadlocks, most recent 2023-07-20T18:51:12 (i.e. now):

Took me a while to figure out what was going on. Sorry, I only did enough troubleshooting/poking through your code to figure out what was happening and work around it. I didn't unwind all the logic to see all the interactions with @EndDate, especially when I saw " e.x.exist('@timestamp[. < sql:variable("@EndDate")]') = 1 ", as I'm sure I saw some comment from you on a recent commit somewhere that said you had changed that logic to work more efficiently (just don't remember where I saw it now (this one maybe (I had a 3rd child...lots more work than 2)) - I've been trawling through heaps of your code in the last few days).

Also, very minor aside, the ISNULL() for @EndDate on line 268 (and the matching @StartDate one in the code above it) is unnecessary as you'll never get to that line of code unless @EndDate is null. But I know sometimes people add code like that to be consistent or just in case some day false equals true (who knows?), so no drama.

...but I'm very grateful for your work/code (so I don't have to do my own XML shredding - thanks!). I'm never going to complain about free stuff, especially when it's good, like yours & Brent's is. I just wish Microsoft would add an option for a table as a target of an XE session (like in Ye Olde Profiler), so I could capture deadlocks directly to a table in real-time without external XEL files or XML shredding or messing around with the ring buffer.

[erikdarlingdata]

@mike-hodgson

Can you run EXEC sp_BlitzLock @Debug = 1 and tell me if the missing rows are screened out in the initial XML grab, or in the filtering afterwards?

The sort of confusing part to me is that this is the code (less the unnecessary ISNULL) that sets @EndDate:

        @EndDate =
            CASE
                WHEN @EndDate IS NULL
                THEN
                    DATEADD
                    (
                        MINUTE,
                        DATEDIFF
                        (
                            MINUTE,
                            SYSDATETIME(),
                            GETUTCDATE()
                        ),
                        SYSDATETIME()
                    )
                ELSE
                    DATEADD
                    (
                        MINUTE,
                        DATEDIFF
                        (
                            MINUTE,
                            SYSDATETIME(),
                            GETUTCDATE()
                        ),
                        @EndDate
                    )
            END;

The only difference here being that if it's NULL, the date math is applied to the SYSDATETIME function, and if it's not NULL then it's applied to the @EndDate parameter.

• In your first example, @EndDate is NULL, so SYSDATETIME would be used.
• In your second example, you set @EndDate to CURRENT_TIMESTAMP, so @EndDate would be used.

Those should be functionally equivalent, unless for some reason SYSDATETIME and CURRENT_TIMESTAMP return different values for you.

[mike-hodgson]

current_timestamp and sysdatetime() both return the same on my SQL box:

function          output
----------------- ---------------------------
current_timestamp 2023-07-21 10:40:51.6370000
sysdatetime()     2023-07-21 10:40:51.6387510

(2 rows affected)


Completion time: 2023-07-21T10:40:54.5013041+10:00

I ran with @debug=1 while I was troubleshooting yesterday, which was a big help by the way - so I could see all the XEvents were coming back in the raw XML (which agreed with what I saw just reading directly from the event_file both with the GUI and with sys.fn_xe_file_target_read_file()). So the data was getting filtered out later in the code, which prompted me to go poking through all the temp tables to figure out why (which is how I stumbled upon the @EndDate theory).

However, the code you showed above is not what I see in the proc. When I was drafting my comment on this thread above, I was checking through the code in the github repo, both in the FRK repo sp_BlitzLock and in your fork of sp_BlitzLock. After you copy/pasted that above code snippet, I double checked the code on my Brisbane server (which is FRK 8.15 - I just updated it about a week ago). The code in both those github repos and also the FRK 8.15 on my SQL box is:

You can see the "ELSE @EndDate" is outside the UTC date manipulation logic.

I see the same behaviour on 2 other SQL boxes I was testing on as well (SQL 2014 and SQL 2019). I ran a super simple deadlock test to debug how "real-time" things were:

and it was pretty clear that adding/omitting the @EndDate parameter either returned or filtered out that new deadlock (unless I waited for 10+ hours before running sp_BlitzLock).

[erikdarlingdata]

@mike-hodgson I need you to stick with me on this one, because I don't know how often you use GitHub, or to what extent.

The codebase you're showing me has the problem you're describing. I know that, and that's why I wrote the code to fix it. But that code isn't going to be in my direct fork, or in any of the FRK repositories.

Right now, it's only in my pull request. You can view the entire file in raw form here.

If you start using the code from my pull request and still have the same issue, please let me know. On top of the additional date math on the start and end date parameters, you should also see new local variables that hold the passed-in values for start and end date before they're adjusted to UTC, and you should see the start and end date parameters reverted back to their original values from UTC so that they don't interfere with filtering done later in the procedure, after event times are converted from UTC to local time.

Thanks,
Erik

[mike-hodgson]

Right, got it. I'll check out your PR and grab that code for the proc. I have been using git for a few years, but primarily on Azure DevOps and local repos, so I'm not a github guru (and I pretty much only use it to keep abreast of changes to dbatools, dbachecks, FRK, etc.).

Sorry for my confusion & going back over ground you've obviously already covered. It's midnight, Friday night where I am at the moment. I need to grab some z's (got patching & some VM disk expansions to do Sat night). I'll check it out on Mon (AEST) when I trudge back into the salt mine.

It's not a big deal (just took a few brain cells on my end to figure out what was going on), but hopefully your new commit will straighten it out and I can get rid of my own UTC time tweaks that I did before passing in @StartDate to sp_BlitzLock. :) I'll let you know how I go in a few days.

Thanks for taking the time to talk to me about it.

Cheers,
Mike

[erikdarlingdata]

You got it! Catch some 💤 and have a great weekend.

[mike-hodgson]

Sorry about the delay. The salt mine got busy.

That looks better now, with regard to the @StartDate / @EndDate parameters. However, it only works (as it is in the PR) on SQL 2016 SP2 or later because min_spills and max_spills were only added to sys.dm_exec_query_stats in SQL 2016 SP2:
https://learn.microsoft.com/en-us/sql/relational-databases/system-dynamic-management-views/sys-dm-exec-query-stats-transact-sql?view=sql-server-ver16#:~:text=14.x)%20CU3-,min_spills,2016%20(13.x)%20SP2%20and%20SQL%20Server%202017%20(14.x)%20CU3,-pdw_node_id

But apart from that (I just commented out the min/max spills stuff at the end) it looks great.

[erikdarlingdata]

@mike-hodgson great! You know, I could have sworn I pulled those spills columns out already. I'll yank'em in this PR.