Profiler, Extended Events And Analysis Services

Last week one of the attendees on my SSAS cube design and performance tuning course in London told me that he had been prevented from running a Profiler trace on his SSAS Multidimensional instance by a DBA because “he should be using Extended Events”. He wasn’t too pleased, and I can understand why. This, plus the recent discussion about Profiler and Extended Events for the SQL Server relational engine provoked by Erin Stellato’s recent blog post on the subject, made me think it was worth writing a few words on this subject myself.

Microsoft is clear that in the long term, Extended Events (also commonly known as XEvents) are the replacement for Profiler. This page shows Profiler listed as functionality that will not be supported in a future version of SQL Server – although, importantly, it is not deprecated yet. Profiler is still officially supported for SSAS and the SQL Server relational engine in SQL Server 2016. What’s more, in my opinion it will be a long time before anyone doing serious performance tuning work with SSAS will be able to forget about Profiler and use Extended Events exclusively. Let me explain why.

First of all there is the fact that support for Extended Events in SSAS was only introduced with SSAS 2012. If you are using an earlier version you can’t use them. Even if you have some instances of 2012 or 2014 and some on earlier versions the desire to have a consistent set of tools for performance analysis and monitoring means you probably won’t want to use Extended Events yet.

Then there is the fact that in both SSAS 2012 and 2014 there is no user interface for working with Extended Events– instead, to create, start and stop a trace session you have to use XMLA commands. There are plenty of blog posts out there explaining how to do this but it’s still incredibly time-consuming and fiddly to do. Even in SSAS 2016, where there is a user interface for working with Extended Events and viewing their output, it’s pretty awful and nowhere near as good as Profiler (which is far from perfect itself, but at least useable). Perhaps at some point someone in the community will create a user-friendly tool for working with Extended Events, in the same way that the community created DAX Studio to make up for the shocking fact that even in SQL Server 2016 there is no proper support for running DAX queries in SQL Server Management Studio. I would prefer it if Microsoft did the job itself, though, and started taking tooling for BI seriously.

Thirdly, if you want to do anything useful with the .xel files beyond open them up in SQL Server Management Studio, you’re going to need to use some TSQL and functions like sys.fn_xe_file_target_read_file. What happens if you don’t have an instance of the SQL Server relational engine handy though? Most SSAS shops use SQL Server as their data source, but not all – some use Oracle, or Teradata, or other relational databases, and for them installing an instance of SQL Server somewhere just to work with .xel files many not be an option.

Ah, you say, but on the other hand Extended Events have many advantages over Profiler traces: for example, they are much more lightweight! As Adam Saxton says here:

[Extended Events] won’t have the same impact on performance that a traditional Profiler Trace has. For example, it is reported that 20,000 events/sec on a 2ghz CPU with 1GB of RAM takes less than 2% of the CPU.

If I was building a monitoring application (something like, say, SQL Sentry’s excellent Performance Advisor for Analysis Services) then this might be relevant. But 99% of the time I’m not running a Profiler trace on a Production server, I’m working on a dev or test server, and I always try to prevent other people doing stuff on a server while I’m doing tuning work too, so this is irrelevant. It’s a mistake to assume that Analysis Services users use Profiler for the same kinds of thing that SQL Server relational engine users do. For me, I use Profiler to get roughly the same kind of information that a SQL Server developer gets from a query plan: I use it to find out what’s going on in the engine when I run a single query, so the performance overhead is not something I care about.

That said, it certainly seems to be the case that Extended Events will provide more information than I can get from a Profiler trace and allow me to do more things with that data than I can with Profiler. In SSAS 2016 there are several events that are only available via Extended Events and not via Profiler, although I have no idea what they do; I’m sure, with a bit of research, I can find out. Will any of them be useful? I have no idea yet but I suspect a few will be.

