Pages

Sunday, March 27, 2016

Salesforce: using Debug Log to Troubleshoot Workflow

Workflow is the most favorite tool available for Salesforce admin for automation (before Process Builder born), even after Process Builder available, workflow still favorite by Salesforce admin because of the simplicity. However, when you have a lot of workflows in the same object, sometimes it become too complex to troubleshoot when workflow do not action as it suppose to.

One of the easiest option to troubleshoot workflow is using Debug Log, navigate to Setup | LogsDebug Logs. You need to define Traced Entity (in this case, select User), Start Date Time, Expiration Date Time, and Debug Level (choose finest).

Once a record is create or update, refresh the debug log and notice new log is added. Here are few samples with debug log detail:


1. One workflow and criteria no match
 36.0 APEX_CODE,NONE;APEX_PROFILING,NONE;CALLOUT,NONE;DB,NONE;SYSTEM,NONE;VALIDATION,NONE;VISUALFORCE,NONE;WORKFLOW,FINEST  
 06:54:11.0 (490818)|EXECUTION_STARTED  
 06:54:11.0 (532130)|CODE_UNIT_STARTED|[EXTERNAL]|Workflow:Account  
 06:54:11.0 (10666652)|WF_RULE_EVAL_BEGIN|Workflow  
 06:54:11.0 (10710163)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|Type = Prospect|01Q28000000DuoK|ON_ALL_CHANGES|0  
 06:54:11.0 (14983111)|WF_RULE_FILTER|[Account : Type equals Prospect]  
 06:54:11.0 (15020276)|WF_RULE_EVAL_VALUE|  
 06:54:11.0 (15044369)|WF_CRITERIA_END|false  
 06:54:11.0 (15062046)|WF_SPOOL_ACTION_BEGIN|Workflow  
 06:54:11.0 (15074132)|WF_ACTION| None  
 06:54:11.0 (15079771)|WF_RULE_EVAL_END  
 06:54:11.0 (15121739)|WF_ACTIONS_END| None  
 06:54:11.0 (15134839)|CODE_UNIT_FINISHED|Workflow:Account  
 06:54:11.0 (15144558)|EXECUTION_FINISHED  
Color coded:
YELLOW background: start and end of workflow
GREEN background: start and end of workflow action
LIGHT YELLOW background: range of one workflow
DARK GREEN background: list of actions
PURPLE text: record Id
BLUE text: workflow Id
RED text: workflow rule criteria match


2. One workflow and criteria match
 36.0 APEX_CODE,NONE;APEX_PROFILING,NONE;CALLOUT,NONE;DB,NONE;SYSTEM,NONE;VALIDATION,NONE;VISUALFORCE,NONE;WORKFLOW,FINEST  
 07:00:42.0 (494258)|EXECUTION_STARTED  
 07:00:42.0 (530411)|CODE_UNIT_STARTED|[EXTERNAL]|Workflow:Account  
 07:00:42.0 (17812902)|WF_RULE_EVAL_BEGIN|Workflow  
 07:00:42.0 (17921019)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|website blank|01Q28000000DuoP|ON_ALL_CHANGES|0  
 07:00:42.0 (22442943)|WF_RULE_FILTER|[Account : Website equals ]  
 07:00:42.0 (22533614)|WF_RULE_EVAL_VALUE|  
 07:00:42.0 (22559049)|WF_CRITERIA_END|true  
 07:00:42.0 (36720479)|WF_SPOOL_ACTION_BEGIN|Workflow  
 07:00:42.0 (47993268)|WF_RULE_INVOCATION|[Account: Ke 1 0012800000UXMjh]  
 07:00:42.0 (48084821)|WF_ACTION_TASK|Task:Remember|Id=01V280000000CKK|CurrentRule:website blank (Id=01Q28000000DuoP)|AssignedTo:Admin Playground|DueDate:Sun Apr 03 00:00:00 GMT 2016  
 07:00:42.0 (48374884)|WF_ACTION| Task: 1;  
 07:00:42.0 (48380808)|WF_RULE_EVAL_END  
 07:00:42.0 (263328067)|WF_ACTIONS_END| Task: 1;  
 07:00:42.0 (263343578)|CODE_UNIT_FINISHED|Workflow:Account  
 07:00:42.0 (263350475)|EXECUTION_FINISHED  
Additional color coded:
FUCHSIA text: Task action Id
ORANGE text: all actions


