Pages

Tuesday, December 22, 2015

A Tale of Two Triggers

The following is a cautionary tale about the importance of having only one* trigger per object type. It is based on actual events. Only the names, apex code, and events have been changed.

Imagine you have a trigger something like the one that appears below, along with its associated support Apex class.

Don't worry too much about reading all the code. Just know that the trigger fires after insert or update of an Opportunity record to do some processing. The first order of business is to ensure that the trigger hasn't already run in the current context due to other triggers that may be present in the org. We want to prevent multiple calls to the trigger in one transaction and the potential for trigger recursion. This is achieved via a static set of Opportunity Ids. Once we've processed a given Opportunity Id and put it in the set there is no need to revisit it again in the current transaction.

trigger MyProduct_Opportunity on Opportunity (after insert, after update) {

    OppTrg_MyProductIntegration productIntegration = new OppTrg_MyProductIntegration ();
    if (trigger.isAfter) {
        productIntegration.handleAfter(trigger.new, trigger.oldMap, trigger.isInsert, trigger.isUpdate);
    }

}
public with sharing class OppTrg_MyProductIntegration {
        private static Set visitedOpportunityIds = new Set();

    public void handleAfter(List triggerNew, Map triggerOldMap, boolean triggerIsInsert, boolean triggerIsUpdate) {

        List tasksToInsert = new List();
        
        for(Opportunity opp : triggerNew) {

            if(visitedOpportunityIds.contains(opp.Id)) {
            System.debug(LoggingLevel.Debug, 'OppTrg_MyProductIntegration.handleAfter skipping OpportunityId: ' + opp.Id + ' triggerIsInsert:' + triggerIsInsert + ' triggerIsUpdate:' + triggerIsUpdate);
            continue;
        } else {
            visitedOpportunityIds.add(opp.Id);
            System.debug(LoggingLevel.Debug, 'OppTrg_MyProductIntegration.handleAfter processing OpportunityId: ' + opp.Id + ' triggerIsInsert:' + triggerIsInsert + ' triggerIsUpdate:' + triggerIsUpdate);
        }

            // Do further processing using opp.Id
            boolean doStuff = triggerIsInsert;
            // If it's an update, check that certain fields have changed
            if(triggerIsUpdate) {
                Opportunity beforeUpdate = triggerOldMap.get(opp.Id);
                // We only need to do something if the Amount has changed
                doStuff = beforeUpdate.Amount != opp.Amount;
            }
            // Otherwise, if it's an insert, proceed with the additional processing
            
            System.debug(LoggingLevel.Info, 'OppTrg_MyProductIntegration doStuff:' + doStuff);
            if(doStuff) {
                //System.assertNotEquals(5000, opp.Amount, 'OppTrg_MyProductIntegration deliberate assertion failure doing stuff');
                Task mockTaskToIndicateStuffHappened = new Task();
                mockTaskToIndicateStuffHappened.WhatId = opp.Id;
             mockTaskToIndicateStuffHappened.Subject = 'Follow Up Test Task';
                tasksToInsert.add(mockTaskToIndicateStuffHappened);
                
            }

        }
        
        insert tasksToInsert;

    }
}

Now the fun begins. Users report that the desired functionality from the after insert trigger code isn't always occurring in production. The first step is to acquire the associated debug log to see what is going on.

Here is an extract from the DEBUG logging messages for the OppTrg_MyProductIntegration class when the assertion fails:

Time            Event            Info 1  Info 2   Message
14:16:31.573 DML_BEGIN  [26]  Op:Insert Type:Opportunity|Rows:1
14:16:31.714 USER_DEBUG  [15]  DEBUG  OppTrg_MyProductIntegration.handleAfter processing OpportunityId: 0067000000c7d3jAAA triggerIsInsert:false triggerIsUpdate:true
14:16:31.717 USER_DEBUG  [11]  DEBUG  OppTrg_MyProductIntegration.handleAfter skipping OpportunityId: 0067000000c7d3jAAA triggerIsInsert:true triggerIsUpdate:false
14:16:31.721 EXCEPTION_THROWN [29]   System.AssertException: Assertion Failed: Expected: 1, Actual: 0

Look closely at the messages, the after insert/update trigger called MyProduct_Opportunity first occurs for update, and secondly for insert. The record was updated before it was inserted!

What's really going on here? The extended debug log shows the cause.

