On-Premise Data Gateway: Capturing SSAS Query Activity By User

When I’m managing an Analysis Services environment, I’m not just interested in the performance of the workload… yeah that’s important, but I’m also interested in the users who are generating that workload… especially the top users… and here’s why:

These top users are your biggest customers. They’ve already bought-in to the product/solution and you should be providing them with good customer service because in most cases it is easier (/cheaper) to keep (or even upsell) an existing customer than it is to find a new one. Take care of these folks and you’ll do well.

Once I know who my top users customers are, I like to reach out to them directly and ask if they have some time to chat or invite them to lunch. Once they accept (most do), I can ask them all sorts of questions that help me provide a better service to them going forward. What are their day-to-day tasks that involve using the cube/model? What do they like/dislike about it? Is anything missing? Often times we learn from each other and both walk away better for it.

This feedback is golden and the process of obtaining it helps fortify the relationship between IT & the business users – a vital component of a successful BI program.

So Who Ran That Query?

In most environments, it is trivial to obtain the name of the user who ran each query… all you have to do was capture the [QueryEnd] event in a profiler/xevent trace and pull the information from the [NTUserName] field. However, in environments involving Power BI and the Enterprise On-Premise Data Gateway, there’s a bit more to it.

The main issue is how authentication is handled in this type of architecture. When working with Power BI reports connected to an on-premise data source via the On-Premise Data Gateway, the account of the user running the report is passed as the “EffectiveUsername”. The implication here is that the value shown in the [NTUserName] field of the xevent/profiler trace is going to be the Data Gateway account – NOT the account of the user who actually generated the activity.

Note: If you’re interested in more details, you can check out the following blog posts by Melissa Coates & Koos van Strien.

In order to find out the actual user generating the queries, here’s what you’ll need…

1. a trace definition that includes the [QueryBegin] event (in addition to the [QueryEnd] event)
2. to ensure the [RequestProperties] field is also included as part of the [QueryBegin] event
3. another cup of coffee cause we’re about to shred some XML

Demo

Taking the output file from the xEvent trace definition below…

<Create xmlns="http://schemas.microsoft.com/analysisservices/2003/engine">
    <ObjectDefinition>
        <Trace>
            <ID>QuerySummary-PBI</ID>
            <Name>QuerySummary-PBI</Name>
            <XEvent xmlns="http://schemas.microsoft.com/analysisservices/2011/engine/300/300">
                <event_session
                        name="QuerySummary-PBI" dispatchLatency="0" maxEventSize="0"
                        maxMemory="4" memoryPartition="none"
                        eventRetentionMode="AllowSingleEventLoss" trackCausality="true"
                        xmlns="http://schemas.microsoft.com/analysisservices/2003/engine">
                    <event package="AS" name="QueryBegin" />
                    <event package="AS" name="QueryEnd" />
                    <target package="package0" name="event_file">
                        <parameter name="filename" value="QuerySummary-PBI.xel" />
                        <parameter name="max_file_size" value="32" />
                    </target>
                </event_session>
            </XEvent>
        </Trace>
    </ObjectDefinition>
</Create>

…we can run the following query… to obtain the username from the [QueryBegin] event and associate it to the corresponding [QueryEnd] event…

