How to Have Standard Event Logging in SSIS and Avoid Traps

Event logging in SSIS gives a lot of valuable information about the run-time behavior and execution status of the SSIS package. Having a common minimum number of events is good for consistency in reports and general analysis. Lets say your team wants to ensure that all packages must log at least OnError, OnWarning, OnPreExecute and OnPostExecute events. If the package has a DataFlowTask then the BufferSizeTuning should also be logged. The developer can include more events to log as required but these mentioned previously are the minimum that must be included.

You can create pre-deployment checklists or documentation to ensure this minimum logging. Probably you already have that. As the number of developers and/or packages increase, it becomes difficult to ensure consistency in anything, not just for event logging. Therefore documentation, checklists and training are helpful to an extent only. Your requirement could be more complex than my five-event example above and thus more prone to to oversight.

The easiest way to ensure a common logging implementation would be a logging template that has all the minimum event pre-selected. The developer should just need to apply that to the package.

Event Logging in SSIS with a Template

I assume that you are already familiar with the concepts of event logging in SSIS so this post is not going to be a beginners level introduction to event logging. I will rather discuss options to have a minimum standard event logging across SSIS packages and teams with minimal effort. I’ll also mention some traps to avoid.

I am using a demo SSIS package with two Data Flow Tasks and an Execute SQL Task. I have enabled event logging in SSIS for the first few events at the package level for the sake of demonstration. The logging configuration options for the package node (which is the top node) are shown in the first image.

Image 1 - Logging configuration window for the package node
Image 1 – Event logging configuration window for the package node

The logging options at the child container node Data Flow Task 1 are shown in the second image. The configuration for other Data Flow and the Execute SQL Task look the same.

Image 2 - Logging configuration window at the child container node
Image 2 – Event logging configuration window at the child container node

The check marks for the tasks are grayed out which means they are inheriting the logging options from their parent, i.e. the package. To disable logging for a task, remove its check mark in the left tree view window.

TIP: Logging can also be disabled by going to the Control Flow canvas and changing the LoggingMode property of the task to Disabled.

The Trick

Now look at the bottom of the images again. Notice the Load… and Save… buttons? They do exactly what they say. You can set your logging options and save them as an XML template. Later, this XML template can be loaded into other packages to enable the same logging options.

The XML template file has nodes for each event. For example, the logging options for OnError event are saved like this –


-<EventsFilter Name="OnError">

-<Filter>

<Computer>true</Computer>

<Operator>true</Operator>

<SourceName>true</SourceName>

<SourceID>true</SourceID>
<ExecutionID>true</ExecutionID>

<MessageText>true</MessageText>

<DataBytes>true</DataBytes>

</Filter>

</EventsFilter>

Notice that the XML just mentions the event name, not the name of any task. This means that when the template file is loaded, this logging option will be set for any task where the event is applicable. More on this later.

The Traps

The OnError event is a generic event applicable to all tasks. Lets talk about events that are specific to tasks. For example, the BufferSizeTuning event is applicable just to the Data Flow Tasks, not Execute SQL Tasks.

When I proceed to set logging for BufferSizeTuning event, I have to set it individually in the Data Flow Task tree node. Notice the message at the bottom of the second image that says –

To enable unique logging options for this container, enable logging for it in the tree view.

This message is important in the context of saving and loading a template file too. When I save a template file, the logging options of just that tree view node are saved. For example, the BufferSizeTuning event will be saved in the template only if I am at the Data Flow task in the tree view. It will not be saved if I am at the Package or the Execute SQL task in the tree view.

The reverse is also true. When I load a template, its logging options are applied to just that node which I select in the tree view. For example, if I load a template at the Data Flow Task 1, the options will not be applied to the Data Flow Task 2 or the Execute SQL Task. If the template has an event that is not applicable to the task then that event’s settings will be ignored. For example, the BufferSizeTuning event logging option is meant for Data Flow Tasks so it will be ignored for the Execute SQL Task. The fact that non-relevant options are ignored can be helpful for us to consolidate all logging options in a single template file.

Conclusion

A package level Save and Load of a logging template is straight forward. But if you need to have logging for events that are specific to a task type, then consider creating a logging template for each type of task. Also, if your logging configuration requires anything else than the package level settings, remember to load the template for each task in the tree view.

Number of Template Files How Pros and Cons
Individual File per Task Create one template file for each type of task. The file will have events applicable to that task. Pros –
Easier to know what type of tasks have a template and which ones do not.Cons –
More files to manage.
Single File for All Tasks Create a template file for each task. Then copy all event options in a single XML file. Pros –
One file is easier to manage.Cons –
Not obvious which tasks are include. Need to put in comments in the XML file.

How to Log SSIS Variable Values During Execution in the Event Log

