SSIS package logging – Custom logging 2008 R2 and 2012

Logging is an important part of SSIS package development , I personaly prefer to have logging in all production level packages

Logging can be used as more than debugging errors in a scheduled package execution environment but also performs the audit functions it needs and we can also measure

performance, Out of the box SSIS 2008 and SSIS 2012 have some nice logging capabilities

The following table describes the predefined events that can be enabled to write log entries when run-time events occur. These log entries apply to executables, the package, and the tasks and containers that the package includes. The name of the log entry is the same as the name of the run-time event that was raised and caused the log entry to be written.

Events Description
OnError Writes a log entry when an error occurs.
OnExecStatusChanged Writes a log entry when the execution status of the executable changes.
OnInformation Writes a log entry during the validation and execution of an executable to report information.
OnPostExecute Writes a log entry immediately after the executable has finished running.
OnPostValidate Writes a log entry when the validation of the executable finishes.
OnPreExecute Writes a log entry immediately before the executable runs.
OnPreValidate Writes a log entry when the validation of the executable starts.
OnProgress Writes a log entry when measurable progress is made by the executable.
OnQueryCancel Writes a log entry at any juncture in the task processing where it is feasible to cancel execution.
OnTaskFailed Writes a log entry when a task fails.
OnVariableValueChanged Writes a log entry when the value of a variable changes.
OnWarning Writes a log entry when a warning occurs.
PipelineComponentTime For each data flow component, writes a log entry for each phase of validation and execution. The log entry specifies the processing time for each phase.
Diagnostic Writes a log entry that provides diagnostic information.For example, you can log a message before and after every call to an external data provider

there are some custom logging messages to some of the control flow tasks and data flow tasks

Data Flow Task

The following table lists the custom log entries for the Data Flow task.

Log entry Description
BufferSizeTuning Indicates that the Data Flow task changed the size of the buffer. The log entry describes the reasons for the size change and lists the temporary new buffer size.
OnPipelinePostEndOfRowset Denotes that a component has been given its end-of-rowset signal, which is set by the last call of the ProcessInput method. An entry is written for each component in the data flow that processes input. The entry includes the name of the component.
OnPipelinePostPrimeOutput Indicates that the component has completed its last call to the PrimeOutput method. Depending on the data flow, multiple log entries may be written. If the component is a source, this means that the component has finished processing rows.
OnPipelinePreEndOfRowset Indicates that a component is about to receive its end-of-rowset signal, which is set by the last call of the ProcessInput method. An entry is written for each component in the data flow that processes input. The entry includes the name of the component.
OnPipelinePrePrimeOutput Indicates that the component is about to receive its call from the PrimeOutput method. Depending on the data flow, multiple log entries may be written.
OnPipelineRowsSent Reports the number of rows provided to a component input by a call to the ProcessInput method. The log entry includes the component name.
PipelineBufferLeak Provides information about any component that kept buffers alive after the buffer manager goes away. This means that buffers resources were not released and may cause memory leaks. The log entry provides the name of the component and the ID of the buffer.
PipelineExecutionPlan Reports the execution plan of the data flow. It provides information about how buffers will be sent to components. This information, in combination with the PipelineExecutionTrees entry, describes what is occurring in the task.
PipelineExecutionTrees Reports the execution trees of the layout in the data flow. The scheduler of the data flow engine use the trees to build the execution plan of the data flow.
PipelineInitialization Provides initialization information about the task. This information includes the directories to use for temporary storage of BLOB data, the default buffer size, and the number of rows in a buffer. Depending on the configuration of the Data Flow task, multiple log entries may be written.

for example in a data flow task you can also log some performance counters to measure the buffer allocation and buffer leakage during the transformations

to know more about custom logging messages in SSIS click the link below

http://msdn.microsoft.com/en-us/library/ms345174.aspx

Why do we need custom logging using event handlers?

Some times it becomes overhead by using the default log providers and it often ends up using the event handlers and system variables to log some key information which some times difficult to analyze using default logging

in order to perform the logging using event handlers we need to better understand the system variables and information they can provide


The following table describes the system variables that Integration Services provides for packages.

