Thursday, December 13, 2012

Tracking SSIS Tasks Execution Duration

All my previous posts are related to the niche requirements. And here I come again to discuss one more such interesting concept.

In SSIS projects, we come across few packages that accomplish a complex business logic. Such packages surely include a chain of control flow tasks. Achieving business logic is not the last step but the first. Once the business logic is achieved in SSIS package, there comes the need to optimize its execution duration which leads us to track the execution time of individual tasks in the package. The tasks which consume more time must be observed and optimized. 

Solution: SSIS Logging to the table is the best way to track the duration. The pros here is we can maintain a history of the executions and compare it with the fresh executions as well. However I recommend to make the history confine to a month or so as per the need. 

When we set the SSIS Package logging to SQL Server tables, a table named "SysSSISLog" is created that holds the execution details like ID, Event, TaskName, StartTime, EndTime...

Below is a step by step process to track the duration.

01. Package Design:

Below is a sample package design that includes multiple tasks few embedded in others.




02. Package Execution:

Below is the shot of package execution.




03. Execution details stored in "SysSSISLog" table:

Query displays the execution details stored in "SysSSISLog" table.


The results include event name, task name, starttime, endtime etc., There can be multiple records depending on number of the events defined for every task.

04. Execution Duration Query:


Observe the last column in the results displaying the duration of every single task. I have set the format in HH:MI:SS.


05. Conclusion:

The objective of this post was to show how to track the duration every single task takes. We very well know that the number of records may impact the execution time. But here we are assuming a static number of records processed through the package. And also here we are not discussing how to optimize the design because it depends upon the package design and the tasks that it include (may be by reducing the components in the tasks or using more of SQL statements rather than relying on SSIS transformations or any other fix).

*We can integrate the "Custom Auditing" concept here but its again a vast area which takes more time to discuss.

I hope its useful just as the previous posts.....Happy SSIS'ing. :)


6 comments:

  1. Nice one Sam,we are already using this..and it is really helpful to check the process timings.

    ReplyDelete
  2. That's excellent, thank you. I needed to see durations of individual table loads happening inside of a Data Flow task (parallel loads created by the SSMS Import Wizard), so I used your basic setup to create the following query. Maybe it will be helpful for one of your readers:

    SELECT DISTINCT A.executionid
    , B.TableName
    , A.endtime
    , A.message
    , B.Start
    , B.StartMessage
    , CONVERT(VARCHAR(10), (A.endtime-B.Start), 108) AS Duration
    FROM dbo.SysSSISLog A
    JOIN
    (SELECT DISTINCT executionid
    , endtime AS Start
    , message AS StartMessage
    , SUBSTRING(message,CHARINDEX('-',message)+2,LEN(message)) AS TableName
    FROM dbo.SysSSISLog
    WHERE message like '%PrimeOutput will be called%') B
    ON B.executionid = A.executionid
    WHERE message like '%final commit%ended%'
    AND message like '%'+TableName+'%'
    ORDER BY endtime

    ReplyDelete
  3. Thanks Eric! Surely helpful to someone.

    ReplyDelete
  4. Hi SAM , Hi want to get an alert when SSIS package execution takes more than 30 min ...Is it possible ?

    ReplyDelete
  5. The above query is wrong -- find the below working one.
    USE msdb

    GO

    SELECT


    Mt.computer,
    Mt.operator,
    Mt.source AS 'Package/Task Name',
    Mt.starttime,
    cp.endtime,
    CONVERT(varchar(10), (cp.endtime - mt.starttime), 108) AS 'Duration- HH:MM:SS',
    DATENAME(dw, mt.starttime) AS Startday,
    DATENAME(dw, cp.endtime) AS Endday


    FROM [dbo].[sysSSISLog] MT WITH (NOLOCK)
    CROSS APPLY (SELECT TOP 1
    id,
    endtime
    FROM [dbo].[sysSSISLog] WITH (NOLOCK)
    WHERE Mt.id < id

    AND executionid = Mt.executionid
    AND sourceid = Mt.sourceid
    AND source = MT.source
    AND Event = 'OnPostExecute'
    ORDER BY id ASC) AS cp
    WHERE Mt.[event] = 'OnPreExecute'

    AND mt.starttime >= '02/15/2017'
    ORDER BY mt.starttime DESC

    ;

    ReplyDelete