Don’t get me wrong, I think Extended Events are a great technology and something all SSAS developers and administrators should learn. There’s still a lot of UI work to do by Microsoft before they are in a position to replace Profiler, but as I said earlier Microsoft hasn’t deprecated Profiler yet so it has given itself a lot of time to do this work. My only problem is with people like the aforementioned DBA who go around telling people they should be using Extended Events with SSAS right now because that’s what they’ve heard is the best practice and that’s what the recommendation is for the SQL Server relational engine. I’ll still need to use Profiler for a few more years yet.

Using XEvents in SSAS 2012

One of the few new features in SSAS 2012 Multidimensional is the ability to use Extended Events (XEvents) for monitoring purposes. I was, naturally, curious about how to use them but quickly found that the documentation in Books Online was completely useless – the code example given just doesn’t work. This started a number of discussions with people like Akshai Mirchandani, Nick Medveditskov, Rob Kerr, Greg Galloway, Francesco De Chirico who all helped me get to the point where I had something working, and I’m very grateful to them. This is a short summary of what I’ve learned so far; hopefully some working XMLA samples will be useful to anyone else who is researching this subject.

First of all, here’s a working XMLA command that creates an XEvent trace:

<Create xmlns=http://schemas.microsoft.com/analysisservices/2003/engine 
xmlns:xsi=http://www.w3.org/2001/XMLSchema-instance
xmlns:ddl2=http://schemas.microsoft.com/analysisservices/2003/engine/2
xmlns:ddl2_2=http://schemas.microsoft.com/analysisservices/2003/engine/2/2
xmlns:ddl100_100=http://schemas.microsoft.com/analysisservices/2008/engine/100/100
xmlns:ddl200_200=http://schemas.microsoft.com/analysisservices/2010/engine/200/200
xmlns:ddl300_300="http://schemas.microsoft.com/analysisservices/2011/engine/300/300"> <ObjectDefinition> <Trace> <ID>XEvent Demo Trace</ID> <Name>XEvent Demo Trace</Name> <ddl300_300:XEvent> <event_session name="xeas" dispatchLatency="1" maxEventSize="4" maxMemory="4"
memoryPartitionMode="none" eventRetentionMode="allowSingleEventLoss"
trackCausality="true"> <event package="AS" name="DiscoverBegin" /> <event package="AS" name="DiscoverEnd" /> <event package="AS" name="QueryBegin" /> <event package="AS" name="QueryEnd" /> <event package="AS" name="CommandBegin" /> <event package="AS" name="CommandEnd" /> <event package="AS" name="LockAcquired"> <action package="Package0" name="callstack"></action> </event> <event package="AS" name="LockReleased"> <action package="Package0" name="callstack"></action> </event> <event package="AS" name="LockWaiting"> <action package="Package0" name="callstack"></action> </event> <target package="Package0" name="event_file"> <parameter name="filename" value="c:\demo.xel" /> </target> </event_session> </ddl300_300:XEvent> </Trace> </ObjectDefinition> </Create>