System variable Data type Description
CancelEvent Int32 The handle to a Windows Event object that the task can signal to indicate that the task should stop running.
CreationDate DateTime The date that the package was created.
CreatorComputerName String The computer on which the package was created.
CreatorName String The name of the person who built the package.
ExecutionInstanceGUID String The unique identifier of the executing instance of a package.
InteractiveMode Boolean Indicates whether the package is run in interactive mode. If a package is running in SSIS Designer, this property is set to True. If a package is running using the DTExec command prompt utility, the property is set toFalse.
LocaleId Int32 The locale that the package uses.
MachineName String The name of the computer on which the package is running.
OfflineMode Boolean Indicates whether the package is in offline mode. Offline mode does not acquire connections to data sources.
PackageID String The unique identifier of the package.
PackageName String The name of the package.
StartTime DateTime The time that the package started to run.
UserName String The account of the user who started the package. The user name is qualified by the domain name.
VersionBuild Int32 The package version.
VersionComment String Comments about the package version.
VersionGUID String The unique identifier of the version.
VersionMajor Int32 The major version of the package.
VersionMinor Int32 The minor version of the package.

please use the below link to better understand the system variables

http://msdn.microsoft.com/en-us/library/ms141788(v=SQL.105).aspx

lets do some  custom logging using event handlers for a simple package

before digging into more details lets create the table to log the details

as

CREATE TABLE [DBO].[PACKAGELOG](
[LOGID] [INT] IDENTITY(1,1) NOT NULL,
[EXECUTIONID] [UNIQUEIDENTIFIER] NULL,
[PACKAGENAME] [NVARCHAR](255) NULL,
[PACKAGEID] [VARCHAR](50) NULL,
[USERNAME] [NVARCHAR](100) NULL,
[MACHINENAME] [NVARCHAR](255) NULL,
[STARTDATETIME] [DATETIME] NULL,
[ENDDATETIME] [DATETIME] NULL,
[SOURCENAME] [VARCHAR](255) NULL,
[MESSAGE] [NVARCHAR](MAX) NULL,
[MESSAGECODE] [INT] NULL,
[LOGDATETIME] [DATETIME] NULL,
[INTERACTIVEMODE] [BIT] NULL,
[SOURCEDESCRIPTION] [VARCHAR](255) NULL,
[TASKNAME] [VARCHAR](255) NULL,
[TASKID] [NVARCHAR](255) NULL,
[EXECSTATUS] [BIT] NULL,
[SERVERNAME] [NVARCHAR](255) NULL,
CONSTRAINT [PK__PACKAGEL__5E5499A820C44329] PRIMARY KEY CLUSTERED
(
[LOGID] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY]
GO
SET ANSI_PADDING OFF
GO
ALTER TABLE [DBO].[PACKAGELOG] ADD CONSTRAINT [DF_PACKAGELOG_EXECSTATUS] DEFAULT ((0)) FOR [EXECSTATUS]
GO

Note : there are some noted issues while using the system:: start time system variable and mapping to any SSIS date time data type

The reason is the value of the system start time looks like  this SYSTEM::STARTTIME  {18/10/2010 14:30:27}

which can not be mapped to any SSIS date time data types we will be getting a error

“The type is not supported.DBTYPE_DBDATE”. Possible failure reasons: Problems with the query, “ResultSet” property not set correctly, parameters not set correctly, or connection not established correctly

To avoid this error we have a work around is to create a variable with string and use a expression and setting the variable value to be evaluate as expression and get the parsed System start time from the variable and map that variable to the execute SQL task

as

(DT_WSTR, 4)YEAR(@[System::StartTime])

+ “-” +
RIGHT(“0” + (DT_WSTR, 2)MONTH(@[System::StartTime]), 2)

+ “-” +

RIGHT(“0″ + (DT_WSTR, 2)DAY(@[System::StartTime]), 2)

+ ” ” +

RIGHT(“0” + (DT_WSTR, 2)DATEPART(“Hour”, @[System::StartTime]), 2)

+ “:” +

RIGHT(“0” + (DT_WSTR, 2)DATEPART(“Minute”, @[System::StartTime]), 2)

+ “:” +

RIGHT(“0” + (DT_WSTR, 2)DATEPART(“Second”, @[System::StartTime]), 2)

+ “.” +

RIGHT(“00” + (DT_WSTR, 3)DATEPART(“Millisecond”,@[System::StartTime]), 3)

insert into dbo.packagelog (ExecutionID,packagename,packageid,username,machinename,interactivemode,sourcename,taskname,taskid,Message,MessageCode,execstatus,servername,startdatetime,enddatetime)
values (?,?,?,?,?,?,?,?,?,?,?,((0)),@@SERVERNAME,?,getdate())

as

log

success log

there are some nice free third party tools to dig the information from the log graphically like log analyzer

http://ssisloganalyzer.codeplex.com/

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s