SQL SERVER – Parsing SSIS Catalog Messages – Notes from the Field #030

Posted by Pinal Dave on SQL Authority See other posts from SQL Authority or by Pinal Dave
Published on Thu, 29 May 2014 01:30:41 +0000 Indexed on 2014/05/29 9:34 UTC
Read the original article Hit count: 510

[Note from Pinal]: This is a new episode of Notes from the Field series. SQL Server Integration Service (SSIS) is one of the most key essential part of the entire Business Intelligence (BI) story. It is a platform for data integration and workflow applications. The tool may also be used to automate maintenance of SQL Server databases and updates to multidimensional cube data.

In this episode of the Notes from the Field series I requested SSIS Expert Andy Leonard to discuss one of the most interesting concepts of SSIS Catalog Messages. There are plenty of interesting and useful information captured in the SSIS catalog and we will learn together how to explore the same.


The SSIS Catalog captures a lot of cool information by default. Here’s a query I use to parse messages from the catalog.operation_messages table in the SSISDB database, where the logged messages are stored.

This query is set up to parse a default message transmitted by the Lookup Transformation. It’s one of my favorite messages in the SSIS log because it gives me excellent information when I’m tuning SSIS data flows. The message reads similar to:

Data Flow Task:Information: The Lookup processed 4485 rows in the cache. The processing time was 0.015 seconds. The cache used 1376895 bytes of memory.

The query:

USE SSISDB
GO
DECLARE @MessageSourceType INT = 60
DECLARE @StartOfIDString VARCHAR(100) = 'The Lookup processed '
DECLARE @ProcessingTimeString VARCHAR(100) = 'The processing time was '
DECLARE @CacheUsedString VARCHAR(100) = 'The cache used '
DECLARE @StartOfIDSearchString VARCHAR(100) = '%' + @StartOfIDString + '%'
DECLARE @ProcessingTimeSearchString VARCHAR(100) = '%' + @ProcessingTimeString + '%'
DECLARE @CacheUsedSearchString VARCHAR(100) = '%' + @CacheUsedString + '%'
SELECT operation_id
, SUBSTRING(MESSAGE,
(
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1))
-
(
PATINDEX(@StartOfIDSearchString, MESSAGE) + LEN(@StartOfIDString) + 1))) AS LookupRowsCount
, SUBSTRING(MESSAGE,
(
PATINDEX(@ProcessingTimeSearchString,MESSAGE) + LEN(@ProcessingTimeString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@ProcessingTimeSearchString,MESSAGE) + LEN(@ProcessingTimeString) + 1))
-
(
PATINDEX(@ProcessingTimeSearchString, MESSAGE) + LEN(@ProcessingTimeString) + 1))) AS LookupProcessingTime
, CASE WHEN (CONVERT(numeric(3,3),SUBSTRING(MESSAGE,
(
PATINDEX(@ProcessingTimeSearchString,MESSAGE) + LEN(@ProcessingTimeString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@ProcessingTimeSearchString,MESSAGE) + LEN(@ProcessingTimeString) + 1))
-
(
PATINDEX(@ProcessingTimeSearchString, MESSAGE) + LEN(@ProcessingTimeString) + 1))))) = 0
THEN 0
ELSE CONVERT(bigint,SUBSTRING(MESSAGE,
(
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1))
-
(
PATINDEX(@StartOfIDSearchString, MESSAGE) + LEN(@StartOfIDString) + 1))))
/
CONVERT(numeric(3,3),SUBSTRING(MESSAGE,
(
PATINDEX(@ProcessingTimeSearchString,MESSAGE) + LEN(@ProcessingTimeString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@ProcessingTimeSearchString,MESSAGE) + LEN(@ProcessingTimeString) + 1))
-
(
PATINDEX(@ProcessingTimeSearchString, MESSAGE) + LEN(@ProcessingTimeString) + 1))))
END AS LookupRowsPerSecond
, SUBSTRING(MESSAGE,
(
PATINDEX(@CacheUsedSearchString,MESSAGE) + LEN(@CacheUsedString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@CacheUsedSearchString,MESSAGE) + LEN(@CacheUsedString) + 1))
-
(
PATINDEX(@CacheUsedSearchString, MESSAGE) + LEN(@CacheUsedString) + 1))) AS LookupBytesUsed
,CASE WHEN (CONVERT(bigint,SUBSTRING(MESSAGE,
(
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1))
-
(
PATINDEX(@StartOfIDSearchString, MESSAGE) + LEN(@StartOfIDString) + 1)))))= 0
THEN 0
ELSE CONVERT(bigint,SUBSTRING(MESSAGE,
(
PATINDEX(@CacheUsedSearchString,MESSAGE) + LEN(@CacheUsedString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@CacheUsedSearchString,MESSAGE) + LEN(@CacheUsedString) + 1))
-
(
PATINDEX(@CacheUsedSearchString, MESSAGE) + LEN(@CacheUsedString) + 1))))
/
CONVERT(bigint,SUBSTRING(MESSAGE,
(
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1),
((
CHARINDEX(' ',
MESSAGE,
PATINDEX(@StartOfIDSearchString,MESSAGE) + LEN(@StartOfIDString) + 1))
-
(
PATINDEX(@StartOfIDSearchString, MESSAGE) + LEN(@StartOfIDString) + 1))))
END AS LookupBytesPerRow
FROM [catalog].[operation_messages]
WHERE message_source_type = @MessageSourceType
AND MESSAGE LIKE @StartOfIDSearchString
GO

Note that you have to set some parameter values:

  • @MessageSourceType [int] – represents the message source type value from the following results:
    Value     Description
    10           Entry APIs, such as T-SQL and CLR Stored procedures
    20           External process used to run package (ISServerExec.exe)
    30           Package-level objects
    40           Control Flow tasks
    50           Control Flow containers
    60           Data Flow task
    70           Custom execution message
    Note: Taken from Reza Rad’s (excellent!) helper.MessageSourceType table found here.
  • @StartOfIDString [VarChar(100)] – use this to uniquely identify the message field value you wish to parse.
    In this case, the string ‘The Lookup processed ‘ identifies all the Lookup Transformation messages I desire to parse.
  • @ProcessingTimeString [VarChar(100)] – this parameter is message-specific. I use this parameter to specifically search the message field value for the beginning of the Lookup Processing Time value.
  • For this execution, I use the string ‘The processing time was ‘.
  • @CacheUsedString [VarChar(100)] – this parameter is also message-specific. I use this parameter to specifically search the message field value for the beginning of the Lookup Cache  Used value. It returns the memory used, in bytes.
    For this execution, I use the string ‘The cache used ‘.
  • The other parameters are built from variations of the parameters listed above.

The query parses the values into text. The string values are converted to numeric values for ratio calculations; LookupRowsPerSecond and LookupBytesPerRow. Since ratios involve division, CASE statements check for denominators that equal 0.

Here are the results in an SSMS grid:

This is not the only way to retrieve this information. And much of the code lends itself to conversion to functions. If there is interest, I will share the functions in an upcoming post.

If you want to get started with SSIS with the help of experts, read more over at Fix Your SQL Server.

Reference: Pinal Dave (http://blog.sqlauthority.com)


Filed under: Notes from the Field, PostADay, SQL, SQL Authority, SQL Backup and Restore, SQL Query, SQL Server, SQL Tips and Tricks, T SQL Tagged: SSIS

© SQL Authority or respective owner

Related posts about Notes from the Field

Related posts about PostADay