tried latest branch 4.0, also segfault similar backtrace Kelvin Chua On Mon, Dec 9, 2013 at 7:13 PM, Daniel-Constantin Mierla <miconda(a)gmail.com>wrote;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 &lt;miconda(a)gmail.com > 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(a)gmail.com> >> 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(a)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 > >

#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 &lt;miconda(a)gmail.com > 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(a)gmail.com> >> 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(a)gmail.com>> >>> 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(a)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 > >

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 &lt;miconda(a)gmail.com > 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(a)gmail.com> >> 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(a)gmail.com>> >>> 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(a)gmail.com>>> >>>> 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(a)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 > >

thanks! can't wait for the 4.0.5 Kelvin Chua On Thu, Dec 12, 2013 at 10:16 PM, Daniel-Constantin Mierla < miconda(a)gmail.com&gt; wrote: