[OpenSIPS-Users] Degrades the performance of opensips after 100k calls

Tue Nov 21 10:29:32 EST 2017

hello Bogdan

Thanks for your reply.

But after 100k calls almost all actions take too many time

Nov 21 14:00:36 OS /usr/local/sbin/opensips[7235]: WARNING:core:log_expiry:
threshold exceeded : msg processing took too long - 61006 us.Source :
SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP
xxx.xxx.x.226:5060;branch=z9hG4bKf59a.7f50e365.0;rport=5060#015#012From:
<sip:50390909150 at xxx.xxx.x.226>;tag=BFH7y5ycBmc4m#015#012To:
<sip:50331152944 at xxx.xxx.x.227>;tag=3D4vXraevcj6r#015#012Call-ID:
22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342
INVITE#015#012Contact:
<sip:50331152944 at xxx.xxx.x.227:5060;transport=udp>#015#012User-Agent:
VOXSBCSWITCH#015#012Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE,
INFO, UPDATE, REFER, NOTIFY#015#012Require: timer#015#012Supported: timer,
path, replaces#015#012Allow-Events: talk, hold, conference,
refer#015#012Session-Expires: 3600;refresher=uac#015#012Content-Type:
application/sdp#015#012Content-Disposition: session#015#012Content-Length:
269#015#012X-FS-Support:
update_display,send_info#015#012#015#012v=0#015#012o=FreeSWITCH 1511254322
1511254323 IN IP4 xxx.xxx.x.227#015#012s=FreeSWITCH#015#012c=IN IP4
xxx.xxx.x.227#015#012t=0 0#015#012a=sendrecv#015#012m=audio 18498 RTP/AVP 8
101#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101
0-16#015#012a=ptime:20#015#012a=rtcp:18499 IN IP4 xxx.xxx.x.227
Nov 21 14:00:36 OS /usr/local/sbin/opensips[7235]: WARNING:core:log_expiry:
threshold exceeded : msg processing took too long - 61006 us.Source :
SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP
xxx.xxx.x.226:5060;branch=z9hG4bKf59a.7f50e365.0;rport=5060#015#012From:
<sip:50390909150 at xxx.xxx.x.226>;tag=BFH7y5ycBmc4m#015#012To:
<sip:50331152944 at xxx.xxx.x.227>;tag=3D4vXraevcj6r#015#012Call-ID:
22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342
INVITE#015#012Contact:
<sip:50331152944 at xxx.xxx.x.227:5060;transport=udp>#015#012User-Agent:
SBCSWITCH#015#012Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO,
UPDATE, REFER, NOTIFY#015#012Require: timer#015#012Supported: timer, path,
replaces#015#012Allow-Events: talk, hold, conference,
refer#015#012Session-Expires: 3600;refresher=uac#015#012Content-Type:
application/sdp#015#012Content-Disposition: session#015#012Content-Length:
269#015#012X-FS-Support:
update_display,send_info#015#012#015#012v=0#015#012o=FreeSWITCH 1511254322
1511254323 IN IP4 xxx.xxx.x.227#015#012s=FreeSWITCH#015#012c=IN IP4
xxx.xxx.x.227#015#012t=0 0#015#012a=sendrecv#015#012m=audio 18498 RTP/AVP 8
101#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101
telephone-event/8000#015#012a=fmtp:101
0-16#015#012a=ptime:20#015#012a=rtcp:18499 IN IP4 xxx.xxx.x.227

