Degrades the performance of opensips after 100k calls

classic Classic list List threaded Threaded
9 messages Options
Reply | Threaded
Open this post in threaded view
|

Degrades the performance of opensips after 100k calls

Dipteshkumar Patel
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 suggest what is wrong and how to improve.

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

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Razvan Crainea-3
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 Developer
www.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 suggest what is wrong and how to improve.

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


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Dipteshkumar Patel
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:[hidden email].226>;tag=BFH7y5ycBmc4m#015#012To: <sip:[hidden email].227>;tag=3D4vXraevcj6r#015#012Call-ID: 22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342 INVITE#015#012Contact: <sip:[hidden email].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:[hidden email].226>;tag=BFH7y5ycBmc4m#015#012To: <sip:[hidden email].227>;tag=3D4vXraevcj6r#015#012Call-ID: 22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342 INVITE#015#012Contact: <sip:[hidden email].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:[hidden email].226>;tag=FQH9vNpjUD89p#015#012To: <sip:[hidden email].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 <[hidden email]> 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 Developer
www.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 suggest what is wrong and how to improve.

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


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Razvan Crainea-3
Are you seeing any other errors, such as out of memory issues? Perhaps you are not configuring enough memory. What values are you using for -m and -M arguments at startup?

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/21/2017 05:29 PM, Dipteshkumar Patel wrote:
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: [hidden email];tag=BFH7y5ycBmc4m#015#012To: [hidden email];tag=3D4vXraevcj6r#015#012Call-ID: 22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342 INVITE#015#012Contact: [hidden email]#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: [hidden email];tag=BFH7y5ycBmc4m#015#012To: [hidden email];tag=3D4vXraevcj6r#015#012Call-ID: 22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342 INVITE#015#012Contact: [hidden email]#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: [hidden email];tag=FQH9vNpjUD89p#015#012To: [hidden email];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 <[hidden email]> 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 Developer
www.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 suggest what is wrong and how to improve.

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


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Dipteshkumar Patel
hello Bogdan

I am using -m 12000 -M 24 at startup.

thanks



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

On Tue, Nov 21, 2017 at 9:13 PM, Răzvan Crainea <[hidden email]> wrote:
Are you seeing any other errors, such as out of memory issues? Perhaps you are not configuring enough memory. What values are you using for -m and -M arguments at startup?

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/21/2017 05:29 PM, Dipteshkumar Patel wrote:
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: [hidden email];tag=BFH7y5ycBmc4m#015#012To: [hidden email];tag=3D4vXraevcj6r#015#012Call-ID: 22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342 INVITE#015#012Contact: [hidden email]#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: [hidden email];tag=BFH7y5ycBmc4m#015#012To: [hidden email];tag=3D4vXraevcj6r#015#012Call-ID: 22b7aa0c-4967-1236-989f-a0369f590b64#015#012CSeq: 115300342 INVITE#015#012Contact: [hidden email]#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: [hidden email];tag=FQH9vNpjUD89p#015#012To: [hidden email];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 <[hidden email]> 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 Developer
www.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 suggest what is wrong and how to improve.

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


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Razvan Crainea-3
So you are not seeing any memory reports, are you?
You should also check what opensips is doing when the CPU usage goes up. For example, when the issue occurs, write down the PIDs involved and then do a full gdb snapshot using the 'opensipsctl trap' command. Get this information and send the resulted info here.

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/21/2017 06:06 PM, Dipteshkumar Patel wrote:
hello Bogdan

I am using -m 12000 -M 24 at startup.

thanks



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

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Dipteshkumar Patel
hello Razvan 

Sorry for addressing you as Bogdan.

We found following statistics after making lots of calls

opensipsctl fifo get_statistics shmem:
shmem:total_size:: 12582912000
shmem:used_size:: 7009825993193851937
shmem:real_used_size:: 7009825993216059273
shmem:max_used_size:: 18446711925787847093
shmem:free_size:: 11436918093076404343
shmem:fragments:: 497092

After restarting opensips

opensipsctl fifo get_statistics shmem:
shmem:total_size:: 12582912000
shmem:used_size:: 3369296
shmem:real_used_size:: 3428304
shmem:max_used_size:: 3435928
shmem:free_size:: 12579483696
shmem:fragments:: 1043


Thanks 






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

On Tue, Nov 21, 2017 at 10:46 PM, Răzvan Crainea <[hidden email]> wrote:
So you are not seeing any memory reports, are you?
You should also check what opensips is doing when the CPU usage goes up. For example, when the issue occurs, write down the PIDs involved and then do a full gdb snapshot using the 'opensipsctl trap' command. Get this information and send the resulted info here.

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/21/2017 06:06 PM, Dipteshkumar Patel wrote:
hello Bogdan

