Workflows: Not an issue due to data or setup? You need a Timer

[christopher_tho]

Workflows can be very complex and complicated. Sometimes, workflows can even be a little unpredictable, even on occasion, they just don't seem to work right. In most cases when there is an issue with a workflow, it's usually two things:

1. A data issue
2. The workflow is not setup right.

If it does happen to be one of these two things, you can start to troubleshoot by checking the Workflow Validation process. There is a third "nugget" that could be causing you some grief, and that is timing. Sometimes, the workflow may not be reading in the most "current" information, and thus it doesn't behave as you might expect. When this situation occurs, the best solution you will come across is to add a Timer.

Now, while there are some good descriptions and definitions that describe Timer activity in workflows, there doesn't seem to be much that explains exactly HOW this Timer activity works on the instance and WHY this can work as a possible workaround for these timing issues. For basic details on this Timer activity see Using Workflow Timer Activity & SLA Percentage Timer and Timer activities.

I will walk you through a simple timing issue scenario with a Workflow and how this type of issue can occur, and then we'll see how adding a Timer can help to address this situation and why this works. We will go about this by:

1. Setting up an example workflow
2. Encountering the workflow issue
3. Applying the Timer to the workflow

Setting up an example workflow

First, we need to setup a demo workflow to demonstrate a timing issue scenario. I have actually attached a ZIP file with all the necessary files that you can import to test this out with (from a Helsinki version), or you can always create this on your own.

NOTE: This workflow is assuming some "default" values for fields like "state", so if on your instance you have modified these default values, then this behavior may not work as expected when using the provided files.

First, there is a record called "workflow_no_timer.xml". This contains the workflow and all the activities to demonstrate the first part of this issue.

This workflow will contain the following activities in this order.

1. Begin
2. Run Script

           Name: Set Request to Work in Progress

           Script:

           --------------------------------------------------------

           var id = current.request.sys_id;

           var req = new GlideRecord('sc_request');

           req.get(id);

           req.state = '2';

           req.update();

           --------------------------------------------------------

3. Wait for Condition

           Name: Wait for State = Work In Progress

           Condition: State…is…Work in Progress

4. End

Second, there is a Business Rule called "Change RITM to WIP" that contains the following values.

        Name: Change RITM to WIP

        Table: Request [sc_request]

        When: after

        Order: 100

        Filter Condition: State….changes to….Work in Progress

        Script:

        ----------------------------------------------------------------------------------------

        (function executeRule(current, previous /*null when async*/) {

                      var item = new GlideRecord('sc_req_item');

                      item.addQuery('request', current.sys_id);

                      item.query();

                      while (item.next()) {

                                              item.state = '2';

                                              item.update();

                      }                    

        })(current, previous);

        ----------------------------------------------------------------------------------------

Finally, there are a couple of other Business Rules you can import as well, although those are just for debugging purposes and I will explain on those later.

All you need to then do, once you import these files, is to link this Workflow to a Catalog Item of your choice (in my example, I used the OOB "Apple iPad 3" Item) and then order the Item via the Service Catalog and see what happens.

Encountering the workflow issue

Now, based on this Workflow, this Business Rule, and how a Request and Requested Item ordering process works (See Which came first, the Request or the Requested Item? for more details about this process), this is the following behavior you may expect.

1. After ordering the Item, the Request record will go through its process to get Approved.
   1. In my example, it just gets "auto-approved" via the default Service Catalog Request workflow.
2. Once that happens and we start running this "Test Workflow" against the Requested Item, we will reach this "Set Request to Work in Progress" Activity, which will update the parent Request record linked to this Requested Item to set the state to "2" (Work in Progress)
3. While that update occurs, this "Change RITM to WIP" Business Rule will get called and it will in turn update this Requested Item record to set its state to "2" (Work in Progress) as well.

What we would expect now is that the workflow should then proceed to this "Wait for State = Work In Progress" activity and it should see that the State has been updated to "Work In Progress" on the Requested Item record (based on the Business Rule being ran just previously), and then we should proceed to the end of the workflow.