3. Two active workflows; only one criteria match: create task
 36.0 APEX_CODE,NONE;APEX_PROFILING,NONE;CALLOUT,NONE;DB,NONE;SYSTEM,NONE;VALIDATION,NONE;VISUALFORCE,NONE;WORKFLOW,FINEST  
 07:02:14.0 (78956)|EXECUTION_STARTED  
 07:02:14.0 (125619)|CODE_UNIT_STARTED|[EXTERNAL]|Workflow:Account  
 07:02:14.0 (24545463)|WF_RULE_EVAL_BEGIN|Workflow  
 07:02:14.0 (24621836)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|Type = Prospect|01Q28000000DuoK|ON_ALL_CHANGES|0  
 07:02:14.0 (30423437)|WF_RULE_FILTER|[Account : Type equals Prospect]  
 07:02:14.0 (30448452)|WF_RULE_EVAL_VALUE|  
 07:02:14.0 (30456367)|WF_CRITERIA_END|false  
 07:02:14.0 (30476927)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|website blank|01Q28000000DuoP|ON_ALL_CHANGES|0  
 07:02:14.0 (30511143)|WF_RULE_FILTER|[Account : Website equals ]  
 07:02:14.0 (30524283)|WF_RULE_EVAL_VALUE|  
 07:02:14.0 (30529957)|WF_CRITERIA_END|true  
 07:02:14.0 (47469103)|WF_SPOOL_ACTION_BEGIN|Workflow  
 07:02:14.0 (50377861)|WF_RULE_INVOCATION|[Account: Ke 1 0012800000UXMjh]  
 07:02:14.0 (50473276)|WF_ACTION_TASK|Task:Remember|Id=01V280000000CKK|CurrentRule:website blank (Id=01Q28000000DuoP)|AssignedTo:Admin Playground|DueDate:Sun Apr 03 00:00:00 GMT 2016  
 07:02:14.0 (50502200)|WF_ACTION| Task: 1;  
 07:02:14.0 (50508567)|WF_RULE_EVAL_END  
 07:02:14.0 (102090292)|WF_ACTIONS_END| Task: 1;  
 07:02:14.0 (102112660)|CODE_UNIT_FINISHED|Workflow:Account  
 07:02:14.0 (102122130)|EXECUTION_FINISHED  
Additional color coded:
GREEN text: second workflow
LIGHT BLUE background: second range workflow
DARK GREEN background: Create Task action


4. Two active workflows; both criteria match: create task & field update
 36.0 APEX_CODE,NONE;APEX_PROFILING,NONE;CALLOUT,NONE;DB,NONE;SYSTEM,NONE;VALIDATION,NONE;VISUALFORCE,NONE;WORKFLOW,FINEST  
 07:06:23.0 (571061)|EXECUTION_STARTED  
 07:06:23.0 (614080)|CODE_UNIT_STARTED|[EXTERNAL]|Workflow:Account  
 07:06:23.0 (13270473)|WF_RULE_EVAL_BEGIN|Workflow  
 07:06:23.0 (13555244)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|Type = Prospect|01Q28000000DuoK|ON_ALL_CHANGES|0  
 07:06:23.0 (17599518)|WF_RULE_FILTER|[Account : Type equals Prospect]  
 07:06:23.0 (17747778)|WF_RULE_EVAL_VALUE|Prospect  
 07:06:23.0 (17833551)|WF_CRITERIA_END|true  
 07:06:23.0 (18589437)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|website blank|01Q28000000DuoP|ON_ALL_CHANGES|0  
 07:06:23.0 (18681542)|WF_RULE_FILTER|[Account : Website equals ]  
 07:06:23.0 (18760950)|WF_RULE_EVAL_VALUE|  
 07:06:23.0 (18767696)|WF_CRITERIA_END|true  
 07:06:23.0 (18860608)|WF_SPOOL_ACTION_BEGIN|Workflow  
 07:06:23.0 (19151790)|WF_FIELD_UPDATE|[Account: Ke 1 0012800000UXMjh]|Field:Account: Description|Value:2016-03-26 23:06:23Z|Id=04Y280000009Poy|CurrentRule:Type = Prospect (Id=01Q28000000DuoK)  
 07:06:23.0 (21694421)|WF_RULE_INVOCATION|[Account: Ke 1 0012800000UXMjh]  
 07:06:23.0 (21797283)|WF_ACTION_TASK|Task:Remember|Id=01V280000000CKK|CurrentRule:website blank (Id=01Q28000000DuoP)|AssignedTo:Admin Playground|DueDate:Sun Apr 03 00:00:00 GMT 2016  
 07:06:23.0 (21879044)|WF_ACTION| Field Update: 1; Task: 1;  
 07:06:23.0 (21929815)|WF_RULE_EVAL_END  
 07:06:23.0 (75368022)|WF_ACTIONS_END| Field Update: 1; Task: 1;  
 07:06:23.0 (75384504)|CODE_UNIT_FINISHED|Workflow:Account  
 07:06:23.0 (75390586)|EXECUTION_FINISHED  
