A lot of things can and do go wrong when using a suite of SSIS packages to populate a SQL Server data warehouse with files from various sources on a daily basis. When something does go wrong, it is important to detect and rectify it in a timely manner. A missing data file or a file containing incomplete, corrupt, or improperly formatted data can cause a package to fail and data to be omitted, while a file that doesn't get transferred in time can cause the previous day's data to be duplicated.

While SQL Server and SSIS have native execution-logging capabilities, they are geared toward the needs of DBAs and do not capture such fundamental things as the timestamp of a processed data file or package-execution end-time, which can be extremely useful pieces of information for determining when an ETL anomaly has occurred.

SSIS Execution Log Table

To capture and utilize SSIS execution information not collected by the built-in logging features we will create a log table for storing the:

1. Name of each SSIS package as it executes
2. Path and timestamp of the data file it processes
3. Number of records in the data file
4. Execution start and end times
5. Length of time it takes for the package to execute
6. Execution status

Here is a the schema we will use.

Sample SSIS Execution Log Data

The following figure shows a query of the log table after the demo package has been run a few times under various test conditions.

Execution Status Conditions

1. OK - The SSIS package executed normally.
2. PROCESSING ERROR - One of the tasks inside the sequence container failed.
3. INCOMPLETE - The SSIS package is in the process of executing, or was aborted.
4. INPUT FILE REPROCESSED - The data file being processed by the SSIS package had the same timestamp as a file previously processed by the package.
5. INPUT FILE MISSING - The SSIS package attempted to read a data file that does not exist.

SSIS Execution-Logging Demo

There is a zip file attached to this article containing versions of the demo for SSIS 2005 and 2008, a sql script to generate the log file, and a test data file for use with the demo.

This is the SSIS logging demo before before it is executed.

The global variables in the left panel allow the script tasks to pass values to downstream tasks. Enabling/disabling the "dummy failed task" script task allows the demo to be tested in "success" and "failure" modes.

This is the package after it runs with the "dummy failed task" disabled.

This is the package after running with the "dummy failed task" enabled.

How It Works

The logging functions occur in the three script tasks outside the sequence container: The initial script task captures starting execution information and writes it to the log table. The failure script task is only executed if a task in the sequence container fails. The last script task determines the final execution status of the job,writes it to the log table, and sends an email if an error condition occurred.

Initial Script Task Algorithm

This script task captures and stores the "execution start "data.

1. Capture execution start time an save it to the User::execution_start_time package variable.
2. Retrieve the input file path from the User::input_file_path package variable and store it in the local variable input_file_path.
3. Retrieve the package name from the System::PackageName and store it in the local variable ssis_package_name.
4. Capture the timestamp of the input file if the input file exists.
5. Query the log table to determine if an SSIS package with this name has already processed an input file with the same timestamp and populate the value of the input_file_status variable accordingly.
6. If the input file exists, count the number of lines in the input file and insert the execution start info into the log table with a value of INCOMPLETE in the execution_status field.
7. If the input file does not exist, insert the execution start info into the log table with a value of ERROR in the execution_status field.

Initial Script Task VB.NET Code