WITH  
  XMLNAMESPACES ('urn:schemas-microsoft-com:xml-analysis' as ns_RequestProperties)
    ,XmlEvents AS ( 
        SELECT   CAST (event_data AS XML) AS E
        FROM     sys.fn_xe_file_target_read_file('E:\SSASLog\QuerySummary-PBI*.xel', NULL, NULL, NULL)
    )
    ,TabularEvents  AS ( 
        SELECT  [ActivityID] = E.value('(/event/action[@name="attach_activity_id"]/value)[1]', 'varchar(255)'),
                [ActivityIDxfer] = E.value('(/event/action[@name="attach_activity_id_xfer"]/value)[1]', 'varchar(255)'),
                [ConnectionID] = E.value('(/event/data[@name="ConnectionID"]/value)[1]', 'int'),
                [CPUTime] = E.value('(/event/data[@name="CPUTime"]/value)[1]', 'int'),
                [CurrentTime] = E.value('(/event/data[@name="CurrentTime"]/value)[1]', 'datetime'),
                [DatabaseName] = E.value('(/event/data[@name="DatabaseName"]/value)[1]', 'varchar(255)'),
                [Duration] = E.value('(/event/data[@name="Duration"]/value)[1]', 'int'),
                [EndTime] = E.value('(/event/data[@name="EndTime"]/value)[1]', 'datetimeoffset'),
                [ErrorType] = E.value('(/event/data[@name="ErrorType"]/value)[1]', 'int'),
                [EventClass] = E.value('(/event/data[@name="EventClass"]/value)[1]', 'int'),
                [EventSubclass] = E.value('(/event/data[@name="EventSubclass"]/value)[1]', 'int'),
                [IntegerData] = E.value('(/event/data[@name="IntegerData"]/value)[1]', 'int'),
                [NTCanonicalUserName] = E.value('(/event/data[@name="NTCanonicalUserName"]/value)[1]', 'varchar(255)'),
                [NTDomainName] = E.value('(/event/data[@name="NTDomainName"]/value)[1]', 'varchar(255)'),
                [NTUserName] = E.value('(/event/data[@name="NTUserName"]/value)[1]', 'varchar(255)'),
                [ObjectPath] = E.value('(/event/data[@name="ObjectPath"]/value)[1]', 'varchar(255)'),
                [RequestID] = E.value('(/event/data[@name="RequestID"]/value)[1]', 'varchar(255)'),
                [ServerName] = E.value('(/event/data[@name="ServerName"]/value)[1]', 'varchar(255)'),
                [SessionID] = E.value('(/event/data[@name="SessionID"]/value)[1]', 'varchar(255)'),
                [Severity] = E.value('(/event/data[@name="Severity"]/value)[1]', 'int'),
                [StartTime] = E.value('(/event/data[@name="StartTime"]/value)[1]', 'datetimeoffset'),
                [Success] = E.value('(/event/data[@name="Success"]/value)[1]', 'int'),
                [QueryString] = E.value('(/event/data[@name="TextData"]/value)[1]', 'varchar(max)'),
                [RequestProperties] = CAST(E.value('(/event/data[@name="RequestProperties"]/value)[1]', 'varchar(max)') AS XML)
        FROM    XmlEvents
    )
    ,CTE_query_base AS (
        SELECT   te.RequestID
                ,te.CPUTime
                ,te.DatabaseName
                ,te.Duration
                ,EndTime = CAST (CASE WHEN te.EndTime >= CAST ('20100101' AS DATETIMEOFFSET) THEN te.EndTime ELSE NULL END AS DATETIME)
                ,te.NTCanonicalUserName
                ,te.ServerName
                ,StartTime = CAST (CASE WHEN te.StartTime >= CAST ('20100101' AS DATETIMEOFFSET) THEN te.StartTime ELSE NULL END AS DATETIME)
                ,te.[QueryString]
        FROM    TabularEvents te
        WHERE   te.EventClass = 10 -- QueryEnd
                AND te.EventSubclass IN ( 0, 3 ) -- Only gets MDX and DAX
    )
    
    ,CTE_powerbi_user AS (
        SELECT   te.RequestID
                ,EffectiveUserName = 
                    te.RequestProperties.query('ns_RequestProperties:PropertyList/ns_RequestProperties:EffectiveUserName').value('.','VARCHAR(128)')
        FROM    TabularEvents te
        WHERE   te.EventClass = 9 -- QueryBegin
                AND te.EventSubclass IN ( 0, 3 ) -- Only gets MDX and DAX
    )
SELECT     q.*
        ,usr.EffectiveUserName
FROM    CTE_query_base q
        LEFT OUTER JOIN CTE_powerbi_user usr 
            ON usr.RequestID = q.RequestID
;

Couple of key points…

1. [RequestProperties] trace field is cast to XML so that the xml query method can be used to extract the value from the EffectiveUserName element.
2. [RequestID] is the key to linking events originating from the same Query (or Command if we’re analyzing processing activity)… but (I *think*) it is only available in SQL 2012 and forward. If you’re using a version older than that…you probably should hop off this blog and focus your efforts on making a case to upgrade (there are plenty of reasons to).

 

Additional References:

• Performance Monitoring for SSAS – Extended Events Cheat Sheet
• Analysis Services Extended Events – AutoRestart Option
• PowerShell Scripts for Collecting SSAS-related Perfmon and xEvent Trace Data