Time            Event              In1  Info 2   Message
14:16:31.573 DML_BEGIN    [26] Op:Insert Type:Opportunity|Rows:1
14:16:31.600 CODE_UNIT_STARTED  [EX] 01q70000000TiLP DFB.OpportunityAfterInsertTest on Opportunity trigger event AfterInsert for [0067000000c7d3j]
14:16:31.601 SOQL_EXECUTE_BEGIN [17] Aggregations:0 SELECT Id FROM Opportunity WHERE Id IN :tmpVar1
14:16:31.604 SOQL_EXECUTE_END   [17] Rows:1
14:16:31.605 DML_BEGIN    [21] Op:Update Type:Opportunity|Rows:1
14:16:31.712 CODE_UNIT_STARTED  [EX] 01q70000000TiLK DFB.MyProduct_Opportunity on Opportunity trigger event AfterUpdate for [0067000000c7d3j]
14:16:31.714 USER_DEBUG    [15] DEBUG  OppTrg_MyProductIntegration.handleAfter processing OpportunityId: 0067000000c7d3jAAA triggerIsInsert:false triggerIsUpdate:true
14:16:31.714 USER_DEBUG    [28] INFO  OppTrg_MyProductIntegration doStuff:false
14:16:31.714 CODE_UNIT_FINISHED   DFB.MyProduct_Opportunity on Opportunity trigger event AfterUpdate for [0067000000c7d3j]
14:16:31.714 DML_END       [21]
14:16:31.717 USER_DEBUG    [11] DEBUG  OppTrg_MyProductIntegration.handleAfter skipping OpportunityId: 0067000000c7d3jAAA triggerIsInsert:true triggerIsUpdate:false
14:16:31.717 DML_END     [26]
14:16:31.717 SOQL_EXECUTE_BEGIN [28]   Aggregations:0 SELECT Id FROM Task WHERE WhatId = :tmpVar1
14:16:31.720 SOQL_EXECUTE_END   [28]   Rows:0
14:16:31.721 EXCEPTION_THROWN   [29]   System.AssertException: Assertion Failed: Expected: 1, Actual: 0

Going carefully through the log, there is another rogue after insert trigger in there that is resulting in an update on the record that was just inserted. This subsequent update causes our trigger of interest to execute first in an update context, before returning to execute for the original insert. The Set of processed Id's is tripping us up here. When the trigger first fires for update the ID isn't in the Set, so the fields are checked for a changed value. Being an update on another field the check doesn't pass, and the additional processing is skipped.

trigger OpportunityAfterInsertTest on Opportunity (after insert) {
     
    List toUpdate = new List();
    for(Opportunity opp : trigger.new) {
        if(opp.Description == 'Hello') {
            toUpdate.add(opp.Id);
        }
    }
    
    if(toUpdate.size() > 0) {
        List opps = [Select Id from Opportunity where Id in :toUpdate];
        for(Opportunity opp : opps) {
            opp.Description = 'World';    
        }  
        update opps; 
    }
}
@IsTest
public class OppTrg_MyProductIntegration_Test {

    @IsTest
    public static void StuffExpectedToHappen(){
        Opportunity opp = new Opportunity();
        opp.Name = 'Test';
        opp.Description = 'FooBar';
        opp.StageName = 'Closed Won';
        opp.CloseDate = DateTime.now().date();
        opp.Amount = 5000;
        insert opp;
        
        List tasksInsertedForNewOpp = [Select Id from Task where WhatId = :opp.Id];
        System.assertEquals(1, tasksInsertedForNewOpp.size());
    }
    
    @IsTest
    public static void WhyDidntStuffHappen(){
        Opportunity opp = new Opportunity();
        opp.Name = 'Test';
        opp.Description = 'Hello';
        opp.StageName = 'Closed Won';
        opp.CloseDate = DateTime.now().date();
        opp.Amount = 5000;
        insert opp;
        
        List tasksInsertedForNewOpp = [Select Id from Task where WhatId = :opp.Id];
        System.assertEquals(1, tasksInsertedForNewOpp.size());
    }
    
}

Which brings us back to the moral of the story, the only way to get predictable trigger ordering is to have one trigger per object type that passes off to other classes in a defined order. This is sometimes easier said than done. Multiple managed packages can all introduce their own set of triggers.

It terms of fixing the example triggers above, we can assume that the action should always occur in a trigger context. Basically bypass the Set check unless it is an update operation.

See also:

No comments:

Post a Comment