Option Strict On
Imports System
Imports System.Data
Imports System.Data.SqlClient
Imports System.Math
Imports Microsoft.SqlServer.Dts.Runtime
Imports System.Windows.FormsPublic Class ScriptMainPublic Sub Main()'Capture execution start time and save it to the "execution_start_time" global variable
Dim execution_start_time As String = CStr(DateTime.Now)
Dts.Variables("execution_start_time").Value = execution_start_time'Get the input file path from the "input_file_path" global variable
Dim input_file_path As String = Dts.Variables("input_file_path").Value.ToString'Get the SSIS package name from the "PackageName" SSIS system variable
Dim ssis_package_name As String = Dts.Variables("PackageName").Value.ToStringTry'Get the timestamp of the input file if the file exists
Dim fileDetail As IO.FileInfo = My.Computer.FileSystem.GetFileInfo(input_file_path)
Dim input_file_timestamp As String = CStr(fileDetail.LastWriteTime)
Dts.Variables("input_file_timestamp").Value = input_file_timestamp'Query the ssis_exec_log table to see if an SSIS package with this name has already processed an input file with the same timestamp
Dim mySqlStatement As String = "SELECT CAST(COUNT(*) AS VARCHAR(10)) AS timestamp_count FROM ssis_exec_log WHERE input_file_timestamp = '" & input_file_timestamp & "' AND ssis_package_name = '" & ssis_package_name & "'"
Dim myADONETConnection As SqlClient.SqlConnection = DirectCast(Dts.Connections("AdoNetConnection").AcquireConnection(Dts.Transaction), SqlClient.SqlConnection)
Dim myCommand As New SqlClient.SqlCommand(mySqlStatement, myADONETConnection)
Dim reader As SqlDataReader = myCommand.ExecuteReader(CommandBehavior.CloseConnection)'Read the results of the query and populate the "execution_status" variable accordingly
Dim timestamp_count As String
Do While reader.Read()
timestamp_count = reader("timestamp_count").ToString
Loop
If timestamp_count <> "0" Then
Dts.Variables("execution_status").Value = "INPUT FILE REPROCESSED"
ElseIf timestamp_count = "0" Then
Dts.Variables("execution_status").Value = "INCOMPLETE"
End If'Count the number of lines in the input file
Dim input_file_record_count As Integer
Dim oFile As System.IO.File
Dim oRead As System.IO.StreamReader
Dim LineIn As String
oRead = oFile.OpenText(input_file_path)
While oRead.Peek <> -1
LineIn = oRead.ReadLine()
input_file_record_count += 1
End While
oRead.Close()'Insert the execution start information into the ssis_exec_log table
mySqlStatement = "INSERT INTO ssis_exec_log (ssis_package_name,input_file_path,input_file_timestamp,input_file_record_count,execution_start_time,execution_status) VALUES ('" & ssis_package_name & " ','" & input_file_path & "','" & input_file_timestamp & "','" & input_file_record_count & "','" & execution_start_time & "','" & Dts.Variables("execution_status").Value.ToString & "')"
myADONETConnection = DirectCast(Dts.Connections("AdoNetConnection").AcquireConnection(Dts.Transaction), SqlClient.SqlConnection)
myCommand = New SqlClient.SqlCommand(mySqlStatement, myADONETConnection)
myCommand.ExecuteNonQuery()
myADONETConnection.Close()Catch ex As Exception 'if the file does not exist insert "INPUT FILE MISSING" execution start information into the ssis_exec_log tableDts.Variables("input_file_timestamp").Value = ""
Dts.Variables("execution_status").Value = "INPUT FILE MISSING"Dim mySqlStatement As String = "INSERT INTO ssis_exec_log (ssis_package_name,input_file_path,execution_start_time,execution_status) VALUES ('" & ssis_package_name & " ','" & input_file_path & "','" & execution_start_time & " ','" & Dts.Variables("execution_status").Value.ToString & "')"
Dim myADONETConnection As SqlClient.SqlConnection = DirectCast(Dts.Connections("AdoNetConnection").AcquireConnection(Dts.Transaction), SqlClient.SqlConnection)
Dim myCommand As New SqlClient.SqlCommand(mySqlStatement, myADONETConnection)
Dim reader As SqlDataReader = myCommand.ExecuteReader(CommandBehavior.CloseConnection)Dts.TaskResult = Dts.Results.FailureEnd TryDts.TaskResult = Dts.Results.SuccessEnd Sub End Class

Failed container task algorithm

The only function of this task is to set the value of the "execution_status" global variable to "processing error" when a task inside the sequence container has failed.

Failed container task VB.NET code.

'Microsoft SQL Server Integration Services Script Task
'Write scripts using Microsoft Visual Basic
'The ScriptMain class is the entry point of the Script Task. Imports System
Imports System.Data
Imports System.MathImports System.Data.SqlClient
Imports Microsoft.SqlServer.Dts.RuntimePublic Class ScriptMainPublic Sub Main()Dts.Variables("execution_status").Value = "PROCESSING ERROR"'Set execution_status to "PROCESSING ERROR" if any of the tasks inside the sequence container failed
 Dim mySqlStatement As String = "UPDATE ssis_exec_log SET execution_status = '" & Dts.Variables("execution_status").Value.ToString & "' WHERE ssis_package_name = '" & Dts.Variables("PackageName").Value.ToString & "' AND execution_start_time = '" & Dts.Variables("execution_start_time").Value.ToString & "'"
 Dim myADONETConnection As SqlClient.SqlConnection = DirectCast(Dts.Connections("AdoNetConnection").AcquireConnection(Dts.Transaction), SqlClient.SqlConnection)
 Dim myCommand As New SqlClient.SqlCommand(mySqlStatement, myADONETConnection)
 myCommand.ExecuteNonQuery()
 myADONETConnection.Close()Dts.TaskResult = Dts.Results.SuccessEnd SubEnd Class

Last Script Task Algorithm

The last script task determines the final execution status of the package, writes it to the log table, and sends a failure-alert email if the package did not execute normally.

1. If value of execution_status variable is "INCOMPLETE," set it to "OK."
2. If execution_status is "OK" or "INPUT FILE REPROCESSED," update the appropriate record in the ssis_exec_log table:
   • Capture the current time and save it to the execution_end_time local variable.
   • Calculate the execution_elapsed_time from the execution_start_time global variable value and the execution_end_time local variable value.
   • Update the ssis_exec_log record inserted by the first script task with the execution_end_time, execution_elapsed_time and execution_status values.
3. Send a failure-alert email if execution_status is not "OK.."