.csharpcode, .csharpcode pre
{
font-size: small;
color: black;
font-family: consolas, “Courier New”, courier, monospace;
background-color: #ffffff;
/*white-space: pre;*/
}
.csharpcode pre { margin: 0em; }
.csharpcode .rem { color: #008000; }
.csharpcode .kwrd { color: #0000ff; }
.csharpcode .str { color: #006080; }
.csharpcode .op { color: #0000c0; }
.csharpcode .preproc { color: #cc6633; }
.csharpcode .asp { background-color: #ffff00; }
.csharpcode .html { color: #800000; }
.csharpcode .attr { color: #ff0000; }
.csharpcode .alt
{
background-color: #f4f4f4;
width: 100%;
margin: 0em;
}
.csharpcode .lnum { color: #606060; }

 

The important parts are the list of events, which are the same as the events that can be seen in Profiler (for a full list see here), and the target node which specifies the .xel file to output to.

Once this has been executed in SQL Server Management Studio, you can verify that the trace is running by using the following DMV:

select * from

$system.discover_traces

Here’s what the output is on my machine:

image

There are three traces shown running here on my SSAS instance and the last in the list is the XEvent trace I’ve just created.

Having run a few queries to make sure there is something in the .xel file, the trace can be stopped by executing the following XMLA:

<Delete xmlns="http://schemas.microsoft.com/analysisservices/2003/engine">
    <Object>
        <TraceID>XEvent Demo Trace</TraceID>
    </Object>
</Delete>

.csharpcode, .csharpcode pre
{
font-size: small;
color: black;
font-family: consolas, “Courier New”, courier, monospace;
background-color: #ffffff;
/*white-space: pre;*/
}
.csharpcode pre { margin: 0em; }
.csharpcode .rem { color: #008000; }
.csharpcode .kwrd { color: #0000ff; }
.csharpcode .str { color: #006080; }
.csharpcode .op { color: #0000c0; }
.csharpcode .preproc { color: #cc6633; }
.csharpcode .asp { background-color: #ffff00; }
.csharpcode .html { color: #800000; }
.csharpcode .attr { color: #ff0000; }
.csharpcode .alt
{
background-color: #f4f4f4;
width: 100%;
margin: 0em;
}
.csharpcode .lnum { color: #606060; }

 

You can now open the .xel file specified in the original trace definition in SQL Server Management Studio, browse through it, sort, group events and so on:

image

Instead of outputting to a .xel file, it’s also possible to output to a .etl file by changing the target. Here’s an XMLA command that does this:

<Create xmlns=http://schemas.microsoft.com/analysisservices/2003/engine 
xmlns:xsi=http://www.w3.org/2001/XMLSchema-instance
xmlns:ddl2=http://schemas.microsoft.com/analysisservices/2003/engine/2
xmlns:ddl2_2=http://schemas.microsoft.com/analysisservices/2003/engine/2/2
xmlns:ddl100_100=http://schemas.microsoft.com/analysisservices/2008/engine/100/100
xmlns:ddl200_200=http://schemas.microsoft.com/analysisservices/2010/engine/200/200
xmlns:ddl300_300="http://schemas.microsoft.com/analysisservices/2011/engine/300/300"> <ObjectDefinition> <Trace> <ID>XEvent Demo Trace</ID> <Name>XEvent Demo Trace</Name> <ddl300_300:XEvent> <event_session name="xeas" dispatchLatency="1" maxEventSize="4" maxMemory="4"
memoryPartitionMode="none" eventRetentionMode="allowSingleEventLoss"
trackCausality="true"> <event package="AS" name="DiscoverBegin" /> <event package="AS" name="DiscoverEnd" /> <event package="AS" name="QueryBegin" /> <event package="AS" name="QueryEnd" /> <event package="AS" name="CommandBegin" /> <event package="AS" name="CommandEnd" /> <event package="AS" name="LockAcquired"> <action package="Package0" name="callstack"></action> </event> <event package="AS" name="LockReleased"> <action package="Package0" name="callstack"></action> </event> <event package="AS" name="LockWaiting"> <action package="Package0" name="callstack"></action> </event> <target package="Package0" name="etw_classic_sync_target"> <parameter name="default_etw_session_logfile_path" value="c:\demo.etl" /> </target> </event_session> </ddl300_300:XEvent> </Trace> </ObjectDefinition> </Create>

.csharpcode, .csharpcode pre
{
font-size: small;
color: black;
font-family: consolas, “Courier New”, courier, monospace;
background-color: #ffffff;
/*white-space: pre;*/
}
.csharpcode pre { margin: 0em; }
.csharpcode .rem { color: #008000; }
.csharpcode .kwrd { color: #0000ff; }
.csharpcode .str { color: #006080; }
.csharpcode .op { color: #0000c0; }
.csharpcode .preproc { color: #cc6633; }
.csharpcode .asp { background-color: #ffff00; }
.csharpcode .html { color: #800000; }
.csharpcode .attr { color: #ff0000; }
.csharpcode .alt
{
background-color: #f4f4f4;
width: 100%;
margin: 0em;
}
.csharpcode .lnum { color: #606060; }

 

This gives you something that can opened in Windows Performance Analyzer:

image