Additional color coded:
LIGHT PINK background: Field Update action

Lesson learn from this scenario:




5. One active workflows - no criteria match; one inactive workflow
 36.0 APEX_CODE,NONE;APEX_PROFILING,NONE;CALLOUT,NONE;DB,NONE;SYSTEM,NONE;VALIDATION,NONE;VISUALFORCE,NONE;WORKFLOW,FINEST  
 07:12:20.0 (607207)|EXECUTION_STARTED  
 07:12:20.0 (677793)|CODE_UNIT_STARTED|[EXTERNAL]|Workflow:Account  
 07:12:20.0 (21667072)|WF_RULE_EVAL_BEGIN|Workflow  
 07:12:20.0 (22135772)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|website blank|01Q28000000DuoP|ON_ALL_CHANGES|0  
 07:12:20.0 (29783091)|WF_RULE_FILTER|[Account : Website equals ]  
 07:12:20.0 (29880114)|WF_RULE_EVAL_VALUE|www.aa.com  
 07:12:20.0 (29973169)|WF_CRITERIA_END|false  
 07:12:20.0 (30005156)|WF_SPOOL_ACTION_BEGIN|Workflow  
 07:12:20.0 (30068782)|WF_ACTION| None  
 07:12:20.0 (30120461)|WF_RULE_EVAL_END  
 07:12:20.0 (30246879)|WF_ACTIONS_END| None  
 07:12:20.0 (30260963)|CODE_UNIT_FINISHED|Workflow:Account  
 07:12:20.0 (30268055)|EXECUTION_FINISHED  

Lesson learn from this scenario: inactive workflow will not be evaluated at all.


6. Three
 active workflows; all criteria match: create task & field update & send email
 36.0 APEX_CODE,NONE;APEX_PROFILING,NONE;CALLOUT,NONE;DB,NONE;SYSTEM,NONE;VALIDATION,NONE;VISUALFORCE,NONE;WORKFLOW,FINEST  
 07:14:30.0 (98803)|EXECUTION_STARTED  
 07:14:30.0 (154441)|CODE_UNIT_STARTED|[EXTERNAL]|Workflow:Account  
 07:14:30.0 (16424626)|WF_RULE_EVAL_BEGIN|Workflow  
 07:14:30.0 (16495118)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|Type = Prospect|01Q28000000DuoK|ON_ALL_CHANGES|0  
 07:14:30.0 (20462863)|WF_RULE_FILTER|[Account : Type equals Prospect]  
 07:14:30.0 (20571360)|WF_RULE_EVAL_VALUE|Prospect  
 07:14:30.0 (20597483)|WF_CRITERIA_END|true  
 07:14:30.0 (36578619)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|website blank|01Q28000000DuoP|ON_ALL_CHANGES|0  
 07:14:30.0 (36681809)|WF_RULE_FILTER|[Account : Website equals ]  
 07:14:30.0 (36795290)|WF_RULE_EVAL_VALUE|  
 07:14:30.0 (36803418)|WF_CRITERIA_END|true  
 07:14:30.0 (36830368)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|Billing Country is Singapore|01Q28000000DuoU|ON_ALL_CHANGES|0  
 07:14:30.0 (36928167)|WF_RULE_FILTER|[Account : Billing Country equals Singapore]  
 07:14:30.0 (36951420)|WF_RULE_EVAL_VALUE|Singapore  
 07:14:30.0 (36955780)|WF_CRITERIA_END|true  
 07:14:30.0 (37008104)|WF_SPOOL_ACTION_BEGIN|Workflow  
 07:14:30.0 (37341627)|WF_FIELD_UPDATE|[Account: Ke 1 0012800000UXMjh]|Field:Account: Description|Value:2016-03-26 23:14:30Z|Id=04Y280000009Poy|CurrentRule:Type = Prospect (Id=01Q28000000DuoK)  
 07:14:30.0 (50320374)|WF_RULE_INVOCATION|[Account: Ke 1 0012800000UXMjh]  
 07:14:30.0 (50413236)|WF_ACTION_TASK|Task:Remember|Id=01V280000000CKK|CurrentRule:website blank (Id=01Q28000000DuoP)|AssignedTo:Admin Playground|DueDate:Sun Apr 03 00:00:00 GMT 2016  
 07:14:30.0 (50441107)|WF_RULE_INVOCATION|[Account: Ke 1 0012800000UXMjh]  
 07:14:30.0 (50459270)|WF_EMAIL_ALERT|Id=01W28000000CylZ|CurrentRule:Billing Country is Singapore (Id=01Q28000000DuoU)  
 07:14:30.0 (136184167)|WF_EMAIL_SENT|Template:00X28000001CeTV|Recipients:yujohan@gmail.com |CcEmails:  
 07:14:30.0 (136249507)|WF_ACTION| Field Update: 1; Task: 1; Email Alert: 1;  
 07:14:30.0 (136265700)|WF_RULE_EVAL_END  
 07:14:30.0 (195583761)|WF_ACTIONS_END| Field Update: 1; Task: 1; Email Alert: 1;  
 07:14:30.0 (195602601)|CODE_UNIT_FINISHED|Workflow:Account  
 07:14:30.0 (195609979)|EXECUTION_FINISHED  