As you should probably guess, this is not what occurs. Everything up to step 3 does exactly what it is supposed to do; however, as you can see in this screenshot below, the workflow stalls at this "Wait for Condition" activity.

This happens even though if you go open the Requested Item record, you will see that this has been updated to "Work in Progress".

The main reason this is occurring has to do with how the workflow is pulling a reference to the record it is tied to (in this case the RITM record) and when it sees (or doesn't see) updates that are being made to this record as this workflow is running. We can see this, for example, if we add some debugging (via Business rules) which I have also included in the attachment in this article as well (see "State Before Workflow" and "State After Workflow").

For example, after Step 1 has been completed above and we are starting to run this "Test Workflow," the workflow at this time will pull a reference to the "current" record with whatever values are set on that record at that time.

By default, a Requested Item when first opened is set with the state = 1 (Open). We can see this based on this first log entry below from the "State Before Workflow" Business Rule.

11:52:11.677: Execute before update business rules on sc_req_item:RITM0010017 before engines (order <1000)

11:52:11.678: Global           ==> 'State Before Workflow' on sc_req_item:RITM0010017

11:52:11.678: : State Before Workflow: State is: Open

11:52:11.680: Global           <== 'State Before Workflow' on sc_req_item:RITM0010017

Then, we will see the "Test Workflow" will get started (based on the "Start Workflow" Business Rule) and will reach the "Set Request to Work in Progress" activity.

11:52:11.692: Global ==> 'Start Workflow' on sc_req_item:RITM0010017

11:52:11.747: Execute before insert business rules on wf_context:Test Workflow before engines (order <1000)

11:52:11.760: completed Begin(83d59cf0db24a2009b67f5131f9619d9): event=execute

As we progress through to update the Request record, and then also make the update on the RITM record, we see again the "State Before Workflow" Business Rule will fire, only this time the State is now changed to "2" (Work in Progress).

11:52:11.817: Execute before update business rules on sc_request:REQ0010014 after engines (order >=1000)

11:52:11.854: Global ==> 'Change RITM to WIP' on sc_request:REQ0010014

11:52:11.860: Global ==> 'State Before Workflow' on sc_req_item:RITM0010017

11:52:11.861: : State Before Workflow: State is: Work in Progress

11:52:11.865: Global <== 'State Before Workflow' on sc_req_item:RITM0010017

At this point, you may expect the Test Workflow to start again here, however, because the workflow is still running from before, nothing will happen in this particular update process.

So, instead we will see our "After" Business Rule get ran before then completing this "Set Request to Work in Progress" activity.

11:52:11.884: Global ==> 'State After Workflow' on sc_req_item:RITM0010017

11:52:11.885: : State After Workflow: State is: Work in Progress

11:52:11.890: Global <== 'State After Workflow' on sc_req_item:RITM0010017

11:52:12.263: completed Set Request to Work in Progress(b198d834db24a2009b67f5131f9619fc): event=execute

Next, we we proceed to the "Wait for State = Work In Progress" activity which then gets "completed", however it doesn't proceed to the "End" activity.

11:52:12.314: completed Wait for State = Work In Progress(83d59cf0db24a2009b67f5131f9619da): event=execute

Instead, we see that this ends the entire process as per the "Start Workflow" activity, and then when we run our "State After Workflow" Business Rule here, because this correlates to the state of the record prior to running this Business Rule, we will see that this shows the state still being at "Open".

11:52:12.402: Global <== 'Start Workflow' on sc_req_item:RITM0010017

11:52:12.402: Global           ==> 'State After Workflow' on sc_req_item:RITM0010017

11:52:12.402: : State After Workflow: State is: Open

11:52:12.404: Global           <== 'State After Workflow' on sc_req_item:RITM0010017

At this point, you may think that the "Wait for Condition" activity should have queried the current version of the RITM record that had its State value updated to "Work in Progress", however instead, it was actually still referencing the version that it originally pulled prior to when workflow was started, which still had State as "Open".

While I'm not exactly sure why this was setup this way, my assumption is that to avoid having to make multiple queries to the current GlideRecord during the execution of a workflow process, it was decided to pull a reference to the "current' record at the beginning of starting this process, and then only reference the values from this referenced copy throughout the update of the workflow, even if there are Business Rules or other scripts in the background that are trying to update this record simultaneously.

I will add that if you have an activity like a "Set Values" activity that does make an update to the current record during an update process, when you proceed to the next activity, this will get reflected if you are trying to query for this value. This is likely because there is a process from the "Set Values" activity to make sure this value gets saved and referenced prior to running the next activity.

In this example, the updated State value from running this "Change RITM to WIP" Business Rule will end up saving and sticking to this record, hence why you still see the State updated to "Work in Progress" on the RITM record itself, even though the workflow didn't see it that way at the particular moment we were referencing it.

So, overall, I hope this helps to explain and understand this potential issue, as this may be a scenario you may run into when trying to correlate updates with different records during a workflow process.

Applying the Timer to the workflow

Being that this is a very trivial workflow, it's obvious that there are different ways to be able to fix this particular issue (for example, the workflow should probably just update the State to "Work in Progress" directly via a Set Values activity in the workflow).

For arguments sake (and because in a real-life scenario, your workflows may be much more complex and intricate to where a simple fix like this may not be applicable), let's assume we have to keep this process in place.

My only other suggestion to help address this would be to add a Timer in between the "Run Script" and "Wait for Condition" activities, like such.

This Timer can be set to as little as 1 second, but that doesn't necessarily mean that it will always be ran in 1 second, and I will explain on that shortly.

Now, what we will end up seeing when running through this test with this Timer in place is that the steps and process will pretty much be the same as when we ran this previously, however now with the Timer in place, if you go and check the workflow once all the activities have been ran, you will see here that the workflow has proceeded past this Wait for Condition activity as expected.

So, how exactly did adding this Timer activity help to address this issue? Well, the first thing to understand is what exactly does this Timer activity do?

Once this Timer activity is called in the Workflow, this actually creates a Scheduled job in the sys_trigger table that will have a name like "WFTimerxxxxxxxx".

You can see this if you were to increase the Timer to a value like "1 minute," then while this Workflow and Timer are running, go to the sys_trigger table and search for this "WFTimer" record.

The characters that are after the "WFTimer" in the name actually reference the wf_executing_activity record that created this timer in your workflow.

Now, when I mentioned earlier about that even though you set this for 1 second, it may actually take longer than that for this to actually be ran, this is because as with most jobs in the sys_trigger table, it is dependent on when the "events process" Scheduled job is ran to check to run this "WFTimer" job, and also if you have potentially have a backlog of other jobs that are taking a long time to run, it may get queued up as well.

In Diagnosing and remedying stuck event processes it explains diagnosing Event Processing issues if you ever run into this situation of events not processing in a timely manner on your instance.

Once this Timer Scheduled job is ran from the sys_trigger table, it will then call an update to complete the "Timer" activity in the workflow and proceed to the next activity. Meanwhile, from the Workflow perspective, as mentioned before, when we start the workflow, we pull in the "current" version of the RITM record to reference as we run through this workflow.

Before, this was the version we referenced throughout this example ordering process, even as we reached the "Wait for Condition" activity. Now, with having this Timer in place, this actually stops the process of the Workflow at this Timer activity, which then allows the Requested Item record to get its State value updated to "Work in Progress" after running the "Set Request to Work in Progress" activity.

Once the Timer is complete and we start back up the Workflow, since this is now considered as a "new" update, the Workflow at this time will now grab the "current" version of the RITM record at this moment, and in this reference, it will see the State as "Work in Progress".

When we then reach the "Wait for Condition" activity, we now see that the State is set to this value and we will then proceed to the End as expected.

----------------------------------------------------------------

Overall, using this "Timer" workaround should only be considered as a last resort if there is no other option to implement your current setup. In the rare cases where you may need this type of behavior to occur, this is an option that is available and can be useful.

Workflow No Timer Example.zip