Why incorrect value is populated on "metric_instance" record? - Support and Troubleshooting

Why incorrect value is populated on "metric_instance" record? Issue  Intermittently, an incorrect value is being populated on a metric_instance record.

For example, let's say we have a "metric_definition" defined for the "Assignment Group" field on the incident table.

As per this "metric_definition", when there is a change with the "Assignment Group" field on an incident record, the system should create a new "metric_instance" record with the new value of the "Assignment Group" field.

When the "Assignment Group" value is changed from "Group A" to "Group B", the newly created "metric_instance" record should have a value as "Group B". However, intermittently, the "metric_instance" record was created with the old value "Group A" instead of "Group B".

This article will brief on the possible reason for this incorrect behavior of the system.

Release Any supported release.

Cause Cause 1: "metric events" before insert/update business rule is not executing as the last one before committing DB update

The out of the box provided "metric events" before insert/update business rule is set to run just before the database insert/update is being made on task record. This is done via setting the order as "10,000".

However, if there are any other custom before insert/update business rule set up on task table with order as "10,000" or higher and if that takes longer time to execute ( for example longer than 3 seconds), the metric records would have been created before the actual insert/update are being fired on database level.

Hence, the newly created metric instance record would have incorrect value. For example, "Group A" instead of "Group B".

Cause 2: Delay with the DB update due to DB performance issue

Ideally DB updates on task table would be completed in milli seconds and hence there will not be much time difference between the metric events business rule invoked (metric instance creation time) and actual DB update, it will be almost same time. Thus the metric instance record would be populated with the latest value which was committed to DB.

However, there are situations, where the DB update might take longer time to complete the update as shown below,

2018-09-10 11:12:28 (745) http-15 New transaction 70A77BC09860238018D4CB465AF2BA7F #12482810 /incident.do

2018-09-10 11:12:28 (752) Default-thread-113 70A77BC09860238018D4CB465AF2BA7F #12482810 /incident.do Parameters -------------------------

...

activity_filter.cmdb_ci=

sys_action=next_state_qualified

sys_display.u_change_ticketing.u_template=

activity_filter.u_third_party_caller=

..

2018-09-10 11:12:28 (752) Default-thread-113 70A77BC09860238018D4CB465AF2BA7F *** Start #12482810 /incident.do, user:

2018-09-10 11:12:29 (694) http-42 New transaction 70A77BC09860238018D4CB465AF2BA7F #12482818 /xmlhttp.do

2018-09-10 11:12:43 (884) http-26 70A77BC09860238018D4CB465AF2BA7F /cancel_my_transaction.do -- transaction time: 0:00:00.000

2018-09-10 11:12:45 (773) http-44 70A77BC09860238018D4CB465AF2BA7F /cancel_my_transaction.do -- transaction time: 0:00:00.000

2018-09-10 11:12:47 (898) http-32 70A77BC09860238018D4CB465AF2BA7F /cancel_my_transaction.do -- transaction time: 0:00:00.000

2018-09-10 11:12:49 (987) http-30 70A77BC09860238018D4CB465AF2BA7F /cancel_my_transaction.do -- transaction time: 0:00:00.000

2018-09-10 11:12:52 (109) http-10 70A77BC09860238018D4CB465AF2BA7F /cancel_my_transaction.do -- transaction time: 0:00:00.000

2018-09-10 11:12:54 (207) http-2 70A77BC09860238018D4CB465AF2BA7F /cancel_my_transaction.do -- transaction time: 0:00:00.000

2018-09-10 11:12:54 (350) Default-thread-113 70A77BC09860238018D4CB465AF2BA7F Time: 0:00:25.425 id: sndb[glide.0] for: UPDATE task SET `sys_updated_by` = ' ', `a_flt_3` = 0.5, `sys_mod_count` = 8, `a_flt_1` = 0.5, `sys_updated_on` = '2018-09-10 09:12:28', `state` = -9, `a_ref_6` = ' ', `topic` = '0.50', `reject_handling` = '0.50', `a_ref_7` = ' ' WHERE task.`sys_id` = ' ' You can see in the above logs that DB update took 25.425 seconds, during that time, possibly metrics instance records would be created, it will not wait for the update to complete. Hence, in such situations, metric instance record would be created with wrong value. Resolution Make sure the "Metrics event" business rule is the last before insert/update business rule to run just before firing insert/update on database level.

This can be achieved via setting highest order to "Metrics event" business rule than any other "before insert/update business rule" on task table.

If you are running into the issue, due to DB performance issue, please align with service now performance / DBA to identify the cause of performance issue and fix it.