Nov 21 14:51:33 OS /usr/local/sbin/opensips[7233]: WARNING:core:log_expiry:
threshold exceeded : msg processing took too long - 117018 us.Source :
SIP/2.0 503 Service Unavailable#015#012Via: SIP/2.0/UDP
xxx.xxx.x.226:5060;branch=z9hG4bKa7a3.2fc757f5.0;rport=5060#015#012Max-Forwards:
69#015#012From: <sip:50390909150 at xxx.xxx.x.226>;tag=FQH9vNpjUD89p#015#012To:
<sip:50331111944 at xxx.xxx.x.227>;tag=F5m876094y75B#015#012Call-ID:
4e565b83-496e-1236-f5b6-a0369f590b64#015#012CSeq: 115301882
INVITE#015#012User-Agent: SBCSWITCH#015#012Accept:
application/sdp#015#012Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE,
INFO, UPDATE, REFER, NOTIFY#015#012Supported: timer, path,
replaces#015#012Allow-Events: talk, hold, conference, refer#015#012Reason:
Q.850;cause=41;text="NORMAL_TEMPORARY_FAILURE"#015#012Content-Length: 0
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7231]: WARNING:core:log_expiry:
#1 is a module action : t_reply - 106282us - line 1112
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7238]: WARNING:core:log_expiry:
#5 is a core action : 69 - 8us - line 987
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7228]: WARNING:core:log_expiry:
#2 is a core action : 82 - 184us - line 696
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7235]: WARNING:core:log_expiry:
#1 is a module action : t_reply - 116776us - line 1112
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7236]: WARNING:core:log_expiry:
#2 is a module action : search - 26us - line 906
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7221]: WARNING:core:log_expiry:
#1 is a module action : t_reply - 68668us - line 1112
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7233]: WARNING:core:log_expiry:
#1 is a module action : t_reply - 116606us - line 1112
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7231]: WARNING:core:log_expiry:
#2 is a module action : rtpproxy_engage - 2175us - line 811
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7228]: WARNING:core:log_expiry:
#3 is a module action : search - 81us - line 906
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7235]: WARNING:core:log_expiry:
#2 is a module action : search - 31us - line 906
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7236]: WARNING:core:log_expiry:
#3 is a core action : 52 - 17us - line 957
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7221]: WARNING:core:log_expiry:
#2 is a module action : t_check_status - 42us - line 879
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7233]: WARNING:core:log_expiry:
#2 is a module action : search - 101us - line 906
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7231]: WARNING:core:log_expiry:
#3 is a core action : 83 - 340us - line 764
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7228]: WARNING:core:log_expiry:
#4 is a module action : t_check_status - 27us - line 956
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7235]: WARNING:core:log_expiry:
#3 is a core action : 52 - 17us - line 957
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7236]: WARNING:core:log_expiry:
#4 is a module action : t_check_status - 16us - line 879
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7221]: WARNING:core:log_expiry:
#3 is a module action : search - 30us - line 906
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7233]: WARNING:core:log_expiry:
#3 is a module action : t_check_status - 43us - line 956
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7231]: WARNING:core:log_expiry:
#4 is a core action : 82 - 189us - line 696
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7228]: WARNING:core:log_expiry:
#5 is a module action : t_check_status - 19us - line 1111
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7235]: WARNING:core:log_expiry:
#4 is a module action : t_check_status - 14us - line 879
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7236]: WARNING:core:log_expiry:
#5 is a core action : 69 - 8us - line 987
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7221]: WARNING:core:log_expiry:
#4 is a module action : t_check_status - 19us - line 1111
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7233]: WARNING:core:log_expiry:
#4 is a module action : t_check_status - 41us - line 1111
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7231]: WARNING:core:log_expiry:
#5 is a module action : t_relay - 60us - line 843
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7235]: WARNING:core:log_expiry:
#5 is a module action : t_check_status - 11us - line 956
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7221]: WARNING:core:log_expiry:
#5 is a core action : 52 - 16us - line 957
Nov 21 14:51:33 OS /usr/local/sbin/opensips[7233]: WARNING:core:log_expiry:
#5 is a core action : 69 - 18us - line 987
Nov 21 15:03:03 OS /usr/local/sbin/opensips[7216]:
WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 60000 us delay
in execution

*Diptesh Patel*
Jr. Software Developer
Ecosmob Technologies Ltd
Ahmedabad
Mo:*+919898962659*

On Tue, Nov 21, 2017 at 8:34 PM, Răzvan Crainea <razvan at opensips.org> wrote:

> Hello!
>
> I see that you have configured different thresholds in your script. Do you
> get any alerts from those thresholds?
>
> Also, how many concurrent calls are there when you are experiencing this?
>
> Best regards,
> Răzvan
>
> Răzvan Crainea
> OpenSIPS Developerwww.opensips-solutions.com
>
> On 11/21/2017 03:08 PM, Dipteshkumar Patel wrote:
>
> hello all
>
> I am using opensips-2.3.2 running on 16 cores of cpu and 32GB of RAM
>
> I am facing an isssue. After making 100k of calls, suddenly opensips
> performance degrades and it takes much time to process a packet. load
> average of cpu incresing significantly.after restarting opensips it works
> fine for another 100k calls then again problem appears.
>
> It is an SBC server, using 6-7 sql queries with async with database
> optimisation(using proper indexing), permission module for auth, aaa_radius
> module for accounting and some string operations.
>
> Summary of operations
> 1. Sanity checks
> 2. Use IP authentication
> 3. Send Requet for accounting
> 4. Some string operations for accounting
>
> I am sending global parameters and module parameters of my opensips config
> file
>
> Please find here https://pastebin.com/B7Y5HRgH
>
> Please suggest what is wrong and how to improve.
>
> *Diptesh Patel*
> Jr. Software Developer
> Ecosmob Technologies Ltd
> Ahmedabad
> Mo:*+919898962659*
>
>
> _______________________________________________
> Users mailing listUsers at lists.opensips.orghttp://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
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20171121/7e27ab05/attachment-0001.html>