I'm trying to log "user last register status" using function jsonrpc_notification
from module jsonrpc-c
jsonrpc_notification("last_reg", "{'user': '$au', 'data':['$Ts', '$au', '$ct', '$ua', '$sel(received.proto_ip_port)']}");
according to doc:
jsonrpc_notification is asynchronous delayed job and do not receive response
notifications do not receive a response. Script processing continues in the usual fashion as soon as the notification has been sent.
The rpc server on localhost is implemented with Node.js which never return responses and never close connections ( it only support jsonrpc notification )
I found kamailio crashed periodically about 2-3 days. ( back trace attached at the end)
settings:
1. the amount of total registered users are about 15k ~ 50k; register expiration is 1200 Secs.
2. kamailio start with parameter pkg 1G and shm 5G.
3. I had patched jsonrpc_io.c from #268
json crash log:
Aug 18 22:12:04 SIP-4 kernel: [50538943.565484] kamailio[84670]: segfault at 0 ip 00007f424a3ea3bf sp 00007fff8b3eab60 error 4 in libjson.so.0.1.0[7f424a3e6000+9000]
Aug 18 22:12:23 SIP-4 /home/pkg/kamailio/sbin/kamailio[84620]: ALERT: <core> [main.c:728]: handle_sigs(): child process 84670 exited by a signal 11
Aug 18 22:12:23 SIP-4 /home/pkg/kamailio/sbin/kamailio[84620]: ALERT: <core> [main.c:731]: handle_sigs(): core was generated
sometimes it would not crash, but result in allocation failure. no new connections can be accept.
Aug 20 12:26:04 SIP-5 /home/pkg/kamailio/sbin/kamailio[181104]: ERROR: <core> [tcp_main.c:959]: tcpconn_new(): mem. allocation failure
Aug 20 12:26:04 SIP-5 /home/pkg/kamailio/sbin/kamailio[181104]: ERROR: <core> [tcp_main.c:3977]: handle_new_connect(): tcpconn_new failed, closing socket
use sip-p
to start a stress test with RPS 2000 register and observing results both from kamcmd core.shmmem
and top
command
Kamailio died quickly along with depleting shm memory.
top
shows kamailio SHR consumed 4.8G
kamcmd core.shmmem
shows free is less than 1MB
jsonrpc_notification
call we've made, the quicker kamailio out of memory.switch on memdbg and shutdown kamailio to get mem status.
see Memory still-in-use summary (shm):
shm_strdup
and jsonrpc_notification
from jsonrpc_request.c
Aug 24 14:39:41 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: -----------------------------
Aug 24 14:39:41 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : <core> [main.c:569]: cleanup(): Memory still-in-use summary (shm):
Aug 24 14:39:41 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: summarizing all alloc'ed. fragments:
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 96 size= 4608 bytes from dialog: dlg_var.c: new_dlg_var(97)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 96 size= 2016 bytes from dialog: dlg_var.c: new_dlg_var(106)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 96 size= 1152 bytes from dialog: dlg_var.c: new_dlg_var(116)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 40 size= 10568 bytes from tmx: tmx_pretran.c: tmx_check_pretran(264)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 40 size= 5520 bytes from tmx: tmx_pretran.c: tmx_check_pretran(243)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 993 size= 7960 bytes from dialog: dlg_handlers.c: dlg_get_iuid_shm_clone(279)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count=997818 size= 113547928 bytes from jsonrpc-c: jsonrpc_request.c: shm_strdup(158)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 1024 bytes from tmx: tmx_pretran.c: tmx_init_pretran_table(90)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 3 size= 64 bytes from usrloc: udomain.c: build_stat_name(51)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from <core>: pt.c: init_pt(110)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from <core>: pt.c: init_pt(105)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count=498909 size= 40377480 bytes from jsonrpc-c: jsonrpc_request.c: jsonrpc_notification(135)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from dialog: dlg_hash.c: init_dlg_table(269)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from dialog: dlg_hash.c: init_dlg_table(262)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from dialog: dlg_hash.c: init_dlg_table(257)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 3 size= 216 bytes from <core>: timer.c: register_timer(1011)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from <core>: usr_avp.c: init_avps(90)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from <core>: usr_avp.c: init_avps(89)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: count= 1 size= 8 bytes from <core>: mem/shm_mem.c: shm_mem_init_mallocs(179)
Aug 24 14:39:42 SIP-6 /home/pkg/kamailio/sbin/kamailio[263619]: : fm_status: -----------------------------
#0 0x00007f424a3ea3bf in json_tokener_parse_ex () from /lib/x86_64-linux-gnu/libjson.so.0
No symbol table info available.
#1 0x00007f424a3ebda6 in json_tokener_parse_verbose () from /lib/x86_64-linux-gnu/libjson.so.0
No symbol table info available.
#2 0x00007f424a3ebdfe in json_tokener_parse () from /lib/x86_64-linux-gnu/libjson.so.0
No symbol table info available.
#3 0x00007f424a5f4e1a in cmd_pipe_cb (fd=6, event=2, arg=0x7fff8b3eae60) at jsonrpc_io.c:152
cmd = 0x7f4304a93cf8
__FUNCTION__ = "cmd_pipe_cb"
params = 0x1bc0aa0
payload = 0x3985b4d6
req = 0x304a9c5
json = 0x7fff8b3ead00 "0\f\274\001"
ns = 0x7f4391ebdc60 "298:{ \"jsonrpc\": \"2.0\", \"method\": \"last_reg\", \"params\": { \"user\": \"597438910\", \"data\": [ \"1439907102\", \"597438910\", \"<sip:597438910@211.246.212.119:55430;transport=tcp>;+sip.instance=\\\"<urn:uuid:f1016"...
bytes = 140735529528624
g = 0x7f424a1ac2f8
sent = 0
#4 0x00007f424a1af254 in event_base_loop () from /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5
No symbol table info available.
#5 0x00007f424a5f45ef in jsonrpc_io_child_process (cmd_pipe=6, _servers=0x7f4391aba578 "10.1.3.9:5013,3 10.1.3.10:5013,2 10.1.3.11:5013,1")
at jsonrpc_io.c:92
__FUNCTION__ = "jsonrpc_io_child_process"
pipe_ev = {ev_active_next = {tqe_next = 0x0, tqe_prev = 0x1bb9dc0}, ev_next = {tqe_next = 0x7f4391ebda20, tqe_prev = 0x1bc0c00},
ev_timeout_pos = {ev_next_with_common_timeout = {tqe_next = 0xffffffff, tqe_prev = 0x0}, min_heap_idx = -1}, ev_fd = 6,
ev_base = 0x1bc0aa0, _ev = {ev_io = {ev_io_next = {tqe_next = 0x0, tqe_prev = 0x1bc0fd0}, ev_timeout = {tv_sec = 0, tv_usec = 0}},
ev_signal = {ev_signal_next = {tqe_next = 0x0, tqe_prev = 0x1bc0fd0}, ev_ncalls = 0, ev_pncalls = 0x0}}, ev_events = 18,
ev_res = 2, ev_flags = 130, ev_pri = 0 '\000', ev_closure = 2 '\002', ev_timeout = {tv_sec = 140733193388081, tv_usec = 6631108320},
ev_callback = 0x7f424a5f4aa7 <cmd_pipe_cb>, ev_arg = 0x7fff8b3eae60}
#6 0x00007f424a5fd50b in child_init (rank=0) at jsonrpc_mod.c:135
pid = 0
#7 0x0000000000596a41 in init_mod_child (m=0x7f4391ab0db8, rank=0) at sr_module.c:898
__FUNCTION__ = "init_mod_child"
#8 0x0000000000596779 in init_mod_child (m=0x7f4391ab1110, rank=0) at sr_module.c:895
__FUNCTION__ = "init_mod_child"
#9 0x0000000000596d55 in init_child (rank=0) at sr_module.c:924
No locals.
#10 0x00000000004aafd3 in main_loop () at main.c:1650
i = 24
pid = 84647
si = 0x0
si_desc = "udp receiver child=23 sock=38.106.58.4:5063\000n\000\000\000~/q\000\001\000\000\000\260\344\213OB\177\000\000\020\261>\213\377\177\000\000\032\264N\000\000\000\000\000`\261>\213\377\177\000\000\000\224\351\221C\177\000\000 \333\330OB\177\000\000\260\344\213OB\177\000\000$!\314\a\000\000\000\000\260\210A\000\001\000\000"
nrprocs = 24
__FUNCTION__ = "main_loop"
#11 0x00000000004b0b5b in main (argc=13, argv=0x7fff8b3eb3d8) at main.c:2533
cfg_stream = 0x1b1a010
c = -1
r = 0
tmp = 0x7fff8b3ecd59 ""
tmp_len = 32579
port = -767281296
proto = 0
options = 0x707db8 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:"
ret = -1
seed = 189487301
rfd = 4
debug_save = 0
debug_flag = 0
dont_fork_cnt = 0
n_lst = 0x76
p = 0x7fff8b3eb2de ""
__FUNCTION__ = "main"
quit
—
Reply to this email directly or view it on GitHub.