[OpenSIPS-Devel] Statistics module concurrency issue

[Ben Newlin]

Hello,

We are seeing some failures that appear to be caused by the Statistics module not operating properly for concurrent execution. When a particular statistic is updated nearly simultaneously by multiple OpenSIPS threads, the statistic does not end up with the correct value; some of the updates appear to get overwritten.

The following log is output when the statistic “calls:Response|481” is updated simultaneously by 2 different threads. Each update is “+1”, but at the end of this execution the value of the statistic was queried and found to be only 1.

Apr 25 14:12:05 [323] DBG:tm:t_check: start=0x7fe936057450
Apr 25 14:12:05 [322] DBG:tm:t_check: start=0x7fe93605a570
Apr 25 14:12:05 [323] DBG:tm:t_check: transaction already found!
Apr 25 14:12:05 [322] DBG:tm:t_check: transaction already found!
Apr 25 14:12:05 [323] DBG:tm:pv_get_tm_reply_code: reply code is <481>
Apr 25 14:12:05 [322] DBG:tm:pv_get_tm_reply_code: reply code is <481>
Apr 25 14:12:05 [323] DBG:core:comp_scriptvar: int 20 : 5 / 0
Apr 25 14:12:05 [322] DBG:core:comp_scriptvar: int 20 : 5 / 0
Apr 25 14:12:05 [322] DBG:core:comp_scriptvar: str 20 : calls
Apr 25 14:12:05 [323] DBG:core:comp_scriptvar: str 20 : calls
Apr 25 14:12:05 [322] DBG:core:comp_scriptvar: int 20 : 12 / 0
Apr 25 14:12:05 [323] DBG:core:comp_scriptvar: int 20 : 12 / 0
Apr 25 14:12:05 [322] DBG:core:comp_scriptvar: str 20 : Response|481
Apr 25 14:12:05 [323] DBG:core:comp_scriptvar: str 20 : Response|481
Apr 25 14:12:05 [322] DBG:statistics:w_update_stat: needed statistic is <calls:Response|481>
Apr 25 14:12:05 [323] DBG:statistics:w_update_stat: needed statistic is <calls:Response|481>
Apr 25 14:12:05 [323] DBG:statistics:parse_groupname: group: 'calls', name: 'Response|481'
Apr 25 14:12:05 [322] DBG:statistics:parse_groupname: group: 'calls', name: 'Response|481'
Apr 25 14:12:05 [322] DBG:statistics:w_update_stat: creating statistic <calls:Response|481>
Apr 25 14:12:05 [323] DBG:statistics:w_update_stat: creating statistic <calls:Response|481>
Apr 25 14:12:05 [322] DBG:tm:relay_reply: T_state=4, branch=0, save=0, relay=0, cancel_BM=0
Apr 25 14:12:05 [323] DBG:tm:relay_reply: T_state=4, branch=0, save=0, relay=0, cancel_BM=0

It this intended? I know the cfg_utils module contains some functionality for script-level locking that could potentially help here, but it seems like the statistics module should internally prevent this sort of data consistency error.

Ben Newlin
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/devel/attachments/20190425/14f3d1cf/attachment.html>