[OpenSIPS-Users] Not enough memory to sync cluster data

Răzvan Crainea razvan at opensips.org
Fri Dec 7 04:28:52 EST 2018 

Actually this looks like a memory leak.
Can you tell us what kind of process is 30896? You can find out running 
`opensipsctl fifo ps | grep 30896`
Also, what version of opensips are you using (output of `opensips -V`).

Best regards,
Răzvan

On 12/7/18 10:52 AM, vasilevalex wrote:
> Hi all,
> 
> Yes, may be my assumption was wrong. @Răzvan please look at logs and routing
> script parts:
> 
> Process of starting OpenSIPS (I skip repeated messages and add some
> comments):
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]: NOTICE:core:main: version:
> opensips 2.4.3 (x86_64/linux)
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]: INFO:core:main: using 512
> Mb of shared memory
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]: INFO:core:main: using 32
> Mb of private process memory
> <... skipped ...>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_CORE_THRESHOLD(0)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_CORE_SHM_THRESHOLD(1)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_CORE_PKG_THRESHOLD(2)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_MYSQL_CONNECTION(3)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]: INFO:proto_bin:mod_init:
> initializing BIN protocol
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]: INFO:clusterer:mod_init:
> Clusterer module - initializing
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_CLUSTERER_REQ_RECEIVED(4)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_CLUSTERER_RPL_RECEIVED(5)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]: INFO:usrloc:ul_init_locks:
> locks array size 512
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_UL_AOR_INSERT(6)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_UL_AOR_DELETE(7)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_UL_CONTACT_INSERT(8)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_UL_CONTACT_DELETE(9)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_UL_CONTACT_UPDATE(10)>
> Dec  1 20:13:01 test02 /usr/sbin/opensips[30853]:
> INFO:core:evi_publish_event: Registered event <E_UL_LATENCY_UPDATE(11)>
> <... skipped normal start messages ...>
> ### Than there are a lot of such messages (300-400):
> Dec  1 20:13:04 test02 /usr/sbin/opensips[30896]:
> INFO:usrloc:receive_ucontact_delete: failed to fetch local urecord -
> ignoring request (ci: '313534303437393137333433343135-n7utfvs2rllm')
> Dec  1 20:13:04 test02 /usr/sbin/opensips[30896]:
> INFO:usrloc:receive_ucontact_delete: failed to fetch local urecord -
> ignoring request (ci: '313534333537353638353630323134-gbdnp67daddu')
> Dec  1 20:13:04 test02 /usr/sbin/opensips[30896]:
> INFO:usrloc:receive_ucontact_delete: failed to fetch local urecord -
> ignoring request (ci: '313534333233353433383232373838-3a3w8ljwjq7f')
> <... skipped ...>
> ### I think this delete messages came from Active server, when it starts
> deleting dead contacts, as TLS connections were of course closed when
> switching.
> ### Than there are a lot of messages generated by OpenSIPS event route
> Dec  1 20:15:11 test02 /usr/sbin/opensips[30896]: ATTENTION! Used 26843600
> of 33554432 private memory by PID 30896
> Dec  1 20:15:11 test02 /usr/sbin/opensips[30896]: ATTENTION! Used 27194504
> of 33554432 private memory by PID 30896
> Dec  1 20:15:11 test02 /usr/sbin/opensips[30896]: ATTENTION! Used 27523656
> of 33554432 private memory by PID 30896
> Dec  1 20:15:11 test02 /usr/sbin/opensips[30896]: ATTENTION! Used 27850224
> of 33554432 private memory by PID 30896
> <... skipped ...>
> ### Than start error messages
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: ERROR:core:fm_malloc: not
> enough free pkg memory (30400 bytes left, need 35904), please increase the
> "-M" command line parameter!
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> attempting defragmentation...
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> unable to alloc a big enough fragment!
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]:
> ERROR:rest_client:start_async_http_req: Init curl handle failed!
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: ERROR:core:fm_malloc: not
> enough free pkg memory (30400 bytes left, need 35904), please increase the
> "-M" command line parameter!
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> attempting defragmentation...
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> unable to alloc a big enough fragment!
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]:
> ERROR:rest_client:start_async_http_req: Init curl handle failed!
> ### rest_client called async from event route
> <... skipped ...>
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> attempting defragmentation...
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> unable to alloc a big enough fragment!
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> attempting defragmentation...
> Dec  1 20:15:12 test02 /usr/sbin/opensips[30896]: INFO:core:fm_malloc:
> unable to alloc a big enough fragment!
> <... skipped ...>
> ### Than server start working like usual, without any unexpected errors.
> Dec  1 20:27:52 test02 /usr/sbin/opensips[30896]:
> INFO:usrloc:receive_ucontact_update: failed to fetch local urecord - create
> new record and contact (ci: '313534333639353234383631313333-k2uymmqblqnx')
> Dec  1 20:35:46 test02 /usr/sbin/opensips[30896]:
> INFO:usrloc:receive_ucontact_update: failed to fetch local urecord - create
> new record and contact (ci: '313534333639353235323136363838-5p34q9svc9v1')
> Dec  1 20:45:09 test02 /usr/sbin/opensips[30896]:
> INFO:usrloc:receive_ucontact_update: failed to fetch local urecord - create
> new record and contact (ci: '313534333639353330363630373039-mv4k1u64jm0s')
> 
> 
> Now some routes from OpenSIPS script:
> 
> event_route[E_UL_CONTACT_INSERT] {
> 	fetch_event_params("aor=$avp(aor);uri=$avp(uri);received=$avp(received)");
> 	$avp(ul_method) = "insert";
> 	$var(body) = "{ ....}\r\n"
> 	launch(rest_post("API_URL", "$var(body)", "application/json", "$var(ret)"),
> resume_post);
> }
> 
> event_route[E_UL_CONTACT_UPDATE] {
> 	fetch_event_params("aor=$avp(aor);uri=$avp(uri);received=$avp(received)");
> 	$avp(ul_method) = "update";
> 	$var(body) = "{ ....}\r\n"
> 	launch(rest_post("API_URL", "$var(body)", "application/json", "$var(ret)"),
> resume_post);
> }
> 
> route[resume_post] {
> 	if ($rc < 0) {
> 		xlog("Error $rc in HTTP POST\n");
> 	}
> 	exit;
> }
> 
> event_route[E_CORE_PKG_THRESHOLD] {
> 	fetch_event_params("used=$avp(used);size=$avp(size);pid=$avp(pid)");
> 	xlog("ATTENTION! Used $avp(used) of $avp(size) private memory by PID
> $avp(pid)\n");
> }
> 
> So may be every contact added by syncing data also calls
> E_UL_CONTACT_INSERT? And libcurl call consumes a lot of memory?
> Thanks.
> 
> 
> 
> --
> Sent from: http://opensips-open-sip-server.1449251.n2.nabble.com/OpenSIPS-Users-f1449235.html
> 
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
> 

-- 
Răzvan Crainea
OpenSIPS Core Developer
   http://www.opensips-solutions.com
Meet the OpenSIPS team at the next OpenSIPS Summit:
   https://www.opensips.org/events

More information about the Users mailing list