Categories
Uncategorized

Ever wondered what’s captured in the SSAS Flight Recorder?

During a recent engagement involving an Analysis Services health assessment, one of the things I noted was that the Flight Recorder was enabled. During the post-assessment review with the client, where we walked through the report and recommendations, I quickly explained what the Flight Recorder was, why it should be disabled (answer: never used, wasted resources, etc), and that disabling it would not produce a noticeable performance gain – the recommendation was mostly out of habit.

This particular client followed up with a question that I hadn’t really considered and certainly couldn’t answer with any sort of precision. So I told the client I’d need to get back to him with a better answer… and voila, a new blog post is born!

Question: What kind of activity is captured by the Flight Recorder?

Short Answer: by default, the following events are captured…

image

 Apologies for the blurry images…my VM clients aren’t playing nicely w/ Windows 10 display scaling (if you have advice, I’m all ears)

The rest of this post deals with how I got this information – and even includes a bit of XML shredding!

The Journey

After a bit of bingle’ing (can’t remember who I stole that term from – if it was you, please claim credit) I was able to find the trace definition file for the Flight Recorder. The file is called flightrecordertracedef.xml and is located in the SSAS-bin directory – which by default is something along the lines of C:\Program Files\Microsoft SQL Server\MSAS12.SSAS_MD\OLAP\bin\

Note: the highlighted part below will be different depending on the version of SQL Server and whether or not Analysis Services was installed as a named instance.

If you open that file up, you’ll see the following:

image

Not too helpful right? Let’s flatten that out a bit…

DECLARE @xmlData XML;
DECLARE @fp_FlightRecorder NVARCHAR(1024);
DECLARE @dynSQL AS NVARCHAR(MAX);

