Topic for this month’s T-SQL Tuesday, hosted by Aaron Nelson (@SQLVariant) is Logging.

I like to think of logging as a Flight Data Recorder (FDR) to an aircraft. FDR records data about functioning of an aircraft. No one cares what is in there as long as the aircraft operates safely – but when bad things happen, every investigation boils down to finding and analyzing FDR data. Investigation results are used to understand what went wrong and make improvements to prevent bad things from reoccurring.

What are the similarities between FDR and Logging? No one will never spend time in reviewing logs as long as the software application is running smoothly, but when accidents happen (think performance degrades and errors) – details collected in the logs become vital for debugging the application. Logging process should collect any data that helps in troubleshooting.

Integration Services 2012 Logging

SQL Server Integration Services prior to 2012 had decent ability in implementing logging. Developers have gone above and beyond to extend the built-in functionality to come up with custom solutions, popularly known as custom logging or frameworks.

One of the bazillion improvements introduced in SQL Server Integration Services 2012 is Logging. Most of the custom logging we implemented earlier is now built into SSIS project deployment model. As a developer you don’t have to do any thing different.

Example

The below example project has two child packages – one for each table and a parent package executes the child packages.

Event Handlers are empty for all the three packages. In addition, there are no red arrows (failure precedence constraints, if that’s how you prefer) in any of the control flows. Showing this will take up quite a bit of space here so you’ll have to trust me on.

This means I’m not implementing any error handling or logging techniques in the packages.

Next, I executed the ETL Master package with logging level as Verbose. SSIS provides different logging levels. Matt Masson wrote an article explaining what events are included in different log levels. Verbose log level logs everything.

Let’s run a few queries against the SSISDB database to see what’s logged.

Execution

Every execution gets a unique execution_id. The following query retrieves the status and duration of the execution.

SELECT  [project_name] ,
[package_name] ,
[status description] = CASE [status]
WHEN 1 THEN 'created'
WHEN 2 THEN 'Running'
WHEN 3 THEN 'canceled'
WHEN 4 THEN 'failed'
WHEN 5 THEN 'pending'
WHEN 6 THEN 'ended unexpectedly'
WHEN 7 THEN 'succeeded'
WHEN 8 THEN 'stopping'
WHEN 9 THEN 'completed'
END ,
Duration = DATEDIFF(ms, start_time, end_time)
FROM    [catalog].[executions]
WHERE   [execution_id] = 40044

Executable and Executable Statistics

Below query gives you duration and status of all the executables.

SELECT  e.package_name ,
e.[executable_name] ,
es.[execution_path] ,
es.[execution_duration] ,
[execution_result] = CASE es.[execution_result]
WHEN 0 THEN 'Success'
WHEN 1 THEN 'Failure'
WHEN 2 THEN 'Completion'
WHEN 3 THEN 'Cancelled'
END

FROM    [catalog].[executables] e
INNER JOIN [catalog].[executable_statistics] es ON es.[executable_id] = e.[executable_id]
WHERE   e.execution_id = 40044

Component Phases

This applies to data flow tasks. See which component phases take up most of the time.

WITH    cte
AS ( SELECT   [package_name] ,
[task_name] ,
[subcomponent_name] ,
[phase] ,
Duration = DATEDIFF(ms, start_time, [end_time])
FROM     [catalog].[execution_component_phases]
WHERE    [execution_id] = 40044
)
SELECT  [package_name] ,
[task_name] ,
[subcomponent_name] ,
[phase] ,
Duration = SUM(Duration)
FROM    cte
GROUP BY [package_name] ,
[task_name] ,
[subcomponent_name] ,
[phase]
ORDER BY [package_name] ,
Duration DESC

Execution Data Statistics

How many rows are transferred? How many buffers are used?

SELECT  [package_name] ,
[task_name] ,
[dataflow_path_id_string] ,
rows_sent = SUM([rows_sent]) ,
buffer_count = COUNT(*)
FROM    [catalog].[execution_data_statistics]
WHERE   [execution_id] = 40044
GROUP BY [package_name] ,
[task_name] ,
[dataflow_path_id_string]

And the list goes on…

I first read about SSIS Logging in Denali from an excellent article written by Jamie Thomson (b|twitter). Jamie also put together a bunch of reports called SSIS Reporting Pack on CodePlex. They are free and you must use them in conjunction with SSIS 2012.

I’m @SamuelVanga on Twitter.