Log entries created during the execution of an SSIS package help in monitoring, analysis, and issue resolution. In addition to logging events, you might want to capture the run-time values of variables in the package. I couldn’t find a native feature to log SSIS variable values so the following post shows how I did it.

The Setup

For this demo, I’ll do an INSERT operation on a table named TableA and use variables to save the before and after INSERT row count. The TableA is always blank at the beginning of the package i.e. the row count is zero. The Execute SQL Task named ESQLT-InsertRowsInTableA inserts 502 rows in TableA. The simple package looks like the image below. If you are wondering about the funny prefixes in the object names then you can read about my naming conventions mentioned in my other blog post.

Log SSIS Variable Value 1 - Package

I have two integer variables named rcTableA_PreRefresh and rcTableA_PostRefresh scoped at the package level.

Log SSIS Variable Value 2 - Variables Init Zero

Enable the Event

A log entry is generated when an event is triggered. Each object in SSIS has its own events that can be logged. I’ll use the event called OnVariableValueChanged, which as the name denotes, is triggered whenever the value of the variable changes. This event is disabled by default. To enable it, go to the Properties window of the variable and make the RaiseChangedEvent property to True. It must be enabled for each variable individually.

Log SSIS Variable Value 3 - Variable Properties

Next, I include the OnVariableValueChanged event in the logging configuration. It has to be included at the container level where the variables are scoped to. In my case, at the package level. I’m using the SSIS Log Provider for SQL Server in this package.

Log SSIS Variable Value 44 - Configure Log

Then I execute the package and look at the [dbo].[sysssislog] table for the log entries.

Log SSIS Variable Value 5 - Log Entries 1

There are some log entries but something is missing. I see the OnVariableValueChanged event logged for the Post Refresh variable but not the Pre Refresh variable.

The reason is that the initial value of the variable is set to zero in the package. The row count of a brand new empty table is also zero. So there was no change in variable value. The OnVariableValueChanged event fires only when the value actually changes! Overwriting with the same value doesn’t fulfill this condition.

To resolve that, I change the initial values in the package to -1. Now even if the row count turns out to be zero, the variable value will still change from -1 to zero. The COUNT function can’t count below zero, can it?

Log SSIS Variable Value 6 - Variables Init Minus One

I run the package again and check out the [dbo].[sysssislog] table.

Log SSIS Variable Value 7 - Log Entries 2

Things are better. The OnVariableValueChanged event for both the variables show up in the log. But the variable values are still not there.

Log SSIS Variable

The reason for missing values is that the event logging just captures the fact that the variable value changed. It doesn’t capture the value by itself. I’ll make an addition to the event handler to get the variable values too. I add an Execute SQL Task to the package level event handler for OnVariableValueChanged event.

Log SSIS Variable Value 8 - Event Handler

The General tab of the Execute SQL Task has the following properties and SQL command –

Log SSIS Variable Value 8 - Event Handler - ESQLT 1

INSERT INTO [dbo].[sysssislog]
([event]
,[computer]
,[operator]
,[ source]
,[sourceid]
,[executionid]
,[starttime]
,[endtime]
,[datacode]
,[databytes]
,[message])
VALUES
('*SSIS-OnVariableValueChanged' -- Custom event name
,? -- param 0
,? -- param 1
,? -- param 2
,? -- param 3
,? -- param 4
,? -- param 5
,? -- param 6
,0 -- Zero
,'' -- Blank string
,?) -- param 7

Notice that I precede the custom event name with an asterisk to differentiate it from the log entries created by the system.

The Parameter Mapping tab of the Execute SQL Task has the following properties –

Log SSIS Variable Value 9 - Event Handler - ESQLT 2

Pay attention to the System::VariableValue (last variable) in this screen. Its data type is LONG, which is appropriate for the numeric row counts in my example. You may have different data types for your variables. Do adjust the data type and length appropriately. Using a wrong type could lead to no value logged at all.

I run the package again and this time, the variable values are also logged in the table.

Log SSIS Variable Value 10 - Log Entries 2

Summary

A single event handler will take care of all variables in that scope. In my case, two package scoped variables are handled by a single package level event handler.

The variable value really has to change to fire the event.

The OnVariableValueChanged event is triggered for the container that has the variable in its scope. The container triggering the change in variable value could be different than the container that has the variable in its scope. In my demo, the variables were scoped to the package. Even though an Execute SQL Task is changing the variable values, I still put the event handler at the package level. As another example, assume there is a variable declared in the scope of a ForEachLoop container and there is a Script Task in the ForEachLoop. The Script Task changes the variable value. The OnVariableValueChanged event will be triggered for the ForEachLoop task.

I have used the default [sysssislog] logging table to log my variable values. You can easily use a different custom table by changing the OLEDB connection and making appropriate changes to the INSERT statement.

Subscribe to Blog via Email

If you liked this post then please subscribe to get new post notifications in email.