#### Use Case Description:
I'm trying to log "user last register status" using function
`jsonrpc_notification` from module `jsonrpc-c`
##### invoke in kamailio.cfg:
`jsonrpc_notification("last_reg", "{'user': '$au', 'data':['$Ts', '$au', '$ct',
'$ua', '$sel(received.proto_ip_port)']}");`
**according to
[doc](http://kamailio.org/docs/modules/4.3.x/modules/jsonrpc-c.html#idp2463944):**
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 )
#### Observation and Test:
##### Crash occurs
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
```
##### Test
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
##### the more `jsonrpc_notification` call we've made, the quicker kamailio out
of memory.
#### MEMDBG
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:
-----------------------------
```
#### crash on jsonrpc back trace
```
#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:[email protected]: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:
https://github.com/kamailio/kamailio/issues/296_______________________________________________
sr-dev mailing list
[email protected]
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
