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

vasilevalex alexei.vasilyev at gmail.com
Fri Dec 7 03:52:44 EST 2018 

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

More information about the Users mailing list