Final Script Task VB.NET Code

Option Strict On
Imports System
Imports System.Data
Imports System.Math
Imports System.Net
Imports System.Net.Mail
Imports System.Data.SqlClient
Imports Microsoft.SqlServer.Dts.Runtime
Imports System.Windows.Forms Public Class ScriptMain Public Sub Main() 'Set execution_status to OK if it is currently INCOMPLETE
 If Dts.Variables("execution_status").Value.ToString = "INCOMPLETE" Then
 Dts.Variables("execution_status").Value = "OK"
 End If 'Update the execution end information in the ssis_exec_log table if execution_status is OK or INPUT FILE REPROCESSED
 If Dts.Variables("execution_status").Value.ToString = "OK" Or Dts.Variables("execution_status").Value.ToString = "INPUT FILE REPROCESSED" Then 'Capture package execution end time and save it to the "execution_end_time" local variable
 Dim execution_end_time As String = CStr(DateTime.Now) 'Get package execution start time from the "execution_start_time" global variable
 Dim execution_start_time As String = Dts.Variables("execution_start_time").Value.ToString 'Calculate execution elapsed time using a T-SQL query and save it to the "execution_elapsed_time" local variable
 Dim execution_elapsed_time As String
 Dim mySqlStatement As String = "SELECT CAST(DATEDIFF(ss, CAST('" & execution_start_time & "' AS DATETIME), CAST('" & execution_end_time & "' AS DATETIME)) AS VARCHAR(10)) AS execution_elapsed_time"
 Dim myADONETConnection As SqlClient.SqlConnection = DirectCast(Dts.Connections("AdoNetConnection").AcquireConnection(Dts.Transaction), SqlClient.SqlConnection)
 Dim myCommand As New SqlClient.SqlCommand(mySqlStatement, myADONETConnection)
 Dim reader As SqlDataReader = myCommand.ExecuteReader(CommandBehavior.CloseConnection)
 Do While reader.Read()
 execution_elapsed_time = reader("execution_elapsed_time").ToString & " seconds"
 Loop 'Update the "ssis_exec_log" record with "execution_end_time" and "execution_elapsed_time"
 mySqlStatement = "UPDATE ssis_exec_log SET execution_end_time = '" & execution_end_time & "',execution_elapsed_time = '" & execution_elapsed_time & "',execution_status = '" & Dts.Variables("execution_status").Value.ToString & "' WHERE ssis_package_name = '" & Dts.Variables("PackageName").Value.ToString & "' AND execution_start_time = '" & Dts.Variables("execution_start_time").Value.ToString & "'"
 myADONETConnection = DirectCast(Dts.Connections("AdoNetConnection").AcquireConnection(Dts.Transaction), SqlClient.SqlConnection)
 myCommand = New SqlClient.SqlCommand(mySqlStatement, myADONETConnection)
 myCommand.ExecuteNonQuery()
 myADONETConnection.Close() End If 'Send failure email if execution_status is not OK
 If Dts.Variables("execution_status").Value.ToString <> "OK" Then Dim myHtmlMessage As MailMessage
 Dim mySmtpClient As SmtpClient
 Dim message As String = "SSIS Package " + Dts.Variables("PackageName").Value.ToString + " failed at " + Dts.Variables("execution_start_time").Value.ToString + " with error mesage " + Dts.Variables("execution_status").Value.ToString + "." myHtmlMessage = New MailMessage("sender@domain", "recipient@domain", "SSIS Execution Failure Occurred", message)
 myHtmlMessage.Bcc.Add("bcc@domain")
 mySmtpClient = New SmtpClient("0.0.0.0") 'IP address of SMTP server
 mySmtpClient.Credentials = CredentialCache.DefaultNetworkCredentials
 mySmtpClient.Send(myHtmlMessage)
 myHtmlMessage.Dispose() End If Dts.TaskResult = Dts.Results.Success End Sub End Class

Adding Execution Logging to Existing SSIS Packages

To add execution logging to any SSIS package:

1. Delete the demo tasks from the demo sequence container.
2. Copy-and-paste the existing SSIS package into the demo sequence container.
3. Edit the input file path global variable to point to the input file of the embedded SSIS package.
4. Add any global variables required by the embedded SSIS package.
5. Add any file/database connections required by the embedded SSIS package.
6. Configure the IP address of the SMTP server and the desired email addresses in the "send email" section of the final script task.
7. Change the name of the demo package to that of the embedded SSIS package.

Conclusion

SSIS and SQL Server have a robust suite of logging features, but most of them are geared toward the needs of DBAs. As a producer/consumer of SSIS ETL services, you have no way of knowing in a timely manner when something has gone wrong unless you actively log SSIS execution events and send out an alert when a package fails. This tutorial demonstrated an easy way to accomplish this goal by pasting an existing SSIS package into the sequence container of the accompanying execution logging demo.