SET @fp_FlightRecorder = N'C:\Program Files\Microsoft SQL Server\MSAS12.SSAS_MD\OLAP\bin\flightrecordertracedef.xml';
SET @dynSQL = 'SET    @dyn_xmlData = (SELECT * FROM OPENROWSET (BULK ''' + @fp_FlightRecorder + ''', SINGLE_CLOB) as xmlData)';

EXEC sp_executesql 
     @stmt = @dynSQL
    ,@params = N'@dyn_xmlData XML OUTPUT'
    ,@dyn_xmlData = @xmlData OUTPUT
;

;WITH 
    XMLNAMESPACES(
        'http://schemas.xmlsoap.org/soap/envelope/' AS env,
        'urn:schemas-microsoft-com:xml-analysis' AS ex,
        'http://schemas.microsoft.com/analysisservices/2003/engine' AS b
    )
    ,CTE_xml_1 AS (
        SELECT     EventID = ref.value('./b:EventID[1]','INT')
                ,ColumnList = ref.query('./b:Columns')
        FROM    @xmlData.nodes('/env:Envelope/env:Body/ex:Execute/ex:Command/b:Batch/b:Create/b:ObjectDefinition/b:Trace/b:Events/b:Event') EventID(ref)
    )
SELECT     xml1.EventID
        ,ColumnID = ref.value('.','INT')
--INTO    #FlightRecorderTraceDef
FROM    CTE_xml_1 xml1
        CROSS APPLY xml1.ColumnList.nodes('/b:Columns/b:ColumnID') ColumnList(ref)
;
image

The EventID values map to extended events (or profiler events for the r/oldschoolcool readers) and the related ColumnIDs correspond to the columns being captured (e.g. duration, cpu_time, textdata, etc).

Fortunately, I already have a table with mappings between EventClassID and EventClassNames in my ssas-tuning database (and you should too if you’re doing a lot of analysis services performance work – start here).

image

The next problem I ran into was that I didn’t have a mapping for the column ID and column names. More bingle’ing and I found a table from Technet and used Power Query to grab it and generate the insert statement…

IF OBJECT_ID('tempdb..#xEventColumns','U') IS NOT NULL
    DROP TABLE #xEventColumns;
CREATE TABLE #xEventColumns (
    ColumnID INT NOT NULL PRIMARY KEY,
    ColumnName VARCHAR(128) NOT NULL,
    ColumnDesc VARCHAR(2048) NULL,
);

INSERT INTO #xEventColumns (ColumnID, ColumnName, ColumnDesc)
    SELECT ColumnID = 10, ColumnName = 'ApplicationName 1', ColumnDesc = 'The name of the client application that created the connection to an instance of SQL Server. This column is populated with the values passed by the application and not the name of the program.' UNION ALL 
    SELECT ColumnID = 52, ColumnName = 'BigintData1', ColumnDesc = 'Value (bigint data type), which depends on the event class specified in the trace.' UNION ALL 
    SELECT ColumnID = 53, ColumnName = 'BigintData2', ColumnDesc = 'Value (bigint data type), which depends on the event class specified in the trace.' UNION ALL 
    SELECT ColumnID = 2, ColumnName = 'Binary Data', ColumnDesc = 'The binary value dependent on the event class that is captured in the trace.' UNION ALL 
    SELECT ColumnID = 9, ColumnName = 'ClientProcessID 1', ColumnDesc = 'The ID assigned by the host computer to the process where the client application is running. This data column is populated if the client process ID is provided by the client.' UNION ALL 
    SELECT ColumnID = 44, ColumnName = 'ColumnPermissions', ColumnDesc = 'Indicates whether a column permission was set. You can parse the statement text to determine which permissions were applied to which columns.' UNION ALL 
    SELECT ColumnID = 18, ColumnName = 'CPU', ColumnDesc = 'The amount of CPU time (in milliseconds) that is used by the event.' UNION ALL 
    SELECT ColumnID = 3, ColumnName = 'Database ID 1', ColumnDesc = 'The ID of the database specified by the USE database_name statement, or the ID of the default database if no USE database_namestatement has been issued for a given instance. SQL Server Profiler displays the name of the database if the Server Name data column is captured in the trace and the server is available. Determine the value for a database by using the DB_ID function.' UNION ALL 
    SELECT ColumnID = 35, ColumnName = 'DatabaseName', ColumnDesc = 'The name of the database in which the user statement is running.' UNION ALL 
    SELECT ColumnID = 40, ColumnName = 'DBUserName 1', ColumnDesc = 'The SQL Server user name of the client.' UNION ALL 
    SELECT ColumnID = 13, ColumnName = 'Duration', ColumnDesc = 'The duration (in microseconds) of the event.Note In SQL Server 2005 or later,  the server reports the duration of an event in microseconds (one millionth, or 10-6, of a second) and the amount of CPU time used by the event in milliseconds (one thousandth, or 10-3, of a second). In SQL Server 2000, the server reported both duration and CPU time in milliseconds. In SQL Server 2005 or later, the SQL Server Profiler graphical user interface displays the Duration column in milliseconds by default, but when a trace is saved to either a file or a database table, the Duration column value is written in microseconds.' UNION ALL 
    SELECT ColumnID = 15, ColumnName = 'EndTime', ColumnDesc = 'The time at which the event ended. This column is not populated for event classes that refer to an event that is starting, such as SQL:BatchStarting or SP:Starting.' UNION ALL 
    SELECT ColumnID = 31, ColumnName = 'Error', ColumnDesc = 'The error number of a given event. Often this is the error number stored in sysmessages.' UNION ALL 
    SELECT ColumnID = 27, ColumnName = 'EventClass 1', ColumnDesc = 'The type of event class that is captured.' UNION ALL 
    SELECT ColumnID = 51, ColumnName = 'EventSequence', ColumnDesc = 'Sequence number for this event.' UNION ALL 
    SELECT ColumnID = 21, ColumnName = 'EventSubClass 1', ColumnDesc = 'The type of event subclass, which provides further information about each event class. For example, event subclass values for the Execution Warning event class represent the type of execution warning:1 = Query wait. The query must wait for resources before it can execute; for example, memory.2 = Query time-out. The query timed out while waiting for required resources to execute. This data column is not populated for all event classes.' UNION ALL 
    SELECT ColumnID = 54, ColumnName = 'GUID', ColumnDesc = 'GUID value which depends on the event class specified in the trace.' UNION ALL 
    SELECT ColumnID = 36, ColumnName = 'FileName', ColumnDesc = 'The logical name of the file that is modified.' UNION ALL 
    SELECT ColumnID = 33, ColumnName = 'Handle', ColumnDesc = 'The integer used by ODBC, OLE DB, or DB-Library to coordinate server execution.' UNION ALL 
    SELECT ColumnID = 8, ColumnName = 'HostName 1', ColumnDesc = 'The name of the computer on which the client is running. This data column is populated if the host name is provided by the client. To determine the host name, use the HOST_NAME function.' UNION ALL 
    SELECT ColumnID = 24, ColumnName = 'IndexID', ColumnDesc = 'The ID for the index on the object affected by the event. To determine the index ID for an object, use the indid column of the sysindexes system table.' UNION ALL 
    SELECT ColumnID = 25, ColumnName = 'IntegerData', ColumnDesc = 'The integer value dependent on the event class captured in the trace.' UNION ALL 
    SELECT ColumnID = 55, ColumnName = 'IntegerData2', ColumnDesc = 'The integer value dependent on the event class captured in the trace.' UNION ALL 
    SELECT ColumnID = 60, ColumnName = 'IsSystem', ColumnDesc = 'Indicates whether the event occurred on a system process or a user process:1 = system0 = user' UNION ALL 
    SELECT ColumnID = 5, ColumnName = 'LineNumber', ColumnDesc = 'Contains the number of the line that contains the error. For events that involve Transact-SQL statements, like SP:StmtStarting, the LineNumber contains the line number of the statement in the stored procedure or batch.' UNION ALL 
    SELECT ColumnID = 45, ColumnName = 'LinkedServerName', ColumnDesc = 'Name of the linked server.' UNION ALL 
    SELECT ColumnID = 11, ColumnName = 'LoginName', ColumnDesc = 'The name of the login of the user (either SQL Server security login or the Windows login credentials in the form of DOMAIN\Username).' UNION ALL 
    SELECT ColumnID = 41, ColumnName = 'LoginSid 1', ColumnDesc = 'The security identifier (SID) of the logged-in user. You can find this information in the sys.server_principals view of the master database. Each login to the server has a unique ID.' UNION ALL 
    SELECT ColumnID = 47, ColumnName = 'MethodName', ColumnDesc = 'Name of the OLEDB method.' UNION ALL 
    SELECT ColumnID = 32, ColumnName = 'Mode', ColumnDesc = 'The integer used by various events to describe a state the event is requesting or has received.' UNION ALL 
    SELECT ColumnID = 29, ColumnName = 'NestLevel', ColumnDesc = 'The integer that represents the data returned by @@NESTLEVEL.' UNION ALL 
    SELECT ColumnID = 7, ColumnName = 'NTDomainName 1', ColumnDesc = 'The Microsoft Windows domain to which the user belongs.' UNION ALL 
    SELECT ColumnID = 6, ColumnName = 'NTUserName 1', ColumnDesc = 'The Windows user name.' UNION ALL 
    SELECT ColumnID = 22, ColumnName = 'ObjectID', ColumnDesc = 'The system-assigned ID of the object.' UNION ALL 
    SELECT ColumnID = 56, ColumnName = 'ObjectID2', ColumnDesc = 'The ID of the related object or entity, if available.' UNION ALL 
    SELECT ColumnID = 34, ColumnName = 'ObjectName', ColumnDesc = 'The name of the object that is referenced.' UNION ALL 
    SELECT ColumnID = 28, ColumnName = 'ObjectType 2', ColumnDesc = 'The value representing the type of the object involved in the event. This value corresponds to the type column in sysobjects.' UNION ALL 
    SELECT ColumnID = 61, ColumnName = 'Offset', ColumnDesc = 'The starting offset of the statement within the stored procedure or batch.' UNION ALL 
    SELECT ColumnID = 58, ColumnName = 'OwnerID', ColumnDesc = 'For lock events only. The type of the object that owns a lock.' UNION ALL 
    SELECT ColumnID = 37, ColumnName = 'OwnerName', ColumnDesc = 'The database user name of the object owner.' UNION ALL 
    SELECT ColumnID = 59, ColumnName = 'ParentName', ColumnDesc = 'The name of the schema in which the object resides.' UNION ALL 
    SELECT ColumnID = 19, ColumnName = 'Permissions', ColumnDesc = 'The integer value that represents the type of permissions checked. Values are:1 = SELECT ALL2 = UPDATE ALL4 = REFERENCES ALL8 = INSERT16 = DELETE32 = EXECUTE (procedures only)4096 = SELECT ANY (at least one column)8192 = UPDATE ANY16384 = REFERENCES ANY' UNION ALL 
    SELECT ColumnID = 46, ColumnName = 'ProviderName', ColumnDesc = 'Name of the OLEDB provider.' UNION ALL 
    SELECT ColumnID = 16, ColumnName = 'Reads', ColumnDesc = 'The number of read operations on the logical disk that are performed by the server on behalf of the event. These read operations include all reads from tables and buffers during the statement''s execution.' UNION ALL 
    SELECT ColumnID = 49, ColumnName = 'RequestID', ColumnDesc = 'ID of the request that contains the statement.' UNION ALL 
    SELECT ColumnID = 38, ColumnName = 'RoleName', ColumnDesc = 'The name of the application role that is being enabled.' UNION ALL 
    SELECT ColumnID = 48, ColumnName = 'RowCounts', ColumnDesc = 'The number of rows in the batch.' UNION ALL 
    SELECT ColumnID = 26, ColumnName = 'ServerName 1', ColumnDesc = 'The name of the instance of SQL Server that is being traced.' UNION ALL 
    SELECT ColumnID = 64, ColumnName = 'SessionLoginName', ColumnDesc = 'The login name of the user who originated the session. For example, if you connect to SQL Server using Login1 and execute a statement as Login2, SessionLoginName displays Login1, while LoginName displays Login2. This data column displays both SQL Server and Windows logins.' UNION ALL 
    SELECT ColumnID = 20, ColumnName = 'Severity', ColumnDesc = 'The severity level of the exception event.' UNION ALL 
    SELECT ColumnID = 62, ColumnName = 'SourceDatabaseID', ColumnDesc = 'The ID of the database in which the source of the object exists.' UNION ALL 
    SELECT ColumnID = 12, ColumnName = 'SPID', ColumnDesc = 'The server process ID (SPID) that is assigned by SQL Server to the process that is associated with the client.' UNION ALL 
    SELECT ColumnID = 63, ColumnName = 'SqlHandle', ColumnDesc = '64-bit hash based on the text of an ad hoc query or the database and object ID of an SQL object. This value can be passed to sys.dm_exec_sql_text() to retrieve the associated SQL text.' UNION ALL 
    SELECT ColumnID = 14, ColumnName = 'StartTime 1', ColumnDesc = 'The time at which the event started, when available.' UNION ALL 
    SELECT ColumnID = 30, ColumnName = 'State', ColumnDesc = 'Error state code.' UNION ALL 
    SELECT ColumnID = 23, ColumnName = 'Success', ColumnDesc = 'Represents whether the event was successful. Values include:1 = Success.0 = FailureFor example, a 1 means a successful permissions check, and a 0 means a failed check.' UNION ALL 
    SELECT ColumnID = 42, ColumnName = 'TargetLoginName', ColumnDesc = 'For actions that target a login, the name of the targeted login; for example, to add a new login.' UNION ALL 
    SELECT ColumnID = 43, ColumnName = 'TargetLoginSid', ColumnDesc = 'For actions that target a login, the SID of the targeted login; for example, to add a new login.' UNION ALL 
    SELECT ColumnID = 39, ColumnName = 'TargetUserName', ColumnDesc = 'For actions that target a database user, the name of that user; for example, to grant permission to a user.' UNION ALL 
    SELECT ColumnID = 1, ColumnName = 'TextData', ColumnDesc = 'The text value dependent on the event class that is captured in the trace. However, if you trace a parameterized query, the variables are not displayed with data values in the TextData column.' UNION ALL 
    SELECT ColumnID = 4, ColumnName = 'Transaction ID', ColumnDesc = 'The system-assigned ID of the transaction.' UNION ALL 
    SELECT ColumnID = 57, ColumnName = 'Type', ColumnDesc = 'The integer value dependent on the event class captured in the trace.' UNION ALL 
    SELECT ColumnID = 17, ColumnName = 'Writes', ColumnDesc = 'The number of physical disk write operations that are performed by the server on behalf of the event.' UNION ALL 
    SELECT ColumnID = 50, ColumnName = 'XactSequence', ColumnDesc = 'A token to describe the current transaction.'
;
GO

Putting all the pieces together, we have our final result…

image

Even though the trace definition can be updated to include additional events (or exclude events of little value) this is not a suitable substitute for a proper performance monitoring trace!

One reply on “Ever wondered what’s captured in the SSAS Flight Recorder?”

Leave a comment