Why is fn_xe_file_target_read_file the worst SQL function?

I haven’t had a rant post in a while. There is a saying: “Anything before the word ‘but’ is ignored”. I love Extended Events, but … reading the extended event file is so much pain.

It feels like there is a conspiracy between Microsoft and Big Pharma SQL Monitoring because the best analytics tool available in SQL Server (and I mean Extended Events and Query Store of course) have the worst GUI and supporting tools. I’m focusing on XE in this post.

An all-too-common scenario 🔗︎

I want to check the built-in system_health or AlwaysOn_health target event files for recent events. First of all, you cannot even set time-based retention on those files so giving them 500 MB might cover anywhere between 6 months and 30 minutes of data. In the former case, you open the file via GUI and spend the next 5 minutes watching the millions of unrelated events load just so you can perhaps read the events from the last day.

If you think the filter can help you there, you’d be surprised. You cannot use the time filter on the date you need until that date is loaded first. If you try to filter out the unrelated events, it just starts loading from the start and filters in the background. I hope you are patient as well because if you try to scroll to the end while it’s still loading, there is a good chance it will crash your SSMS (bye-bye tabs).

Don’t blink.
Blink and the SSMS is dead.
Don’t turn your back.
Don’t look away.
And don’t blink.
Good Luck.
— 10th Doctor

fn_xe_file_target_read_file to the rescue 🔗︎

Surely, with GUI having these (and other) problems, the DMF is a better way to read the event data, right? Right?

Parsing the XML 🔗︎

XE’s event files are stored as .xel files which is basically an XML. While SQL Server has XML shredding capabilities, chances are the DBAs/Developers are not very good at it unless you’re using a lot of Service Broker or are familiar with Extended Events already.

But that’s ok, there are plenty of examples on the internet which you can plagiarize borrow and edit until it works. Or find the presentation from Michael Rys and learn something new.

At any rate, one would assume that a function for reading the xel files would return an xml data type as its result.
You probably see where I’m going with this.

Function sys.fn_xe_file_target_read_file returns event_data nvarchar(max)!

So if you want to use it with the nodes() xml method, you have to cast to xml data type first. I’ve also commonly seen cases where the cast to xml is evaluated multiple times per query and it’s super slow.

That’s why I always cast it as xml and insert it into a temp table to pay the conversion price only once.
It’s not super effective, but that one is on you, fn_xe_file_target_read_file, not me.

Time filter 🔗︎

This was my main gripe with the GUI but this function returns a timestamp_utc datetime2(7) so you can easily filter on time like this:

SELECT 
  ef.module_guid
  , ef.package_guid
  , ef.object_name
  , ef.event_data
  , ef.file_name
  , ef.file_offset
  , ef.timestamp_utc
FROM sys.fn_xe_file_target_read_file('system_health*.xel',NULL,NULL,null) AS ef
WHERE timestamp_utc > DATEADD(DAY, -1, SYSUTCDATETIME())

I bet you got 0 rows returned. That’s because the function is a filthy liar and doesn’t return datetime2(7) (in an expected way). So we must add the explicit cast to make it work.

…
WHERE CAST(timestamp_utc AS datetime2(7)) > DATEADD(DAY, -1, SYSUTCDATETIME());

Which doesn’t use the predicate pushdown and is instead applied as a residual.

There is an open feedback item Filtering output from fn_xe_file_target_read_file on timestamp_utc returns no rows which is planned to be fixed in an unspecified 2022 future update. I won’t be holding my breath.

More time filtering 🔗︎

Maybe you’re a slightly more experienced XE user, and you’re leveraging the rollover files. There might be a slightly more efficient way to read your data.

If you want the latest data, then it’s probably in the last rollover file. The function’s 3rd and 4th parameters are initial_file_name and initial_offset respectively. So you can efficiently skip the unrelated files and get to the tail of the log.

A superlative suggestion with just two minor flaws:

• One, the only way to get the list of the files is to run the same function without the parameters.
• And two, the only way to get the list of the files is to run the same function without the parameters.

Now, I realize that technically speaking that’s only one flaw, but I thought that it was such a big one that it was worth mentioning twice.

Alright, alright. You can use the undocumented xp_dirtree or enable xp_cmdshell to get the file names but I don’t like using either in my production just for the sake of this.

The file format is also… interesting. Looks like this system_health_0_133733556689540000.xel. I’m not sure what is the first number after the session name but the second one looks like ticks.

Slightly tweaking the code from Michael J. Swart’s blog Converting from DateTime to Ticks using SQL Server (because of course, dateadd cannot use bigint) we’ll get this:

DECLARE  @Ticks bigint = 133733556689540000
DECLARE @DateTime datetime2 = DATEFROMPARTS(1601,1,1);
SET @DateTime = DATEADD( DAY, @Ticks / 864000000000, @DateTime );
SET @DateTime = DATEADD( SECOND, ( @Ticks % 864000000000) / 10000000, @DateTime );
select DATEADD( NANOSECOND, ( @Ticks % 10000000 ) * 100, @DateTime );

This gives me output 2024-10-14 05:01:08.9540000 The start year 1601 was reverse-engineered to get to the current year but it matches the start of Microsoft Epoch.

As I was writing this blog post Martin Smith posted an answer to my almost 2-year-old question. What are the odds? Go and read it.

Conclusion 🔗︎

So is it all bad?

No, I still use it and it’s the best/worst (in other words only) option for programmatically parsing the xel file from within the SQL Server. But it could be so much more…

Thank you for reading