Relating ExecutionInstanceGUID to the SSISDB

Question

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 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_id

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.

Answer 1

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 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.executionid

SELECT 
    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. NULL

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 System::ServerExecutionID will be 0. It makes sense, but future readers either use a LEFT OUTER JOIN when linking sysssislog to catalog.operation_messages if you want to catch all executions of the package.

Hat tip, my hearty thanks and the answer credit go to Marian for putting me on the correct track. Given the choice between storing a GUID (16 bytes) and a bigint (8 bytes) in my summarized logging table, it's a no brainer for me: monotonically increasing big integer please.

Answer 2

Too much for a comment, but trying something. From the msdn page of that system table catalog.executions I get:

execution_id - bigint - The unique identifier (ID) for the instance of execution.

From this article - SSIS 2012 – View Connection Manager Information for Past Executions - I understand that:

SSIS 2012 provides a new system variable, ServerExecutionID, for your use inside packages, so if you do any custom logging/notifications it is a good variable to include as it will be a direct pointer to the catalog views that we’ll use to find connection string information. ... Catalog.executions contains one row per execution. This is where we’ll filter by execution_id.

With a sample query of:

DECLARE @execution_id BIGINT = 41753; -- Your execution_id/ServerExecutionID goes here.
SELECT e.package_name,
        e.start_time,
        e.end_time,
        e.status,
        emc.package_path,
        CAST(emc.property_value AS VARCHAR(1000)) AS connection_string
   FROM catalog.executions e
   JOIN catalog.event_messages em
     ON e.execution_id = em.operation_id
   JOIN catalog.event_message_context AS emc WITH (FORCESEEK)
     ON em.event_message_id = emc.event_message_id
    AND emc.property_name = 'ConnectionString'
    AND emc.context_type = 80 -- Connection Managers
  WHERE e.execution_id = @execution_id;

What I don't see is your ExecutionInstanceGUID in this table. What I see, though, is this ancient Connect item where there's the following story:

SSIS RunningPackage.InstanceID != System::ExecutionInstanceGUID though they should be equal.

So my conclusion is that ExecutionInstanceGUID is not related to execution_id, but some InstanceId column, in case you might have one in the SSISDB.