Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Mem leak in smsops which leads to the udp receiver process leak memory continuously #3833

Open
paresh-panda opened this issue Apr 29, 2024 · 4 comments

Comments

@paresh-panda
Copy link

Hi,
I am using Kamailio 5.8.1 ( ubuntu 22.04 Jammy 64 Bit),. Below are the observations.

I am running a load of 500 3GPP IMS SMS which kamailio decodes and sends to another application over Rabbit MQ (Kazoo Module).
-m 512 -M 256 , using 512 MB Shared memory and 256MB Package Memory.

When the load for 20 mins the available Memory drops from 80% to 25%

And I see below error logs

Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0x7ff912e21010, 192); Free fragment not found!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0x7ff912e21010, 192) called from smsops: smsops_impl.c: decode_3gpp_sms(813), module: smsops; Free fragment not found!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:815]: decode_3gpp_sms(): Error allocating 192 bytes!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:1320]: pv_get_sms(): Error getting/decoding RP-Data from request!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0x7ff912e21010, 192); Free fragment not found!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0x7ff912e21010, 192) called from smsops: smsops_impl.c: decode_3gpp_sms(813), module: smsops; Free fragment not found!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:815]: decode_3gpp_sms(): Error allocating 192 bytes!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:1320]: pv_get_sms(): Error getting/decoding RP-Data from request!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/pvapi.c:1136]: pv_parse_format(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/sr_module.c:1318]: fix_param(): bad PVE format: "PRD-IR92/11 term-Motorola/XT2205-1-T2STS33.105-51-11-1-2-2 device-type/smart-phone"
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/mod_fix.c:601]: fixup_spve_null(): Cannot convert function parameter 1 to spve
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1178]: do_action(): runtime fixup failed for jansson_set param 3
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:539
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/sr_module.c:1208]: fix_param(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/mod_fix.c:601]: fixup_spve_null(): Cannot convert function parameter 1 to spve
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1178]: do_action(): runtime fixup failed for jansson_set param 3
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:540
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/sr_module.c:1208]: fix_param(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/mod_fix.c:601]: fixup_spve_null(): Cannot convert function parameter 1 to spve
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1178]: do_action(): runtime fixup failed for jansson_set param 3
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:541
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/rvalue.c:1321]: rval_get_str(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1178]: do_action(): failed to convert RVE to string
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:542
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/rvalue.c:1321]: rval_get_str(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1178]: do_action(): failed to convert RVE to string
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:543
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:815]: decode_3gpp_sms(): Error allocating 192 bytes!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:1320]: pv_get_sms(): Error getting/decoding RP-Data from request!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:815]: decode_3gpp_sms(): Error allocating 192 bytes!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:1320]: pv_get_sms(): Error getting/decoding RP-Data from request!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:815]: decode_3gpp_sms(): Error allocating 192 bytes!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:1320]: pv_get_sms(): Error getting/decoding RP-Data from request!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:815]: decode_3gpp_sms(): Error allocating 192 bytes!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:1320]: pv_get_sms(): Error getting/decoding RP-Data from request!
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/rvalue.c:1321]: rval_get_str(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1178]: do_action(): failed to convert RVE to string
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:555
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/rvalue.c:1321]: rval_get_str(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1178]: do_action(): failed to convert RVE to string
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:556
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/rvalue.c:1321]: rval_get_str(): could not allocate private memory from pkg pool
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1171]: do_action(): failed to convert RVE to string
Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} [core/action.c:1566]: do_action(): run action error at: /etc/kamailio/kamailio.cfg:559

I am attaching the configuration for reference.

Help on this is much appreciated
configfiles.tar.gz
, I am looking into this issue for quite a long time.

Thank you!
Regards Paresh

@kamailio-sync
Copy link

kamailio-sync commented Apr 29, 2024 via email

@paresh-panda
Copy link
Author

Hi Henning,

Thank you for guidance and suggestion. I did change the PKG size to 32MB and increased SHM to 1GB. But the same issue observed with a lesser time duration.

While looking at the below error, found that something changes in the smsops module which was causing the leak

Apr 29 13:28:53 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5520]: ERROR: {1 1 MESSAGE 739708-3401@192.168.136.152} smsops [smsops_impl.c:815]: decode_3gpp_sms(): Error allocating 192 bytes!

