[OpenSIPS-Users] SIP messages delayed

[Vlad Paiu]

Hello,

Seems your processes get stuck in something, thus the high amount of 
time needed to process a single message.
 From the stats, OpenSIPS says the load is 100% but if the CPU load was 
low, then it means the OpenSIPS was stuck in an IO blocking operation. 
If you are using mysql, please check out the exec_query_threshold 
parameter I mentioned in the previous emails.

If no DB is involved in your cfg, can you please examine your CFG for 
other sources of IO blocking operations ( Radius, external scripts 
execution, etc ) ?
Maybe paste the CFG here or send it to me personally so I can take a 
look as well.

Regards,

Vlad Paiu
OpenSIPS Developer


On 12/12/2011 06:33 PM, Maciej Bylica wrote:
> Hello,
>
> Here is an output from opensips.log file
>    =rtpmap:0 PCMU/8000 087637 IN IP4 127.0.0.16SIPpTag002:
> WARNING:core:log_expiry: threshold exceeded : msg processing took too
> long - 309013 us.Source : INVITE sip:222221133 at X1.X1.X1.X1:5060
> SIP/2.0
>    =rtpmap:0 PCMU/8000 087637 IN IP4 127.0.0.16SIPpTag0017
> WARNING:core:log_expiry: threshold exceeded : msg processing took too
> long - 927067 us.Source : INVITE sip:222221133 at X1.X1.X1.X1:5060
> SIP/2.0
>    =rtpmap:0 PCMU/8000 087637 IN IP4 127.0.0.16SIPpTag0013
> WARNING:core:log_expiry: threshold exceeded : msg processing took too
> long - 300760 us.Source : INVITE sip:222221133 at X1.X1.X1.X1:5060
> SIP/2.0
>    =rtpmap:0 PCMU/8000 087637 IN IP4 127.0.0.16SIPpTag003:
> WARNING:core:log_expiry: threshold exceeded : msg processing took too
> long - 267328 us.Source : INVITE sip:222221133 at X1.X1.X1.X1:5060
> SIP/2.0
>    =rtpmap:0 PCMU/8000 087637 IN IP4 127.0.0.16SIPpTag0018
> WARNING:core:log_expiry: threshold exceeded : msg processing took too
> long - 860686 us.Source : INVITE sip:222221133 at X1.X1.X1.X1:5060
> SIP/2.0
>    =rtpmap:0 PCMU/8000 087637 IN IP4 127.0.0.16SIPpTag0014
> WARNING:core:log_expiry: threshold exceeded : msg processing took too
> long - 284254 us.Source : INVITE sip:222221133 at X1.X1.X1.X1:5060
> SIP/2.0
>
> Core parameters were as follows:
> exec_dns_threshold=60000
> exec_msg_threshold=60000
>
> What is more number of awaken processes were as below:
> opensipsctl fifo get_statistics udp:X1.X1.X1.X1:5060-load
> load:udp:X1.X1.X1.X1:5060-load = 100
> opensipsctl fifo get_statistics udp:X1.X1.X1.X1:5060-load
> load:udp:X1.X1.X1.X14:5060-load = 100
> opensipsctl fifo get_statistics udp:X1.X1.X1.X1:5060-load
> load:udp:X1.X1.X1.X1:5060-load = 100
> opensipsctl fifo get_statistics udp:X1.X1.X1.X1:5060-load
> load:udp:X1.X1.X1.X1:5060-load = 100
> opensipsctl fifo get_statistics udp:X1.X1.X1.X1:5060-load
> load:udp:X1.X1.X1.X1:5060-load = 25
> opensipsctl fifo get_statistics udp:X1.X1.X1.X1:5060-load
> load:udp:X1.X1.X1.X1:5060-load = 0
>
> CPS was more less four, so quite low.
>
> Where the problem might be located? :(
>
> Thanks,
> Maciej
>
>> Hello,
>>
>> First of all, i am sorry for long delay - i was unable to keep on
>> working on this.
>> Thank You for your replies.
>>
>> Logan: there is no DB back end at all in my configuration.
>> It is not necessery for me and as you mentioned could cause delays.
>>
>> Vlad: i was trying to specify only IP addresses and omit dns names,
>> the after effect was exactly the same.
>> But i am about to proceed with core parameters as you described and
>> give you feedback here.
>>
>> Thanks,
>> Maciej
>>
>>> Hello,
>>>
>>> Try to use the exec_dns_threshold [1] and the exec_msg_threshold [2] core
>>> parameters, as well as the exec_query_threshold parameter in the db_mysql
>>> module to try and see which component is determining the delay ( whether
>>> it's the DNS, MySQL or some other things in your config ).
>>>
>>> [1] http://www.opensips.org/Resources/DocsCoreFcn#toc49
>>> [2] http://www.opensips.org/Resources/DocsCoreFcn#toc50
>>> [3] http://www.opensips.org/html/docs/modules/devel/db_mysql.html#id249058
>>>
>>> Regards,
>>>
>>> Vlad Paiu
>>> OpenSIPS Developer
>>>
>>>
>>>
>>> On 12/02/2011 09:13 PM, logan wrote:
>>>> Are you using a DB back end for ACC? If so which one? I've seen instances
>>>> where using MySQL under heavy load w/o optimizing your mysql config can
>>>> cause messages to hang in OpenSIPs while it's waiting for a mysql resource
>>>> to write down its existing ACC or Missed_Call records.
>>>>
>>>> --
>>>> View this message in context:
>>>> http://opensips-open-sip-server.1449251.n2.nabble.com/SIP-messages-delayed-tp7054793p7055831.html
>>>> Sent from the OpenSIPS - Users mailing list archive at Nabble.com.
>>>>
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users at lists.opensips.org
>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>
>>> _______________________________________________
>>> Users mailing list
>>> Users at lists.opensips.org
>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users