I am using -m 12000 -M 24 at startup.

thanks



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

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Razvan Crainea-3
So you are seeing ERROR logs regarding memory exhaution, right? If so, most likely that's the problem. Can you tell me how many concurrent calls you are having? You can find out by running 'opensipsctl fifo get_statistics dialog:'.
Also, what memory alocator are you using? Can you post the output of 'opensips -V'?

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/22/2017 07:56 AM, Dipteshkumar Patel wrote:
hello Razvan 

Sorry for addressing you as Bogdan.

We found following statistics after making lots of calls

opensipsctl fifo get_statistics shmem:
shmem:total_size:: 12582912000
shmem:used_size:: 7009825993193851937
shmem:real_used_size:: 7009825993216059273
shmem:max_used_size:: 18446711925787847093
shmem:free_size:: 11436918093076404343
shmem:fragments:: 497092

After restarting opensips

opensipsctl fifo get_statistics shmem:
shmem:total_size:: 12582912000
shmem:used_size:: 3369296
shmem:real_used_size:: 3428304
shmem:max_used_size:: 3435928
shmem:free_size:: 12579483696
shmem:fragments:: 1043


Thanks 






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

On Tue, Nov 21, 2017 at 10:46 PM, Răzvan Crainea <[hidden email]> wrote:
So you are not seeing any memory reports, are you?
You should also check what opensips is doing when the CPU usage goes up. For example, when the issue occurs, write down the PIDs involved and then do a full gdb snapshot using the 'opensipsctl trap' command. Get this information and send the resulted info here.

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/21/2017 06:06 PM, Dipteshkumar Patel wrote:
hello Bogdan

I am using -m 12000 -M 24 at startup.

thanks



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

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Degrades the performance of opensips after 100k calls

Dipteshkumar Patel
hello Razvan

This is the output of opensips -V

flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
git revision: 823044b
main.c compiled on 08:28:39 Nov 22 2017 with gcc 4.8.5

and i am using 100 cps with 1500 concurent calls 

result of opensipsctl fifo get_statistics dialog:

dialog:active_dialogs:: 1288
dialog:early_dialogs:: 120
dialog:processed_dialogs:: 7077
dialog:expired_dialogs:: 0
dialog:failed_dialogs:: 14
dialog:create_sent:: 0
dialog:update_sent:: 0
dialog:delete_sent:: 0
dialog:create_recv:: 0
dialog:update_recv:: 0
dialog:delete_recv:: 0


thanks 

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

On Wed, Nov 22, 2017 at 2:36 PM, Răzvan Crainea <[hidden email]> wrote:
So you are seeing ERROR logs regarding memory exhaution, right? If so, most likely that's the problem. Can you tell me how many concurrent calls you are having? You can find out by running 'opensipsctl fifo get_statistics dialog:'.
Also, what memory alocator are you using? Can you post the output of 'opensips -V'?

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/22/2017 07:56 AM, Dipteshkumar Patel wrote:
hello Razvan 

Sorry for addressing you as Bogdan.

We found following statistics after making lots of calls

opensipsctl fifo get_statistics shmem:
shmem:total_size:: 12582912000
shmem:used_size:: 7009825993193851937
shmem:real_used_size:: 7009825993216059273
shmem:max_used_size:: 18446711925787847093
shmem:free_size:: 11436918093076404343
shmem:fragments:: 497092

After restarting opensips

opensipsctl fifo get_statistics shmem:
shmem:total_size:: 12582912000
shmem:used_size:: 3369296
shmem:real_used_size:: 3428304
shmem:max_used_size:: 3435928
shmem:free_size:: 12579483696
shmem:fragments:: 1043


Thanks 






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

On Tue, Nov 21, 2017 at 10:46 PM, Răzvan Crainea <[hidden email]> wrote:
So you are not seeing any memory reports, are you?
You should also check what opensips is doing when the CPU usage goes up. For example, when the issue occurs, write down the PIDs involved and then do a full gdb snapshot using the 'opensipsctl trap' command. Get this information and send the resulted info here.

Best regards,
Răzvan Crainea
OpenSIPS Developer
www.opensips-solutions.com
On 11/21/2017 06:06 PM, Dipteshkumar Patel wrote:
hello Bogdan

I am using -m 12000 -M 24 at startup.

thanks



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

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users