Color coded:
BLACK bold text: Record Id
RED text: 1st workflow Id
BLUE text: 2nd workflow Id
FUCHSIA textL 3rd workflow Id
YELLOW background: 1st workflow action
GREEN background: 2nd workflow action
BLUE background: 3rd workflow action
GREEN background text: Field Update Id
CYAN background text: Email Alert Id
YELLOW background text: Email Alert Id


7. Workflow with formula evaluates to true
 36.0 APEX_CODE,NONE;APEX_PROFILING,NONE;CALLOUT,NONE;DB,NONE;SYSTEM,NONE;VALIDATION,NONE;VISUALFORCE,NONE;WORKFLOW,FINEST  
 09:57:09.0 (539007)|EXECUTION_STARTED  
 09:57:09.0 (578864)|CODE_UNIT_STARTED|[EXTERNAL]|Workflow:Account  
 09:57:09.0 (23452602)|WF_RULE_EVAL_BEGIN|Workflow  
 09:57:09.0 (23564561)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|Type = Prospect|01Q28000000DuoK|ON_ALL_CHANGES|0  
 09:57:09.0 (39215585)|WF_RULE_FILTER|[Account : Type equals Prospect]  
 09:57:09.0 (39316655)|WF_RULE_EVAL_VALUE|Prospect  
 09:57:09.0 (39344976)|WF_CRITERIA_END|true  
 09:57:09.0 (58619174)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|website blank formula|01Q28000000Duoj|ON_ALL_CHANGES|0  
 09:57:09.0 (59063797)|WF_FORMULA|Formula:ENCODED:[treatNullAsNull]ISBLANK({!ID:Website})|Values:Website=null  
 09:57:09.0 (59074730)|WF_CRITERIA_END|true  
 09:57:09.0 (59108389)|WF_CRITERIA_BEGIN|[Account: Ke 1 0012800000UXMjh]|Billing Country is Singapore|01Q28000000DuoU|ON_ALL_CHANGES|0  
 09:57:09.0 (59218244)|WF_RULE_FILTER|[Account : Billing Country equals Singapore]  
 09:57:09.0 (59255080)|WF_RULE_EVAL_VALUE|Singapore  
 09:57:09.0 (59260781)|WF_CRITERIA_END|true  
 09:57:09.0 (59301987)|WF_SPOOL_ACTION_BEGIN|Workflow  
 09:57:09.0 (59648416)|WF_FIELD_UPDATE|[Account: Ke 1 0012800000UXMjh]|Field:Account: Description|Value:2016-03-27 01:57:09Z|Id=04Y280000009Poy|CurrentRule:Type = Prospect (Id=01Q28000000DuoK)  
 09:57:09.0 (77261802)|WF_RULE_INVOCATION|[Account: Ke 1 0012800000UXMjh]  
 09:57:09.0 (77377441)|WF_ACTION_TASK|Task:Remember|Id=01V280000000CKK|CurrentRule:website blank formula (Id=01Q28000000Duoj)|AssignedTo:Admin Playground|DueDate:Sun Apr 03 00:00:00 GMT 2016  
 09:57:09.0 (77440859)|WF_RULE_INVOCATION|[Account: Ke 1 0012800000UXMjh]  
 09:57:09.0 (77461684)|WF_EMAIL_ALERT|Id=01W28000000CylZ|CurrentRule:Billing Country is Singapore (Id=01Q28000000DuoU)  
 09:57:09.0 (146795599)|WF_EMAIL_SENT|Template:00X28000001CeTV|Recipients:yujohan@gmail.com |CcEmails:  
 09:57:09.0 (146993665)|WF_ACTION| Field Update: 1; Task: 1; Email Alert: 1;  
 09:57:09.0 (147007835)|WF_RULE_EVAL_END  
 09:57:09.0 (212561460)|WF_ACTIONS_END| Field Update: 1; Task: 1; Email Alert: 1;  
 09:57:09.0 (212578852)|CODE_UNIT_FINISHED|Workflow:Account  
 09:57:09.0 (212586074)|EXECUTION_FINISHED  

All above samples before (7), we use criteria are met in the workflow rule criteria, but in (7), we use formula evaluates to true - note the difference in highlighted debug log above.



Reference: