How many times a trigger is fired when a record is updated?

Question

Could someone explain me how many times a single trigger is fired when a single record is updated? I cannot paste the whole debug log because of it's size this is just a part of it.

12:35:37.830 (28830076751)|CODE_UNIT_STARTED|[EXTERNAL]|01qt000000001NS|SoM_RequestComplete on SoM_Request trigger event AfterUpdate|__sfdc_trigger/SoM_RequestComplete
12:35:37.830 (28830114625)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:8
12:35:37.830 (28830124547)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:8
12:35:37.830 (28830152111)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:4
12:35:37.830 (28830160112)|VARIABLE_SCOPE_BEGIN|[1]|this|SoM_RequestComplete|true|false
12:35:37.830 (28830185850)|VARIABLE_ASSIGNMENT|[1]|this|{}|0x438382e5
12:35:37.830 (28830223024)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:4
12:35:37.830 (28830232730)|VARIABLE_SCOPE_BEGIN|[1]|this|SoM_RequestComplete|true|false
12:35:37.830 (28830249132)|VARIABLE_ASSIGNMENT|[1]|this|{}|0x438382e5
12:35:37.830 (28830258330)|STATEMENT_EXECUTE|[1]
12:35:37.830 (28830272527)|STATEMENT_EXECUTE|[4]
12:35:37.830 (28830279310)|STATEMENT_EXECUTE|[5]
12:35:37.830 (28830294526)|HEAP_ALLOCATE|[5]|Bytes:4
12:35:37.830 (28830322526)|VARIABLE_SCOPE_BEGIN|[5]|completeRequest|Set<Id>|true|false
12:35:37.830 (28830359021)|VARIABLE_ASSIGNMENT|[5]|completeRequest|[]|0x14d58fa2
12:35:37.830 (28830367543)|STATEMENT_EXECUTE|[6]
12:35:37.830 (28830380611)|HEAP_ALLOCATE|[6]|Bytes:4
12:35:37.830 (28830399220)|VARIABLE_SCOPE_BEGIN|[6]|holdId|List<Id>|true|false
12:35:37.830 (28830431330)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:4
12:35:37.830 (28830444196)|VARIABLE_ASSIGNMENT|[6]|holdId|[]|0x321af56f
12:35:37.830 (28830450872)|STATEMENT_EXECUTE|[7]
12:35:37.830 (28830465943)|HEAP_ALLOCATE|[7]|Bytes:4
12:35:37.830 (28830478041)|VARIABLE_SCOPE_BEGIN|[7]|completedTruckDecalReqs|Map<Id,SoM_Request__c>|true|false
12:35:37.830 (28830500275)|VARIABLE_ASSIGNMENT|[7]|completedTruckDecalReqs|{}|0x31609b7
12:35:37.830 (28830547737)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:8
12:35:37.830 (28830561015)|HEAP_ALLOCATE|[8]|Bytes:8
12:35:37.830 (28830591157)|HEAP_ALLOCATE|[8]|Bytes:5
12:35:37.830 (28830614573)|VARIABLE_SCOPE_BEGIN|[8]|req|SoM_Request__c|true|false
12:35:37.830 (28831303143)|VARIABLE_ASSIGNMENT|[8]|req|{"SoM_Priority__c":true,"SoM_Conditional_Reviews_Complete__c":false,"LastModifiedDate":"2018-12-13T17:35:37.000Z","SoM_Days_on_Hold__c":0,"SOM_Total_Balance__c":0.00,"Item_Requested_Detail__c":"TRANSFER OWNERSHIP 2 (236 more) ...","Name":"RQ-1803-03335","SoM_Existing_License_Inspection__c":true,"SoM_Applicant_Name__c":" ","Current_LGU_Population__c":14674,"SoM_Account_ID__c":"001t000000BK7Ub","CreatedById":"005t0000000lUPAAA2","Dishonored_Payment_in_less_tha_36_months__c":true,"Trucks_for_Fee__c":0,"SOM_Total_Payments__c":2897.65,"SoM_Days_Clock_Ran__c":179,"IsDeleted":false,"SoM_Completed_Date__c":"2018-12-13T00:00:00.000Z","SoM_Clock_Exceeded__c":true,"Issued_Number__c":"03335","SoM_Clock_Update__c":false,"SoM_Received_Date__c":"2018-03-16T00:00:00.000Z","SoM_Clock_Status__c":"Not Started","SoM_Total_Days__c":0,"Launch_Review_Process__c":false,"CreatedDate":"2018-03-20T15:21:17.000Z","Id":"a2Nt00000009YkVEAU","SoM_Account_Name__c":"001t000000BK7UbAAL","SoM_Special_License_Request__c":false,"SoM_Items_Requested__c":"Transfer Ownership ( (59 more) ...","Completed_Clock_Request_Transactions__c":0,"OwnerId":"00Gt0000000J3hbEAC","Conditional_Request__c":true,"RecordTypeId":"012t00000004HuaAAE","SoM_Status__c":"Complete","SoM_Business_ID__c":"0260399","SoM_Additional_Records_in_APEX__c":false,"SoM_Business_County__c":"GR TRAVERSE","SoM_Current_LGU_Account__c":"TRAVERSE CITY","SoM_Church_or_School_Invest_Required__c":false,"Confirm_Complete_Request__c":true,"Is_Portal__c":false,"SystemModstamp":"2018-12-13T17:35:37.000Z","SoM_Requires_Inspection__c":false,"Override_and_Launch_Review_Workflow__c":false,"SOM_Total_Fees__c":2897.65,"Request_ID__c":"R-2353586","SoM_Last_Start_Date__c":"2018-04-04T14:58:44.000Z","LastActivityDate":"2018-04-12T00:00:00.000Z","SoM_Free_Money_Applied__c":false,"SoM_Initials__c":"SG","SoM_Type__c":"Transfer Ownership ( (38 more) ...","SoM_Free_Money__c":false,"SoM_Days_in_Review__c":0,"SOM_Historical__c":false,"LastModifiedById":"005t00000015RAWAA2","Request_Number__c":"_HL_ENCODED_../a2Nt0 (42 more) ..."}|0x73e48ca3
12:35:37.830 (28831345433)|STATEMENT_EXECUTE|[9]
12:35:37.830 (28831411214)|STATEMENT_EXECUTE|[10]
12:35:37.830 (28831426927)|HEAP_ALLOCATE|[8]|Bytes:5
12:35:37.830 (28831447399)|VARIABLE_ASSIGNMENT|[8]|req|null|
12:35:37.830 (28831465246)|STATEMENT_EXECUTE|[19]
12:35:37.830 (28831476591)|STATEMENT_EXECUTE|[22]
12:35:37.831 (28831484811)|CUMULATIVE_LIMIT_USAGE
12:35:37.831 (28831484811)|LIMIT_USAGE_FOR_NS|(default)|
  Number of SOQL queries: 94 out of 100 ******* CLOSE TO LIMIT
  Number of query rows: 279 out of 50000
  Number of SOSL queries: 0 out of 20
  Number of DML statements: 32 out of 150
  Number of DML rows: 54 out of 10000
  Maximum CPU time: 8267 out of 10000 ******* CLOSE TO LIMIT
  Maximum heap size: 0 out of 6000000
  Number of callouts: 0 out of 100
  Number of Email Invocations: 0 out of 10
  Number of future calls: 0 out of 50
  Number of queueable jobs added to the queue: 0 out of 50
  Number of Mobile Apex push calls: 0 out of 10

If you look at the trigger (SoM_RequestComplete) in the log , it is called 9 times!! And there other triggers in a similar way called multiple times. What's happening here functionally is.. a checkbox on child record is updating two fields on parent record, there are other triggers which are fired based on those fields on parent record.

Answer 1

A single trigger can run many times in a single transaction. This might occur because of workflow field updates, Process Builder flows, triggers that recursively update records, and particularly for batches of records greater than 100 or 200, depending on API version, as well as using AllOrNone=false on DML operations of more than 1 row.

Since there are different causes, there are different solutions to the problem, which mostly involve using asynchronous code to delay some of the business logic for later, checking to see if records have already been processed (a "recursion blocker", as developers tend to call it), optimizing/streamlining code so that fewer DML updates occur, avoiding mixing code and configuration field updates (e.g. avoid using triggers on objects that have workflow field updates/Process flows), using before insert/before update triggers when possible to avoid recursive updates, and perhaps a few other tricks I haven't immediately thought of.

You might want to try using the Apex Replay Debugger if you want to step through your logs and figure out what happened (note: just install the entire Salesforce Extension Pack for a whole set of cool features), or you can use the Developer Console to look at the log using the graphical environment (turn on the "timeline" feature to see how the execution looks, and the "execution stack" feature to see how the methods/triggers were called). Debugging this situation is going to take a bit of time, but the tools you need are there.

Answer 2

If you have a workflow field update, the tigger is fired again. Refer to the below excerpt from Triggers and Order of Execution (emphasis mine):

If the record was updated with workflow field updates, fires before update triggers and after update triggers one more time (and only one more time), in addition to standard validations. Custom validation rules, duplicate rules, and escalation rules are not run again.

You may be getting confused with the name of the trigger in the log. Having the name of the trigger does not mean that it's fired those many times. It just mentions the context in which the trigger is getting executed, e.g., variable assignment, heap allocation, etc.

Also note the below mention, that this applies to any type of operation:

The refiring of triggers isn't limited to updates, but applies to all operation types. A workflow field update that fires on record insert will rerun any before and after insert triggers again—as insert triggers.

Answer 3

The trigger should be fired only one time for the update made. That said, I have seen several times in my own code where a trigger is fired that updates a record, which in turn causes some other automation to fire. This can sometimes lead to a chain of updates that in turn update the same type of object again in addition to the one that causes the initial fire of the trigger. My understanding is that this can then lead to the trigger being fired multiple times for a single update, though I have only every seen the trigger fire a second time personally.

My recommendation, and the one I received on a similar question previously Here, is to start shoving System.debug messages everywhere in your code and then tracing back through the logs to see what is happening at what time. I'd also strongly recommend filter the logs by debug messages only when doing this process as it is far more readable than seeing the full log dump.