Below is my analysis:
The initial code was

       if (!rp_data) {
		rp_data = (sms_rp_data_t*)pkg_malloc(sizeof(struct _sms_rp_data));
		if (!rp_data) {
			LM_ERR("Error allocating %lu bytes!\n", sizeof(struct _sms_rp_data));
			return -1;
		}
	} else {
		freeRP_DATA(rp_data);
	}

But it got changed in "smsops: Fix conversion from UCS-2 to UTF-8 and viceversa (#3546)" tag 8 months ago

           if(rp_data) {
		freeRP_DATA(rp_data);
	}
	rp_data = (sms_rp_data_t *)pkg_malloc(sizeof(struct _sms_rp_data));
	if(!rp_data) {
		LM_ERR("Error allocating %lu bytes!\n",
				(unsigned long)sizeof(struct _sms_rp_data));
		return -1;
	} 

Now in the recent code it is not reusing the rp_data pointer, rather it allocates every time a new message reaches.

I will try to clone the tag and fix the code and keep you posted

            if(_smsops_rp_data) {
                    freeRP_DATA(_smsops_rp_data);
            } else {  //Added by Paresh Panda

            _smsops_rp_data =
                            (sms_rp_data_t *)pkg_malloc(sizeof(struct _sms_rp_data));
            }

Is there any plan for new tag ? , I am planning to take the latest kamailio tag to production.

I will update you after testing the fix as above.

Thank you!
Regards
Paresh

@henningw
Copy link
Contributor

Hello, thanks for the feedback. Your description sounds indeed like a memory leak. The code logic got changed, so its freeing the rp_data when its allocated now. Its a bit longer function, so it should be properly analyzed that its freed in all error conditions (which does not look like that right now).

@paresh-panda
Copy link
Author

Hi Henning,
Thank you for the quick response!

I cloned the code and just changed back the block (which was problematic). Now I see error again as below :

May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5885]: INFO: <script>: {1 1 MESSAGE 1939882-1516@192.168.136.152} Message Outbound MESSAGE sip:+16475800172@192.168.136.152:5060 (sip:+15197963701@192.168.136.152:5061 (192.168.136.152:5062) to sip:+16475800172@192.168.136.151:5060, 1939882-1516@192.168.136.152)
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: INFO: {2 1 MESSAGE 1939882-1516@192.168.136.152} <script>: reply route
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} [core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0x7f3af4736010, 384); Free fragment not found!
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} [core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0x7f3af4736010, 384) called from core: core/msg_translator.c: generate_res_buf_from_sip_res(2435), module: core; Free fragment not found!
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} [core/msg_translator.c:2438]: generate_res_buf_from_sip_res(): could not allocate private memory from pkg pool
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} tm [t_reply.c:2067]: relay_reply(): no mem for outbound reply buffer
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} [core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0x7f3af4736010, 416); Free fragment not found!
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} [core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0x7f3af4736010, 416) called from core: core/msg_translator.c: build_res_buf_from_sip_req(2608), module: core; Free fragment not found!
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} [core/msg_translator.c:2610]: build_res_buf_from_sip_req(): could not allocate private memory from pkg pool
May 1 16:54:43 stgn-haud-vm-ub-kamailio01 /usr/sbin/kamailio[5875]: ERROR: {2 1 MESSAGE 1939882-1516@192.168.136.152} tm [t_reply.c:465]: _reply_light(): response building failed

Does it also look like memory leak this error log appeared and kamailio stopped processing traffic after 35 minutes or so.

When check the pkg memory for the pid as in log

{
entry: 6
pid: 5875
rank: 6
used: 5701888
free: 5728
real_used: 33548704
total_size: 33554432
total_frags: 28
desc: udp receiver child=5 sock=192.168.136.151:5060
}

It shows the udp receiver process PKG Mem is full , I have 8 childrens configured and all started showing the same issue.

Config : PKG 32 MB , SHM 1GB load 1000 msg/sec

Can you please quickly through some lights on this please? Shall I look at it as mem leak or config issue ( may be increase in PKG mem ?

Thank you!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants