patternModerate
Relating ExecutionInstanceGUID to the SSISDB
Viewed 0 times
ssisdbtheexecutioninstanceguidrelating
Problem
The 2012 release of SQL Server Integration Services, SSIS, has delivered an SSISDB catalog which tracks the operations of packages (among other things). The default package execution for solutions using the Project Deployment model will have logging to the SSISDB turned on.
When a package executes, the
What I'd like to know, is how do I tie an ExecutionInstanceGUID to anything in the SSISDB catalog. Alternatively, is an SSIS package executing in the SSISDB privy to the value of its
Ultimately, I am trying to use the existing, custom audit table and link it back to the detailed history in the SSISDB catalog but can't seem to find the link.
When a package executes, the
System::ExecutionInstanceGUID is populated with a value that, if one were using explicit logging (to sys.sysdtslog90/sys.sysssislog) would record all the events for a specific package execution.What I'd like to know, is how do I tie an ExecutionInstanceGUID to anything in the SSISDB catalog. Alternatively, is an SSIS package executing in the SSISDB privy to the value of its
catalog.executions.execution_idUltimately, I am trying to use the existing, custom audit table and link it back to the detailed history in the SSISDB catalog but can't seem to find the link.
Solution
I created a SSIS project using the 2012 Deployment Model consisting of a single package. In that package, I added an OLE DB Connection Manager, pointed it to tempdb and dropped a Script Task onto the canvas. I also turned on explicit logging using that OLE DB Connection Manager and captured the
SCR Fire info
I configured my script task to grab two parameters:
Deploy and execute
I then deployed my project to a server and executed it.
I opened the Operations Report and and clicked into the
The red circled item shows that we are viewing details for Operation 8, as expected. The highlighted lines are the
Tying it all together
I now had a two different logs I wanted to tie together.
sysssislog query
Running this query pulled back relevant rows from the old-school logging table.
The results looked like
catalog.operation_messages query
Running this query against the SSISDB catalog showed all the messages that were in the above report and also confirmed I could link the value in
Those results were
Wrap up
When the package is executed outside of the context of the SSISDB catalog (aka via SSDT-BI or the command line to an .ispac) the value of the the
OnInformation event.SCR Fire info
I configured my script task to grab two parameters:
System::ExecutionInstanceGUID and System::ServerExecutionID I will admit at this point, I had not noticed the second variable until Marian's answer. Inside the task, I raise 2 Information events so I can get the values recorded. This should be logged to both the explicit table (dbo.sysssislog) and the "free" logging (catalog.operation_messages).public void Main()
{
bool fireAgain = true;
string description = string.Empty;
string variable = string.Empty;
string value = string.Empty;
variable = "System::ServerExecutionID";
value = Dts.Variables[variable].Value.ToString();
description = string.Format("{0}: {1}", variable, value);
Dts.Events.FireInformation(0, "Reporting", description, string.Empty, 0, ref fireAgain);
variable = "System::ExecutionInstanceGUID";
value = Dts.Variables[variable].Value.ToString();
description = string.Format("{0}: {1}", variable, value);
Dts.Events.FireInformation(0, "Reporting", description, string.Empty, 0, ref fireAgain);
Dts.TaskResult = (int)ScriptResults.Success;
}Deploy and execute
I then deployed my project to a server and executed it.
I opened the Operations Report and and clicked into the
SCR Fire info task details.The red circled item shows that we are viewing details for Operation 8, as expected. The highlighted lines are the
OnInformation events which bubbled up the values of those two system variables. Also as expected, the value of System::ServerExecutionID matched what was in the report. The value of System::ExecutionInstanceGUID was meaningless as always but it was present {3F515780-8062-40AA-B9EC-C320CBAC5EFD}. Tying it all together
I now had a two different logs I wanted to tie together.
sysssislog query
Running this query pulled back relevant rows from the old-school logging table.
SELECT
L.event
, L.source
, L.message
FROM
dbo.sysssislog AS L
WHERE
L.executionid = '{3F515780-8062-40AA-B9EC-C320CBAC5EFD}'
ORDER BY
L.id ASC;The results looked like
event source message
PackageStart ParameterTest Beginning of package execution.
OnInformation SCR Fire info System::ServerExecutionID: 8
OnInformation ParameterTest System::ServerExecutionID: 8
OnInformation SCR Fire info System::ExecutionInstanceGUID: {3F515780-8062-40AA-B9EC-C320CBAC5EFD}
OnInformation ParameterTest System::ExecutionInstanceGUID: {3F515780-8062-40AA-B9EC-C320CBAC5EFD}
PackageEnd ParameterTest End of package execution.catalog.operation_messages query
Running this query against the SSISDB catalog showed all the messages that were in the above report and also confirmed I could link the value in
message to operation_id as well as over to dbo.sysssislog.executionidSELECT
OM.*
FROM
catalog.operation_messages AS OM
WHERE
OM.operation_id = 8;Those results were
operation_message_id operation_id message_time message_type message_source_type message extended_info_id
30 8 2013-04-02 21:02:34.1418917 -05:00 10 30 ParameterTest:Validation has started. NULL
31 8 2013-04-02 21:02:34.1738922 -05:00 10 40 SCR Fire info:Validation has started. NULL
32 8 2013-04-02 21:02:34.1768872 -05:00 20 40 SCR Fire info:Validation is complete. NULL
33 8 2013-04-02 21:02:34.1788903 -05:00 20 30 ParameterTest:Validation is complete. NULL
34 8 2013-04-02 21:02:34.3349188 -05:00 30 30 ParameterTest:Start, 9:02:34 PM. NULL
35 8 2013-04-02 21:02:34.4009253 -05:00 30 40 SCR Fire info:Start, 9:02:34 PM. NULL
36 8 2013-04-02 21:02:34.4009253 -05:00 10 40 SCR Fire info:Validation has started. NULL
37 8 2013-04-02 21:02:34.4019251 -05:00 20 40 SCR Fire info:Validation is complete. NULL
38 8 2013-04-02 21:02:34.4219283 -05:00 70 40 SCR Fire info:Information: System::ServerExecutionID: 8 NULL
39 8 2013-04-02 21:02:34.4259295 -05:00 70 40 SCR Fire info:Information: System::ExecutionInstanceGUID: {3F515780-8062-40AA-B9EC-C320CBAC5EFD} NULL
40 8 2013-04-02 21:02:34.4409316 -05:00 40 40 SCR Fire info:Finished, 9:02:34 PM, Elapsed time: 00:00:00.031. NULL
41 8 2013-04-02 21:02:34.4419388 -05:00 40 30 ParameterTest:Finished, 9:02:34 PM, Elapsed time: 00:00:00.125. NULLWrap up
When the package is executed outside of the context of the SSISDB catalog (aka via SSDT-BI or the command line to an .ispac) the value of the the
System::ServerExecutionID will be 0. It makes sense, but future readers either use a LEFCode Snippets
public void Main()
{
bool fireAgain = true;
string description = string.Empty;
string variable = string.Empty;
string value = string.Empty;
variable = "System::ServerExecutionID";
value = Dts.Variables[variable].Value.ToString();
description = string.Format("{0}: {1}", variable, value);
Dts.Events.FireInformation(0, "Reporting", description, string.Empty, 0, ref fireAgain);
variable = "System::ExecutionInstanceGUID";
value = Dts.Variables[variable].Value.ToString();
description = string.Format("{0}: {1}", variable, value);
Dts.Events.FireInformation(0, "Reporting", description, string.Empty, 0, ref fireAgain);
Dts.TaskResult = (int)ScriptResults.Success;
}SELECT
L.event
, L.source
, L.message
FROM
dbo.sysssislog AS L
WHERE
L.executionid = '{3F515780-8062-40AA-B9EC-C320CBAC5EFD}'
ORDER BY
L.id ASC;event source message
PackageStart ParameterTest Beginning of package execution.
OnInformation SCR Fire info System::ServerExecutionID: 8
OnInformation ParameterTest System::ServerExecutionID: 8
OnInformation SCR Fire info System::ExecutionInstanceGUID: {3F515780-8062-40AA-B9EC-C320CBAC5EFD}
OnInformation ParameterTest System::ExecutionInstanceGUID: {3F515780-8062-40AA-B9EC-C320CBAC5EFD}
PackageEnd ParameterTest End of package execution.SELECT
OM.*
FROM
catalog.operation_messages AS OM
WHERE
OM.operation_id = 8;operation_message_id operation_id message_time message_type message_source_type message extended_info_id
30 8 2013-04-02 21:02:34.1418917 -05:00 10 30 ParameterTest:Validation has started. NULL
31 8 2013-04-02 21:02:34.1738922 -05:00 10 40 SCR Fire info:Validation has started. NULL
32 8 2013-04-02 21:02:34.1768872 -05:00 20 40 SCR Fire info:Validation is complete. NULL
33 8 2013-04-02 21:02:34.1788903 -05:00 20 30 ParameterTest:Validation is complete. NULL
34 8 2013-04-02 21:02:34.3349188 -05:00 30 30 ParameterTest:Start, 9:02:34 PM. NULL
35 8 2013-04-02 21:02:34.4009253 -05:00 30 40 SCR Fire info:Start, 9:02:34 PM. NULL
36 8 2013-04-02 21:02:34.4009253 -05:00 10 40 SCR Fire info:Validation has started. NULL
37 8 2013-04-02 21:02:34.4019251 -05:00 20 40 SCR Fire info:Validation is complete. NULL
38 8 2013-04-02 21:02:34.4219283 -05:00 70 40 SCR Fire info:Information: System::ServerExecutionID: 8 NULL
39 8 2013-04-02 21:02:34.4259295 -05:00 70 40 SCR Fire info:Information: System::ExecutionInstanceGUID: {3F515780-8062-40AA-B9EC-C320CBAC5EFD} NULL
40 8 2013-04-02 21:02:34.4409316 -05:00 40 40 SCR Fire info:Finished, 9:02:34 PM, Elapsed time: 00:00:00.031. NULL
41 8 2013-04-02 21:02:34.4419388 -05:00 40 30 ParameterTest:Finished, 9:02:34 PM, Elapsed time: 00:00:00.125. NULLContext
StackExchange Database Administrators Q#38808, answer score: 10
Revisions (0)
No revisions yet.