following is backtrace:
#0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to"
Kelvin Chua
Hello,
can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release.
Cheers, Daniel
On 09/12/13 10:35, Kelvin Chua wrote:
following is backtrace:
#0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to"
Kelvin Chua
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
tried latest branch 4.0, also segfault similar backtrace
Kelvin Chua
On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla miconda@gmail.comwrote:
Hello,
can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release.
Cheers, Daniel
On 09/12/13 10:35, Kelvin Chua wrote:
following is backtrace:
#0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to"
Kelvin Chua
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing listsr-users@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message.
Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically?
Cheers, Daniel
On 09/12/13 16:45, Kelvin Chua wrote:
tried latest branch 4.0, also segfault similar backtrace
Kelvin Chua
On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com> wrote:
Hello, can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release. Cheers, Daniel On 09/12/13 10:35, Kelvin Chua wrote:following is backtrace: #0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to" Kelvin Chua _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
i didn's set any global parameter, just the defaults. yes, i can reproduce it consistently, i just send an INVITE and CANCEL while kamailio is trying the destinations. (serial forks to non-existent IP) after i send the CANCEL, kamailio will crash.
below is the MEMDBG=1 syslog:
Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22191]: WARNING: tm [t_lookup.c:1564]: t_unref(): WARNING: script writer didn't release transaction Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22209]: : <core> [pass_fd.c:293]: receive_fd(): ERROR: receive_fd: EOF on 13 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:788]: handle_sigs(): child process 22189 exited by a signal 6 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:791]: handle_sigs(): core was generated Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1) Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157)
Kelvin Chua
On Mon, Dec 9, 2013 at 11:54 PM, Daniel-Constantin Mierla <miconda@gmail.com
wrote:
Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message.
Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically?
Cheers, Daniel
On 09/12/13 16:45, Kelvin Chua wrote:
tried latest branch 4.0, also segfault similar backtrace
Kelvin Chua
On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Hello,
can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release.
Cheers, Daniel
On 09/12/13 10:35, Kelvin Chua wrote:
following is backtrace:
#0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to"
Kelvin Chua
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing listsr-users@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
It is a different place now, can you give the bt full output?
Cheers, Daniel
On 09/12/13 17:18, Kelvin Chua wrote:
i didn's set any global parameter, just the defaults. yes, i can reproduce it consistently, i just send an INVITE and CANCEL while kamailio is trying the destinations. (serial forks to non-existent IP) after i send the CANCEL, kamailio will crash.
below is the MEMDBG=1 syslog:
Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22191]: WARNING: tm [t_lookup.c:1564]: t_unref(): WARNING: script writer didn't release transaction Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22209]: : <core> [pass_fd.c:293]: receive_fd(): ERROR: receive_fd: EOF on 13 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:788]: handle_sigs(): child process 22189 exited by a signal 6 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:791]: handle_sigs(): core was generated Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1) Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157)
Kelvin Chua
On Mon, Dec 9, 2013 at 11:54 PM, Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com> wrote:
Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message. Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically? Cheers, Daniel On 09/12/13 16:45, Kelvin Chua wrote:tried latest branch 4.0, also segfault similar backtrace Kelvin Chua On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Hello, can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release. Cheers, Daniel On 09/12/13 10:35, Kelvin Chua wrote:following is backtrace: #0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to" Kelvin Chua _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda
#0 0x00007fbf3aee9425 in raise () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #1 0x00007fbf3aeecb8b in abort () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #2 0x000000000054d710 in qm_free (qm=0x7fbf30414000, p=0x7fbf3088a9a8, file=0x7fbf38b85cb5 "tm: h_table.c", func=0x7fbf38b85e58 "free_cell", line=157) at mem/q_malloc.c:470 f = 0x7fbf3088a978 size = 0 next = 0x7fbf30449518 prev = 0x7fbf3088c660 __FUNCTION__ = "qm_free" #3 0x00007fbf38b19b10 in free_cell (dead_cell=0x7fbf30887de8) at h_table.c:157 b = 0x7fff7da2d4b0 " ֢}\377\177" i = 1 rpl = 0x7fbf30887de8 tt = 0x7fff7da2d9c0 foo = 0x22b7da2d3d0 cbs = 0x0 cbs_tmp = 0x0 __FUNCTION__ = "free_cell" #4 0x00007fbf38b4a486 in t_unref (p_msg=0x7fbf3abbf368) at t_lookup.c:1574 kr = 12 __FUNCTION__ = "t_unref" #5 0x00007fbf38b4e60b in w_t_unref (foo=0x7fbf3abbf368, flags=2147483649, bar=0x0) at tm.c:725 No locals. #6 0x00000000004db5bb in exec_post_script_cb (msg=0x7fbf3abbf368, type=REQUEST_CB_TYPE) at script_cb.c:195 cb = 0x7fbf3abf4fa0 flags = 2147483649 #7 0x00000000004a9cd8 in receive_msg ( buf=0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non". .., len=555, rcv_info=0x7fff7da2d680) at receive.c:227 msg = 0x7fbf3abbf368 ctx = {rec_lev = -1, run_flags = 0, last_retcode = 984293392, jmp_env = {{__jmpbuf = {140459304019208, 1204527218, 8881072, 0, 0, 0, 0, 140459312289652}, __mask_was_saved = 5, __saved_mask = {__val = { 0, 140459304039824, 1, 140459125283080, 1204527218, 2107823648, 1024, 6402790880, 140459125283080, 140735301211616, 5493883, 4087102589, 140459125283080, 16963, 140459125283080, 140735301211772}}}}} ret = 0 inb = { s = 0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"..., len = 555} __FUNCTION__ = "receive_msg" #8 0x000000000054148b in udp_rcv_loop () at udp_server.c:557 len = 555 buf = "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"... tmp = 0x7fff7da2d690 "\020ע}\377\177" from = 0x7fbf3abc4df0 fromlen = 16 ri = {src_ip = {af = 2, len = 4, u = {addrl = {8382069885, 140735301211920}, addr32 = {4087102589, 1, 2107823888, 32767}, addr16 = {15485, 62364, 1, 0, 55056, 32162, 32767, 0}, addr = "}<\234\363\001\000\000\000\020ע}\377\177\000"}}, dst_ip = {af = 2, len = 4, u = {addrl = { 489123792, 0}, addr32 = {489123792, 0, 0, 0}, addr16 = {28624, 7463, 0, 0, 0, 0, 0, 0}, addr = "\320o'\035", '\000' <repeats 11 times>}}, src_port = 17218, dst_port = 5060, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "CB}<\234\363\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 16963, sin_addr = {s_addr = 4087102589}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 16963, sin6_flowinfo = 4087102589, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = { 0, 0, 0, 0}}}, sin6_scope_id = 0}}, bind_address = 0x7fbf3aaf03d8, proto = 1 '\001'} __FUNCTION__ = "udp_rcv_loop" #9 0x000000000046ce9c in main_loop () at main.c:1638 i = 0 pid = 0 si = 0x7fbf3aaf03d8 si_desc = "udp receiver child=0 sock=2X8.1X1.3X.2X:5060\000\364\357:\000\,5\277\177\000\000r\240\313G\000\000\000\000\000DA\000\000\000\000\000\300٢}\377\177", '\000' <repeats 18 times>"\360, ע}\377\177\000\000\232\373K\000\000\000\000\000\020آ}\377\177\000\000\240Ó\000\000\000\000" nrprocs = 4 __FUNCTION__ = "main_loop" #10 0x000000000046fec0 in main (argc=15, argv=0x7fff7da2d9c8) at main.c:2566 cfg_stream = 0xfd6010 c = -1 r = 0 tmp = 0x7fff7da2df48 "" tmp_len = 0 port = 4274515 proto = 0 options = 0x5e5c10 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:" ret = -1 seed = 3558558127 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x5d0670 p = 0xc2 <Address 0xc2 out of bounds> __FUNCTION__ = "main"
...cut
Kelvin Chua
On Tue, Dec 10, 2013 at 1:04 AM, Daniel-Constantin Mierla <miconda@gmail.com
wrote:
It is a different place now, can you give the bt full output?
Cheers, Daniel
On 09/12/13 17:18, Kelvin Chua wrote:
i didn's set any global parameter, just the defaults. yes, i can reproduce it consistently, i just send an INVITE and CANCEL while kamailio is trying the destinations. (serial forks to non-existent IP) after i send the CANCEL, kamailio will crash.
below is the MEMDBG=1 syslog:
Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22191]: WARNING: tm [t_lookup.c:1564]: t_unref(): WARNING: script writer didn't release transaction Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22209]: : <core> [pass_fd.c:293]: receive_fd(): ERROR: receive_fd: EOF on 13 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:788]: handle_sigs(): child process 22189 exited by a signal 6 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:791]: handle_sigs(): core was generated Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1) Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157)
Kelvin Chua
On Mon, Dec 9, 2013 at 11:54 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message.
Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically?
Cheers, Daniel
On 09/12/13 16:45, Kelvin Chua wrote:
tried latest branch 4.0, also segfault similar backtrace
Kelvin Chua
On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Hello,
can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release.
Cheers, Daniel
On 09/12/13 10:35, Kelvin Chua wrote:
following is backtrace:
#0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to"
Kelvin Chua
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing listsr-users@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
This is for an ACK and slightly different case -- it can happen only with MEMDBG=1 -- I will look over it as well.
Can you run another test with:
mem_safety=1
?
Still keeping MEMDBG=1
Daniel
On 09/12/13 19:22, Kelvin Chua wrote:
#0 0x00007fbf3aee9425 in raise () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #1 0x00007fbf3aeecb8b in abort () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #2 0x000000000054d710 in qm_free (qm=0x7fbf30414000, p=0x7fbf3088a9a8, file=0x7fbf38b85cb5 "tm: h_table.c", func=0x7fbf38b85e58 "free_cell", line=157) at mem/q_malloc.c:470 f = 0x7fbf3088a978 size = 0 next = 0x7fbf30449518 prev = 0x7fbf3088c660 __FUNCTION__ = "qm_free" #3 0x00007fbf38b19b10 in free_cell (dead_cell=0x7fbf30887de8) at h_table.c:157 b = 0x7fff7da2d4b0 " ֢}\377\177" i = 1 rpl = 0x7fbf30887de8 tt = 0x7fff7da2d9c0 foo = 0x22b7da2d3d0 cbs = 0x0 cbs_tmp = 0x0 __FUNCTION__ = "free_cell" #4 0x00007fbf38b4a486 in t_unref (p_msg=0x7fbf3abbf368) at t_lookup.c:1574 kr = 12 __FUNCTION__ = "t_unref" #5 0x00007fbf38b4e60b in w_t_unref (foo=0x7fbf3abbf368, flags=2147483649, bar=0x0) at tm.c:725 No locals. #6 0x00000000004db5bb in exec_post_script_cb (msg=0x7fbf3abbf368, type=REQUEST_CB_TYPE) at script_cb.c:195 cb = 0x7fbf3abf4fa0 flags = 2147483649 #7 0x00000000004a9cd8 in receive_msg ( buf=0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non". .., len=555, rcv_info=0x7fff7da2d680) at receive.c:227 msg = 0x7fbf3abbf368 ctx = {rec_lev = -1, run_flags = 0, last_retcode = 984293392, jmp_env = {{__jmpbuf = {140459304019208, 1204527218, 8881072, 0, 0, 0, 0, 140459312289652}, __mask_was_saved = 5, __saved_mask = {__val = { 0, 140459304039824, 1, 140459125283080, 1204527218, 2107823648, 1024, 6402790880, 140459125283080, 140735301211616, 5493883, 4087102589, 140459125283080, 16963, 140459125283080, 140735301211772}}}}} ret = 0 inb = { s = 0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"..., len = 555} __FUNCTION__ = "receive_msg" #8 0x000000000054148b in udp_rcv_loop () at udp_server.c:557 len = 555 buf = "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"... tmp = 0x7fff7da2d690 "\020ע}\377\177" from = 0x7fbf3abc4df0 fromlen = 16 ri = {src_ip = {af = 2, len = 4, u = {addrl = {8382069885, 140735301211920}, addr32 = {4087102589, 1, 2107823888, 32767}, addr16 = {15485, 62364, 1, 0, 55056, 32162, 32767, 0}, addr = "}<\234\363\001\000\000\000\020ע}\377\177\000"}}, dst_ip = {af = 2, len = 4, u = {addrl = { 489123792, 0}, addr32 = {489123792, 0, 0, 0}, addr16 = {28624, 7463, 0, 0, 0, 0, 0, 0}, addr = "\320o'\035", '\000' <repeats 11 times>}}, src_port = 17218, dst_port = 5060, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "CB}<\234\363\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 16963, sin_addr = {s_addr = 4087102589}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 16963, sin6_flowinfo = 4087102589, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = { 0, 0, 0, 0}}}, sin6_scope_id = 0}}, bind_address = 0x7fbf3aaf03d8, proto = 1 '\001'} __FUNCTION__ = "udp_rcv_loop" #9 0x000000000046ce9c in main_loop () at main.c:1638 i = 0 pid = 0 si = 0x7fbf3aaf03d8 si_desc = "udp receiver child=0 sock=2X8.1X1.3X.2X:5060\000\364\357:\000\,5\277\177\000\000r\240\313G\000\000\000\000\000DA\000\000\000\000\000\300٢}\377\177", '\000' <repeats 18 times>"\360, ע}\377\177\000\000\232\373K\000\000\000\000\000\020آ}\377\177\000\000\240Ó\000\000\000\000" nrprocs = 4 __FUNCTION__ = "main_loop" #10 0x000000000046fec0 in main (argc=15, argv=0x7fff7da2d9c8) at main.c:2566 cfg_stream = 0xfd6010 c = -1 r = 0 tmp = 0x7fff7da2df48 "" tmp_len = 0 port = 4274515 proto = 0 options = 0x5e5c10 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:" ret = -1 seed = 3558558127 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x5d0670 p = 0xc2 <Address 0xc2 out of bounds> __FUNCTION__ = "main"
...cut
Kelvin Chua
On Tue, Dec 10, 2013 at 1:04 AM, Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com> wrote:
It is a different place now, can you give the bt full output? Cheers, Daniel On 09/12/13 17:18, Kelvin Chua wrote:i didn's set any global parameter, just the defaults. yes, i can reproduce it consistently, i just send an INVITE and CANCEL while kamailio is trying the destinations. (serial forks to non-existent IP) after i send the CANCEL, kamailio will crash. below is the MEMDBG=1 syslog: Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22191]: WARNING: tm [t_lookup.c:1564]: t_unref(): WARNING: script writer didn't release transaction Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22209]: : <core> [pass_fd.c:293]: receive_fd(): ERROR: receive_fd: EOF on 13 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:788]: handle_sigs(): child process 22189 exited by a signal 6 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:791]: handle_sigs(): core was generated Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1) Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) Kelvin Chua On Mon, Dec 9, 2013 at 11:54 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message. Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically? Cheers, Daniel On 09/12/13 16:45, Kelvin Chua wrote:tried latest branch 4.0, also segfault similar backtrace Kelvin Chua On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Hello, can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release. Cheers, Daniel On 09/12/13 10:35, Kelvin Chua wrote:following is backtrace: #0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to" Kelvin Chua _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda
Hi Daniel,
if i turn on mem_safety=1 it doesn't crash.
here is the syslog Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e88b8), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e71d0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f47f0), called from tm: h_table.c: free_cell(159), first free tm: h_table.c: free_cell(159) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e8790), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e87f8), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e7148), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5c98), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5b10), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e90b8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e94a8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e9898), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e9c80), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f4170), called from tm: h_table.c: free_cell(189), first free tm: h_table.c: free_cell(189) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5de0), called from tm: h_table.c: free_cell(244), first free tm: h_table.c: free_cell(244) - aborting ..cut Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ee528), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ecae0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ee238), called from tm: h_table.c: free_cell(159), first free tm: h_table.c: free_cell(159) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e8790), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e7148), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb4c8), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb630), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb6d0), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eec48), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e88b8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f4c18), called from tm: h_table.c: free_cell(189), first free tm: h_table.c: free_cell(189) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb778), called from tm: h_table.c: free_cell(244), first free tm: h_table.c: free_cell(244) - aborting
Kelvin Chua
On Tue, Dec 10, 2013 at 7:28 AM, Daniel-Constantin Mierla <miconda@gmail.com
wrote:
This is for an ACK and slightly different case -- it can happen only with MEMDBG=1 -- I will look over it as well.
Can you run another test with:
mem_safety=1
?
Still keeping MEMDBG=1
Daniel
On 09/12/13 19:22, Kelvin Chua wrote:
#0 0x00007fbf3aee9425 in raise () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #1 0x00007fbf3aeecb8b in abort () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #2 0x000000000054d710 in qm_free (qm=0x7fbf30414000, p=0x7fbf3088a9a8, file=0x7fbf38b85cb5 "tm: h_table.c", func=0x7fbf38b85e58 "free_cell", line=157) at mem/q_malloc.c:470 f = 0x7fbf3088a978 size = 0 next = 0x7fbf30449518 prev = 0x7fbf3088c660 __FUNCTION__ = "qm_free" #3 0x00007fbf38b19b10 in free_cell (dead_cell=0x7fbf30887de8) at h_table.c:157 b = 0x7fff7da2d4b0 " ֢}\377\177" i = 1 rpl = 0x7fbf30887de8 tt = 0x7fff7da2d9c0 foo = 0x22b7da2d3d0 cbs = 0x0 cbs_tmp = 0x0 __FUNCTION__ = "free_cell" #4 0x00007fbf38b4a486 in t_unref (p_msg=0x7fbf3abbf368) at t_lookup.c:1574 kr = 12 __FUNCTION__ = "t_unref" #5 0x00007fbf38b4e60b in w_t_unref (foo=0x7fbf3abbf368, flags=2147483649, bar=0x0) at tm.c:725 No locals. #6 0x00000000004db5bb in exec_post_script_cb (msg=0x7fbf3abbf368, type=REQUEST_CB_TYPE) at script_cb.c:195 cb = 0x7fbf3abf4fa0 flags = 2147483649 #7 0x00000000004a9cd8 in receive_msg ( buf=0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non". .., len=555, rcv_info=0x7fff7da2d680) at receive.c:227 msg = 0x7fbf3abbf368 ctx = {rec_lev = -1, run_flags = 0, last_retcode = 984293392, jmp_env = {{__jmpbuf = {140459304019208, 1204527218, 8881072, 0, 0, 0, 0, 140459312289652}, __mask_was_saved = 5, __saved_mask = {__val = { 0, 140459304039824, 1, 140459125283080, 1204527218, 2107823648, 1024, 6402790880, 140459125283080, 140735301211616, 5493883, 4087102589, 140459125283080, 16963, 140459125283080, 140735301211772}}}}} ret = 0 inb = { s = 0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"..., len = 555} __FUNCTION__ = "receive_msg" #8 0x000000000054148b in udp_rcv_loop () at udp_server.c:557 len = 555 buf = "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"... tmp = 0x7fff7da2d690 "\020ע}\377\177" from = 0x7fbf3abc4df0 fromlen = 16 ri = {src_ip = {af = 2, len = 4, u = {addrl = {8382069885, 140735301211920}, addr32 = {4087102589, 1, 2107823888, 32767}, addr16 = {15485, 62364, 1, 0, 55056, 32162, 32767, 0}, addr = "}<\234\363\001\000\000\000\020ע}\377\177\000"}}, dst_ip = {af = 2, len = 4, u = {addrl = { 489123792, 0}, addr32 = {489123792, 0, 0, 0}, addr16 = {28624, 7463, 0, 0, 0, 0, 0, 0}, addr = "\320o'\035", '\000' <repeats 11 times>}}, src_port = 17218, dst_port = 5060, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "CB}<\234\363\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 16963, sin_addr = {s_addr = 4087102589}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 16963, sin6_flowinfo = 4087102589, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = { 0, 0, 0, 0}}}, sin6_scope_id = 0}}, bind_address = 0x7fbf3aaf03d8, proto = 1 '\001'} __FUNCTION__ = "udp_rcv_loop" #9 0x000000000046ce9c in main_loop () at main.c:1638 i = 0 pid = 0 si = 0x7fbf3aaf03d8 si_desc = "udp receiver child=0 sock=2X8.1X1.3X.2X:5060\000\364\357:\000\,5\277\177\000\000r\240\313G\000\000\000\000\000DA\000\000\000\000\000\300٢}\377\177", '\000' <repeats 18 times>"\360, ע}\377\177\000\000\232\373K\000\000\000\000\000\020آ}\377\177\000\000\240Ó\000\000\000\000" nrprocs = 4 __FUNCTION__ = "main_loop" #10 0x000000000046fec0 in main (argc=15, argv=0x7fff7da2d9c8) at main.c:2566 cfg_stream = 0xfd6010 c = -1 r = 0 tmp = 0x7fff7da2df48 "" tmp_len = 0 port = 4274515 proto = 0 options = 0x5e5c10 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:" ret = -1 seed = 3558558127 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x5d0670 p = 0xc2 <Address 0xc2 out of bounds> __FUNCTION__ = "main"
...cut
Kelvin Chua
On Tue, Dec 10, 2013 at 1:04 AM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
It is a different place now, can you give the bt full output?
Cheers, Daniel
On 09/12/13 17:18, Kelvin Chua wrote:
i didn's set any global parameter, just the defaults. yes, i can reproduce it consistently, i just send an INVITE and CANCEL while kamailio is trying the destinations. (serial forks to non-existent IP) after i send the CANCEL, kamailio will crash.
below is the MEMDBG=1 syslog:
Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22191]: WARNING: tm [t_lookup.c:1564]: t_unref(): WARNING: script writer didn't release transaction Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22209]: : <core> [pass_fd.c:293]: receive_fd(): ERROR: receive_fd: EOF on 13 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:788]: handle_sigs(): child process 22189 exited by a signal 6 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:791]: handle_sigs(): core was generated Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1) Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157)
Kelvin Chua
On Mon, Dec 9, 2013 at 11:54 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message.
Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically?
Cheers, Daniel
On 09/12/13 16:45, Kelvin Chua wrote:
tried latest branch 4.0, also segfault similar backtrace
Kelvin Chua
On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Hello,
can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release.
Cheers, Daniel
On 09/12/13 10:35, Kelvin Chua wrote:
following is backtrace:
#0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to"
Kelvin Chua
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing listsr-users@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Hello,
I pushed a patch recently that will catch this situation even without MEMDBG=1 at compile time. It was used with former default memory manager f_malloc, but for what so ever reason was not on q_malloc.
The details provided are good to look further and avoid those double frees.
Cheers, Daniel
On 12/12/13 11:33, Kelvin Chua wrote:
Hi Daniel,
if i turn on mem_safety=1 it doesn't crash.
here is the syslog Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e88b8), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e71d0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f47f0), called from tm: h_table.c: free_cell(159), first free tm: h_table.c: free_cell(159) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e8790), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e87f8), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e7148), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5c98), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5b10), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e90b8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e94a8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e9898), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e9c80), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f4170), called from tm: h_table.c: free_cell(189), first free tm: h_table.c: free_cell(189) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5de0), called from tm: h_table.c: free_cell(244), first free tm: h_table.c: free_cell(244) - aborting ..cut Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ee528), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ecae0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ee238), called from tm: h_table.c: free_cell(159), first free tm: h_table.c: free_cell(159) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e8790), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e7148), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb4c8), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb630), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb6d0), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eec48), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e88b8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f4c18), called from tm: h_table.c: free_cell(189), first free tm: h_table.c: free_cell(189) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb778), called from tm: h_table.c: free_cell(244), first free tm: h_table.c: free_cell(244) - aborting
Kelvin Chua
On Tue, Dec 10, 2013 at 7:28 AM, Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com> wrote:
This is for an ACK and slightly different case -- it can happen only with MEMDBG=1 -- I will look over it as well. Can you run another test with: mem_safety=1 ? Still keeping MEMDBG=1 Daniel On 09/12/13 19:22, Kelvin Chua wrote:#0 0x00007fbf3aee9425 in raise () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #1 0x00007fbf3aeecb8b in abort () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #2 0x000000000054d710 in qm_free (qm=0x7fbf30414000, p=0x7fbf3088a9a8, file=0x7fbf38b85cb5 "tm: h_table.c", func=0x7fbf38b85e58 "free_cell", line=157) at mem/q_malloc.c:470 f = 0x7fbf3088a978 size = 0 next = 0x7fbf30449518 prev = 0x7fbf3088c660 __FUNCTION__ = "qm_free" #3 0x00007fbf38b19b10 in free_cell (dead_cell=0x7fbf30887de8) at h_table.c:157 b = 0x7fff7da2d4b0 " ֢}\377\177" i = 1 rpl = 0x7fbf30887de8 tt = 0x7fff7da2d9c0 foo = 0x22b7da2d3d0 cbs = 0x0 cbs_tmp = 0x0 __FUNCTION__ = "free_cell" #4 0x00007fbf38b4a486 in t_unref (p_msg=0x7fbf3abbf368) at t_lookup.c:1574 kr = 12 __FUNCTION__ = "t_unref" #5 0x00007fbf38b4e60b in w_t_unref (foo=0x7fbf3abbf368, flags=2147483649, bar=0x0) at tm.c:725 No locals. #6 0x00000000004db5bb in exec_post_script_cb (msg=0x7fbf3abbf368, type=REQUEST_CB_TYPE) at script_cb.c:195 cb = 0x7fbf3abf4fa0 flags = 2147483649 #7 0x00000000004a9cd8 in receive_msg ( buf=0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username=\"kelvin\",realm=\"2X8.1X1.3X.2X\",non". .., len=555, rcv_info=0x7fff7da2d680) at receive.c:227 msg = 0x7fbf3abbf368 ctx = {rec_lev = -1, run_flags = 0, last_retcode = 984293392, jmp_env = {{__jmpbuf = {140459304019208, 1204527218, 8881072, 0, 0, 0, 0, 140459312289652}, __mask_was_saved = 5, __saved_mask = {__val = { 0, 140459304039824, 1, 140459125283080, 1204527218, 2107823648, 1024, 6402790880, 140459125283080, 140735301211616, 5493883, 4087102589, 140459125283080, 16963, 140459125283080, 140735301211772}}}}} ret = 0 inb = { s = 0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username=\"kelvin\",realm=\"2X8.1X1.3X.2X\",non"..., len = 555} __FUNCTION__ = "receive_msg" #8 0x000000000054148b in udp_rcv_loop () at udp_server.c:557 len = 555 buf = "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username=\"kelvin\",realm=\"2X8.1X1.3X.2X\",non"... tmp = 0x7fff7da2d690 "\020ע}\377\177" from = 0x7fbf3abc4df0 fromlen = 16 ri = {src_ip = {af = 2, len = 4, u = {addrl = {8382069885, 140735301211920}, addr32 = {4087102589, 1, 2107823888, 32767}, addr16 = {15485, 62364, 1, 0, 55056, 32162, 32767, 0}, addr = "}<\234\363\001\000\000\000\020ע}\377\177\000"}}, dst_ip = {af = 2, len = 4, u = {addrl = { 489123792, 0}, addr32 = {489123792, 0, 0, 0}, addr16 = {28624, 7463, 0, 0, 0, 0, 0, 0}, addr = "\320o'\035", '\000' <repeats 11 times>}}, src_port = 17218, dst_port = 5060, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "CB}<\234\363\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 16963, sin_addr = {s_addr = 4087102589}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 16963, sin6_flowinfo = 4087102589, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = { 0, 0, 0, 0}}}, sin6_scope_id = 0}}, bind_address = 0x7fbf3aaf03d8, proto = 1 '\001'} __FUNCTION__ = "udp_rcv_loop" #9 0x000000000046ce9c in main_loop () at main.c:1638 i = 0 pid = 0 si = 0x7fbf3aaf03d8 si_desc = "udp receiver child=0 sock=2X8.1X1.3X.2X:5060\000\364\357:\000\\,5\277\177\000\000r\240\313G\000\000\000\000\000DA\000\000\000\000\000\300٢}\377\177", '\000' <repeats 18 times>"\360, ע}\377\177\000\000\232\373K\000\000\000\000\000\020آ}\377\177\000\000\240Ó\000\000\000\000" nrprocs = 4 __FUNCTION__ = "main_loop" #10 0x000000000046fec0 in main (argc=15, argv=0x7fff7da2d9c8) at main.c:2566 cfg_stream = 0xfd6010 c = -1 r = 0 tmp = 0x7fff7da2df48 "" tmp_len = 0 port = 4274515 proto = 0 options = 0x5e5c10 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:" ret = -1 seed = 3558558127 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x5d0670 p = 0xc2 <Address 0xc2 out of bounds> __FUNCTION__ = "main" ...cut Kelvin Chua On Tue, Dec 10, 2013 at 1:04 AM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: It is a different place now, can you give the bt full output? Cheers, Daniel On 09/12/13 17:18, Kelvin Chua wrote:i didn's set any global parameter, just the defaults. yes, i can reproduce it consistently, i just send an INVITE and CANCEL while kamailio is trying the destinations. (serial forks to non-existent IP) after i send the CANCEL, kamailio will crash. below is the MEMDBG=1 syslog: Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22191]: WARNING: tm [t_lookup.c:1564]: t_unref(): WARNING: script writer didn't release transaction Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22209]: : <core> [pass_fd.c:293]: receive_fd(): ERROR: receive_fd: EOF on 13 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:788]: handle_sigs(): child process 22189 exited by a signal 6 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:791]: handle_sigs(): core was generated Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1) Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) Kelvin Chua On Mon, Dec 9, 2013 at 11:54 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message. Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically? Cheers, Daniel On 09/12/13 16:45, Kelvin Chua wrote:tried latest branch 4.0, also segfault similar backtrace Kelvin Chua On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla <miconda@gmail.com <mailto:miconda@gmail.com>> wrote: Hello, can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release. Cheers, Daniel On 09/12/13 10:35, Kelvin Chua wrote:following is backtrace: #0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to" Kelvin Chua _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org <mailto:sr-users@lists.sip-router.org> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda-- Daniel-Constantin Mierla -http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> -http://www.linkedin.com/in/miconda
thanks! can't wait for the 4.0.5
Kelvin Chua
On Thu, Dec 12, 2013 at 10:16 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Hello,
I pushed a patch recently that will catch this situation even without MEMDBG=1 at compile time. It was used with former default memory manager f_malloc, but for what so ever reason was not on q_malloc.
The details provided are good to look further and avoid those double frees.
Cheers, Daniel
On 12/12/13 11:33, Kelvin Chua wrote:
Hi Daniel,
if i turn on mem_safety=1 it doesn't crash.
here is the syslog Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e88b8), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e71d0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f47f0), called from tm: h_table.c: free_cell(159), first free tm: h_table.c: free_cell(159) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e8790), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323)
- aborting
Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e87f8), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e7148), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5c98), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323)
- aborting
Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5b10), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e90b8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e94a8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e9898), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e9c80), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f4170), called from tm: h_table.c: free_cell(189), first free tm: h_table.c: free_cell(189) - aborting Dec 12 05:32:22 kelvin /usr/local/sbin/kamailio[30189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e5de0), called from tm: h_table.c: free_cell(244), first free tm: h_table.c: free_cell(244) - aborting ..cut Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ee528), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ecae0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581ee238), called from tm: h_table.c: free_cell(159), first free tm: h_table.c: free_cell(159) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e8790), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323)
- aborting
Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e7148), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb4c8), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb630), called from dialog: dlg_handlers.c: dlg_iuid_sfree(323), first free dialog: dlg_handlers.c: dlg_iuid_sfree(323)
- aborting
Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb6d0), called from tm: h_table.c: free_cell(178), first free tm: h_table.c: free_cell(178) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eec48), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581e88b8), called from tm: h_table.c: free_cell(186), first free tm: h_table.c: free_cell(186) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581f4c18), called from tm: h_table.c: free_cell(189), first free tm: h_table.c: free_cell(189) - aborting Dec 12 05:32:23 kelvin /usr/local/sbin/kamailio[30190]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7eff581eb778), called from tm: h_table.c: free_cell(244), first free tm: h_table.c: free_cell(244) - aborting
Kelvin Chua
On Tue, Dec 10, 2013 at 7:28 AM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
This is for an ACK and slightly different case -- it can happen only with MEMDBG=1 -- I will look over it as well.
Can you run another test with:
mem_safety=1
?
Still keeping MEMDBG=1
Daniel
On 09/12/13 19:22, Kelvin Chua wrote:
#0 0x00007fbf3aee9425 in raise () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #1 0x00007fbf3aeecb8b in abort () from /lib/x86_64-linux-gnu/libc.so.6 No symbol table info available. #2 0x000000000054d710 in qm_free (qm=0x7fbf30414000, p=0x7fbf3088a9a8, file=0x7fbf38b85cb5 "tm: h_table.c", func=0x7fbf38b85e58 "free_cell", line=157) at mem/q_malloc.c:470 f = 0x7fbf3088a978 size = 0 next = 0x7fbf30449518 prev = 0x7fbf3088c660 __FUNCTION__ = "qm_free" #3 0x00007fbf38b19b10 in free_cell (dead_cell=0x7fbf30887de8) at h_table.c:157 b = 0x7fff7da2d4b0 " ֢}\377\177" i = 1 rpl = 0x7fbf30887de8 tt = 0x7fff7da2d9c0 foo = 0x22b7da2d3d0 cbs = 0x0 cbs_tmp = 0x0 __FUNCTION__ = "free_cell" #4 0x00007fbf38b4a486 in t_unref (p_msg=0x7fbf3abbf368) at t_lookup.c:1574 kr = 12 __FUNCTION__ = "t_unref" #5 0x00007fbf38b4e60b in w_t_unref (foo=0x7fbf3abbf368, flags=2147483649, bar=0x0) at tm.c:725 No locals. #6 0x00000000004db5bb in exec_post_script_cb (msg=0x7fbf3abbf368, type=REQUEST_CB_TYPE) at script_cb.c:195 cb = 0x7fbf3abf4fa0 flags = 2147483649 #7 0x00000000004a9cd8 in receive_msg ( buf=0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non". .., len=555, rcv_info=0x7fff7da2d680) at receive.c:227 msg = 0x7fbf3abbf368 ctx = {rec_lev = -1, run_flags = 0, last_retcode = 984293392, jmp_env = {{__jmpbuf = {140459304019208, 1204527218, 8881072, 0, 0, 0, 0, 140459312289652}, __mask_was_saved = 5, __saved_mask = {__val = { 0, 140459304039824, 1, 140459125283080, 1204527218, 2107823648, 1024, 6402790880, 140459125283080, 140735301211616, 5493883, 4087102589, 140459125283080, 16963, 140459125283080, 140735301211772}}}}} ret = 0 inb = { s = 0x9263c0 "ACK sip:18X88X441X1@2X8.1X1.3X.2XSIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"..., len = 555} __FUNCTION__ = "receive_msg" #8 0x000000000054148b in udp_rcv_loop () at udp_server.c:557 len = 555 buf = "ACK sip:18X88X441X1@2X8.1X1.3X.2X SIP/2.0\r\nVia: SIP/2.0/UDP 125.60.156.243:17218;rport;branch=z9hG4bKogunmjtk\r\nMax-Forwards: 16\r\nProxy-Authorization: Digest username="kelvin",realm="2X8.1X1.3X.2X",non"... tmp = 0x7fff7da2d690 "\020ע}\377\177" from = 0x7fbf3abc4df0 fromlen = 16 ri = {src_ip = {af = 2, len = 4, u = {addrl = {8382069885, 140735301211920}, addr32 = {4087102589, 1, 2107823888, 32767}, addr16 = {15485, 62364, 1, 0, 55056, 32162, 32767, 0}, addr = "}<\234\363\001\000\000\000\020ע}\377\177\000"}}, dst_ip = {af = 2, len = 4, u = {addrl = { 489123792, 0}, addr32 = {489123792, 0, 0, 0}, addr16 = {28624, 7463, 0, 0, 0, 0, 0, 0}, addr = "\320o'\035", '\000' <repeats 11 times>}}, src_port = 17218, dst_port = 5060, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "CB}<\234\363\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 16963, sin_addr = {s_addr = 4087102589}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 16963, sin6_flowinfo = 4087102589, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = { 0, 0, 0, 0}}}, sin6_scope_id = 0}}, bind_address = 0x7fbf3aaf03d8, proto = 1 '\001'} __FUNCTION__ = "udp_rcv_loop" #9 0x000000000046ce9c in main_loop () at main.c:1638 i = 0 pid = 0 si = 0x7fbf3aaf03d8 si_desc = "udp receiver child=0 sock=2X8.1X1.3X.2X:5060\000\364\357:\000\,5\277\177\000\000r\240\313G\000\000\000\000\000DA\000\000\000\000\000\300٢}\377\177", '\000' <repeats 18 times>"\360, ע}\377\177\000\000\232\373K\000\000\000\000\000\020آ}\377\177\000\000\240Ó\000\000\000\000" nrprocs = 4 __FUNCTION__ = "main_loop" #10 0x000000000046fec0 in main (argc=15, argv=0x7fff7da2d9c8) at main.c:2566 cfg_stream = 0xfd6010 c = -1 r = 0 tmp = 0x7fff7da2df48 "" tmp_len = 0 port = 4274515 proto = 0 options = 0x5e5c10 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:" ret = -1 seed = 3558558127 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x5d0670 p = 0xc2 <Address 0xc2 out of bounds> __FUNCTION__ = "main"
...cut
Kelvin Chua
On Tue, Dec 10, 2013 at 1:04 AM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
It is a different place now, can you give the bt full output?
Cheers, Daniel
On 09/12/13 17:18, Kelvin Chua wrote:
i didn's set any global parameter, just the defaults. yes, i can reproduce it consistently, i just send an INVITE and CANCEL while kamailio is trying the destinations. (serial forks to non-existent IP) after i send the CANCEL, kamailio will crash.
below is the MEMDBG=1 syslog:
Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22191]: WARNING: tm [t_lookup.c:1564]: t_unref(): WARNING: script writer didn't release transaction Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22189]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157) - aborting Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22209]: : <core> [pass_fd.c:293]: receive_fd(): ERROR: receive_fd: EOF on 13 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:788]: handle_sigs(): child process 22189 exited by a signal 6 Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ALERT: <core> [main.c:791]: handle_sigs(): core was generated Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1) Dec 9 11:12:14 kelvin /usr/local/sbin/kamailio[22186]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f35a60e01e0), called from tm: h_table.c: free_cell(157), first free tm: h_table.c: free_cell(157)
Kelvin Chua
On Mon, Dec 9, 2013 at 11:54 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Can you compile with MEMDBG=1 in Makefile.defs and try again? Might be a memory overwritten issues somewhere. Look in the syslog for memory related message.
Few more details needed ... do you have memjoin global parameter set? Is the situation reproducible, or it happens sporadically?
Cheers, Daniel
On 09/12/13 16:45, Kelvin Chua wrote:
tried latest branch 4.0, also segfault similar backtrace
Kelvin Chua
On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:
Hello,
can you try latest branch 4.0? There were some fixes for similar case. Soon will be a 4.0.5 release.
Cheers, Daniel
On 09/12/13 10:35, Kelvin Chua wrote:
following is backtrace:
#0 qm_detach_free (frag=0x7f91a4656170, qm=<optimized out>) at mem/q_malloc.c:269 prev = 0x7f91a4656170 next = 0x0 #1 qm_malloc (qm=0x7f91a429b000, size=3840) at mem/q_malloc.c:386 f = 0x7f91a4656170 hash = -1536859792 #2 0x000000000050977f in shm_malloc (size=3832) at parser/../mem/shm_mem.h:262 p = <optimized out> #3 sip_msg_shm_clone (org_msg=0x7f91ae9d7630, sip_msg_len=0x7fff56a2dde0, clone_lumps=0) at sip_msg_clone.c:502 len = 3832 hdr = <optimized out> new_hdr = <optimized out> last_hdr = <optimized out> via = <optimized out> prm = <optimized out> to_prm = <optimized out> new_to_prm = <optimized out> new_msg = <optimized out> p = <optimized out> __FUNCTION__ = "sip_msg_shm_clone" #4 0x00007f91ac989062 in build_cell (p_msg=0x7f91ae9d7630) at h_table.c:372 new_cell = 0x7f91a4656180 sip_msg_len = <optimized out> old = <optimized out> cbs = <optimized out> cbs_tmp = <optimized out> xold = <optimized out> #5 0x00007f91ac9b5fc6 in new_t (p_msg=0x7f91ae9d7630) at t_lookup.c:1357 new_cell = <optimized out> #6 t_newtran (p_msg=0x7f91ae9d7630) at t_lookup.c:1497 lret = <optimized out> my_err = <optimized out> canceled = <optimized out> __FUNCTION__ = "t_newtran" #7 0x00007f91ac9a99e0 in t_forward_cancel (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, tran=0x7fff56a2e2c0) at t_fwd.c:1607 t_invite = <optimized out> t = 0x0 ret = <optimized out> new_tran = <optimized out> dst = {send_sock = 0x63371f, to = {s = {sa_family = 54224, sa_data = "\003\255\221\177\000\000\020\300\220\256\221\177\000"}, sin = {sin_family = 54224, sin_port = 44291, sin_addr = {s_addr = 32657}, sin_zero = "\020\300\220\256\221\177\000"}, sin6 = {sin6_family = 54224, sin6_port = 44291, sin6_flowinfo = 32657, sin6_addr = {__in6_u = {__u6_addr8 = "\020\300\220\256\221\177\000\000\070\261W\000\000\000\000", __u6_addr16 = {49168, 44688, 32657, 0, 45368, 87, 0, 0}, __u6_addr32 = {2928721936, 32657, 5747000, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 96 '`', send_flags = { f = 225 '\341', blst_imask = 162 '\242'}} host = {s = 0x0, len = 0} port = <optimized out> __FUNCTION__ = "t_forward_cancel" #8 0x00007f91ac99ae15 in t_relay_to (p_msg=0x7f91ae9d7630, proxy=0x0, proto=0, replicate=0) at t_funcs.c:264 ret = 0 new_tran = <optimized out> t = <optimized out> dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, proto = 64 '@', send_flags = {f = 243 '\363', blst_imask = 162 '\242'}} port = <optimized out> host = {s = 0x7fff56a2eab8 "0[*\244\221\177", len = -1398876638} __FUNCTION__ = "t_relay_to"
Kelvin Chua
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing listsr-users@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
-- Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
-
Daniel-Constantin Mierla -
Kelvin Chua