How to log the queries received by a cube?

In a previous post, I explained how to analyze which users connect to your cube, this blog post will focus on logging their queries. The strategy, here under, has a small footprint on your server by using traces. Use it to debug some weird situations or to monitor during a brief instant but if you want to use this strategy for long periods, be careful and monitor the impact on your server’s performances.

average dba and queries

The way to achieve this is the similar to the method for auditing users’ connections. You create a trace with Extended Events, you redirect the flow of events to a flat file and you read this file with the help of the function fn_xe_file_target_read.

Let’s start by creating the trace. The interesting event is Query End (code = QueryEnd). This event comes with its children: notably, the query itself (TextData), the start and end time (UTC format) and the NTUserName. For the last one, I’ve noticed that the information is not necessarily filled. Without confirmation, I’d say that this field is only available when the event AuditLogin is also intercepted by a 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>SQLAdmin_Query</ID>
       <Name>SQLAdmin_Query</Name>
       <AutoRestart>true</AutoRestart>

       <ddl300_300:XEvent>
         <event_session name="xeas"            
            dispatchLatency="1"            
            maxEventSize="4"            
            maxMemory="4"            
            memoryPartitionMode="none"            
            eventRetentionMode="allowSingleEventLoss"            
            trackCausality="true"
         >
         <event package="AS" name="QueryEnd" />
         <target package="Package0" name="event_file">
           <parameter name="filename" value="L:\MSSQL_AS_Log\SQLAdmin_Query.xel" />
           <parameter name="max_file_size" value="1024" />
           <parameter name="max_rollover_files" value="3" />
         </target>
       </event_session>
     </ddl300_300:XEvent>
     </Trace>
   </ObjectDefinition>
 </Create>

If you’re looking for queries executing in more than 60 seconds, you should define the following query:

with cte as
(
select
	event_data.value(
		'(event/data[@name="StartTime"])[1]'
		, 'varchar(255)'
	) as StartTime
	, event_data.value(
		'(event/data[@name="EndTime"])[1]'
		, 'varchar(255)'
	) as EndTime
	, event_data.value(
		'(event/data[@name="TextData"])[1]'
		, 'varchar(4000)'
	) as TextData
	, event_data.value(
		'(event/data[@name="NTUserName"])[1]'
		, 'varchar(255)'
	) as NTUserName
	, event_data
from
(
select
   cast(event_data as xml) as event_data
from
   sys.fn_xe_file_target_read_file(
      'L:\MSOLAP\SQLAdmin_Query_*.xel'
       , null, null, null
   )
where
   object_name='QueryEnd'
) t
)
select
	StartTime
	, EndTime
	, datediff(SECOND, StartTime, EndTime) as Duration
	, TextData
	, NTUserName
	, event_data

from
	cte
where
	datediff(SECOND, StartTime, EndTime)>60
Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s