This is during shut down clean up. Have you stopped kamailio manually? If not, aave you got more than one core file? If not, enable one core file per process.

Cheers, Daniel

On 09/09/15 17:03, Thibault Gueslin wrote:

It seems related to tsilo module and tm module:

#0 0x00007f6a7c8978f5 in lock_entry () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so

#0 0x00007f6a7c8978f5 in lock_entry () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so

(gdb) bt full

#0 0x00007f6a7c8978f5 in lock_entry () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so

No symbol table info available.

#1 0x00007f6a7c89d185 in ts_onreply () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so

No symbol table info available.

#2 0x00007f6a7f688f67 in run_trans_callbacks_internal () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#3 0x00007f6a7f68921e in run_trans_callbacks () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#4 0x00007f6a7f6043e0 in free_cell () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#5 0x00007f6a7f605c58 in free_hash_table () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#6 0x00007f6a7f67f9a1 in tm_shutdown () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#7 0x0000000000509142 in destroy_modules ()

No symbol table info available.

#8 0x00000000004ff559 in cleanup ()

No symbol table info available.

#9 0x00000000005004e8 in ?? ()

No symbol table info available.

#10 0x00000000005023cb in handle_sigs ()

No symbol table info available.

#11 0x0000000000506a3e in main_loop ()

No symbol table info available.

#12 0x000000000041b944 in main ()

No symbol table info available.

version: kamailio 4.3.1 (x86_64/linux)

flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, DBG_F_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES

ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB

poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.

id: unknown

compiled with gcc 4.9.2

I have seen some commits related to tm module after release 4.3.1

Should it work better in 4.3.2 ?

Regards

thibault

2015-09-09 14:26 GMT+02:00 Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com>:

Hello,

do you get other error messages in syslog before the one
"CRITICAL: ..."?

It is hard to say it is from something already known or new. Right
now there is an open issue for saving dialog variables in database
that was not yet sorted out. Another one related to tm and memory
manager, reported after 4.3.1, got a safety fix. Apart of these
two, I don't remember any active crash report for the moment.

If you get it very often, then it should be easy to catch and
troubleshoot properly. Can you run it so it generates a core file?

The easiest way is to run it as root, with 'ulimit -c unlimited'
executed before starting kamailio.

Can you share what operating system are you using and exact
version of kamailio (output of kamailio -v)?

Cheers,
Daniel


On 09/09/15 12:15, Thibault Gueslin wrote:

...

After upgrading to kamailio 4.3.1 and modifying the config, I get
this crash very often:
...

CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 21

ALERT: <core> [main.c:728]: handle_sigs(): child process 9341
exited by a signal 11

ALERT: <core> [main.c:731]: handle_sigs(): core was not generated

INFO: <core> [main.c:743]: handle_sigs(): terminating due to SIGCHLD

INFO: <core> [main.c:794]: sig_usr(): signal 15 received

INFO: <core> [main.c:794]: sig_usr(): signal 15 received

INFO: <core> [main.c:794]: sig_usr(): signal 15 received

...


Is it known ? or may be related to my config ?


Thank you


Thibault 



_______________________________________________
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://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/miconda
Book: SIP Routing With Kamailio - http://www.asipto.com
Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

Hello,

can you install the kamailio-dbg package to get access to debugging sysmbols? Once that package is installed, get the backtrace again and send it here.

Cheers, Daniel

On 10/09/15 10:55, Thibault Gueslin wrote:

I have done again the trace and obtained 2 core dumps:

Here is the second:

Core was generated by `kamailio -f /etc/kamailio/kamailio.cfg -w /tmp'.

Program terminated with signal SIGSEGV, Segmentation fault.

#0 0x0000000000000264 in ?? ()

(gdb) bt full

#0 0x0000000000000264 in ?? ()

No symbol table info available.

#1 0x00007fac88d39ebb in free_faked_req () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#2 0x00007fac88d3a1e7 in run_failure_handlers () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#3 0x00007fac88d3bf59 in ?? () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#4 0x00007fac88d43105 in relay_reply () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#5 0x00007fac88d4764b in reply_received () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#6 0x00000000004fbfee in ?? ()

No symbol table info available.

#7 0x000000000054074c in receive_msg ()

No symbol table info available.

#8 0x00000000005b806b in tcp_read_req ()

No symbol table info available.

#9 0x00000000005bb704 in ?? ()

No symbol table info available.

#10 0x00000000005c191a in tcp_receive_loop ()

No symbol table info available.

#11 0x00000000004d3447 in tcp_init_children ()

No symbol table info available.

#12 0x0000000000506863 in main_loop ()

No symbol table info available.

#13 0x000000000041b944 in main ()

No symbol table info available.

The scenario is to call a remote which is started. After starting the regisration, the call is presented, then kill the app, then started again, call is presented, wait while ringing....

After a few times, kamailio crashs.

(sent to mailing list now)

2015-09-09 17:20 GMT+02:00 Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com>:

This is during shut down clean up. Have you stopped kamailio
manually? If not, aave you got more than one core file? If not,
enable one core file per process.

Cheers,
Daniel


On 09/09/15 17:03, Thibault Gueslin wrote:

...

It seems related to tsilo module and tm module:


#0  0x00007f6a7c8978f5 in lock_entry () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so


#0  0x00007f6a7c8978f5 in lock_entry () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so

(gdb) bt full

#0  0x00007f6a7c8978f5 in lock_entry () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so

No symbol table info available.

#1  0x00007f6a7c89d185 in ts_onreply () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tsilo.so

No symbol table info available.

#2  0x00007f6a7f688f67 in run_trans_callbacks_internal () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#3  0x00007f6a7f68921e in run_trans_callbacks () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#4  0x00007f6a7f6043e0 in free_cell () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#5  0x00007f6a7f605c58 in free_hash_table () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#6  0x00007f6a7f67f9a1 in tm_shutdown () from
/usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so

No symbol table info available.

#7  0x0000000000509142 in destroy_modules ()

No symbol table info available.

#8  0x00000000004ff559 in cleanup ()

No symbol table info available.

#9  0x00000000005004e8 in ?? ()

No symbol table info available.

#10 0x00000000005023cb in handle_sigs ()

No symbol table info available.

#11 0x0000000000506a3e in main_loop ()

No symbol table info available.

#12 0x000000000041b944 in main ()

No symbol table info available.


version: kamailio 4.3.1 (x86_64/linux) 

flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS,
USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM,
SHM_MMAP, PKG_MALLOC, F_MALLOC, DBG_F_MALLOC, USE_FUTEX,
FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER,
USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES

ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN
16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB

poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.

id: unknown 

compiled with gcc 4.9.2


I have seen some commits related to tm module after release 4.3.1


Should it work better in 4.3.2 ?


Regards


thibault



2015-09-09 14:26 GMT+02:00 Daniel-Constantin Mierla
<miconda@gmail.com <mailto:miconda@gmail.com>>:

    Hello,

    do you get other error messages in syslog before the one
    "CRITICAL: ..."?

    It is hard to say it is from something already known or new.
    Right now there is an open issue for saving dialog variables
    in database that was not yet sorted out. Another one related
    to tm and memory manager, reported after 4.3.1, got a safety
    fix. Apart of these two, I don't remember any active crash
    report for the moment.

    If you get it very often, then it should be easy to catch and
    troubleshoot properly. Can you run it so it generates a core
    file?

    The easiest way is to run it as root, with 'ulimit -c
    unlimited' executed before starting kamailio.

    Can you share what operating system are you using and exact
    version of kamailio (output of kamailio -v)?

    Cheers,
    Daniel


    On 09/09/15 12:15, Thibault Gueslin wrote:

...

    After upgrading to kamailio 4.3.1 and modifying the config,
    I get this crash very often:
    ...

    CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 21

    ALERT: <core> [main.c:728]: handle_sigs(): child process
    9341 exited by a signal 11

    ALERT: <core> [main.c:731]: handle_sigs(): core was not
    generated

    INFO: <core> [main.c:743]: handle_sigs(): terminating due to
    SIGCHLD

    INFO: <core> [main.c:794]: sig_usr(): signal 15 received

    INFO: <core> [main.c:794]: sig_usr(): signal 15 received

    INFO: <core> [main.c:794]: sig_usr(): signal 15 received

    ...


    Is it known ? or may be related to my config ?


    Thank you


    Thibault 



    _______________________________________________
    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://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/miconda
    Book: SIP Routing With Kamailio - http://www.asipto.com
    Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

-- 
Daniel-Constantin Mierla
http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/miconda
Book: SIP Routing With Kamailio - http://www.asipto.com
Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

Do you have msrp enabled in configuration file?

Send the output from gdb for next commands:

frame 0 info locals p *msg p *ruri p *ptr p *_r

Cheers, Daniel

On 10/09/15 14:07, Thibault Gueslin wrote:

[Thread debugging using libthread_db enabled]

Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Core was generated by `/usr/sbin/kamailio -f /etc/kamailio/kamailio.cfg -P /var/run/kamailio/kamailio.'.

Program terminated with signal SIGSEGV, Segmentation fault.

#0 ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30, table=0x7f883bf7e390 "location") at ts_append.c:60

60ts_append.c: No such file or directory.

(gdb) bt

#0 ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30, table=0x7f883bf7e390 "location") at ts_append.c:60

#1 0x00007f8837f638fc in w_ts_append (_msg=0x7f883bfd5490, _table=0x7f883bf7e390 "location", _ruri=0x7f88339aa634 "\002") at tsilo.c:225

#2 0x0000000000534db0 in do_action (h=0x7fff65fc1a40, a=0x7f883bf7d278, msg=0x7f883bfd5490) at action.c:1059

#3 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#4 0x00000000005352e6 in do_action (h=0x7fff65fc1a40, a=0x7f883bf7dc50, msg=0x7f883bfd5490) at action.c:1048

#5 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#6 0x00000000005352e6 in do_action (h=0x7fff65fc1a40, a=0x7f883bf7df48, msg=0x7f883bfd5490) at action.c:1048

#7 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#8 0x00000000005354a3 in do_action (h=0x7fff65fc1a40, a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

#9 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#10 0x00000000005354a3 in do_action (h=0x7fff65fc1a40, a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

#11 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#12 0x00000000005352e6 in do_action (h=0x7fff65fc1a40, a=0x7f883bf56068, msg=0x7f883bfd5490) at action.c:1048

#13 0x00000000005339e8 in run_actions (h=0x7f8837f65540, h@entry=0x7fff65fc1a40, a=0x5, a@entry=0x7f883bf4f958, msg=0x7f88339aa634, msg@entry=0x7f883bfd5490) at action.c:1548

#14 0x000000000053f885 in run_top_route (a=0x7f883bf4f958, msg=0x7f883bfd5490, c=<optimized out>) at action.c:1634

#15 0x00000000005407e6 in receive_msg (buf=0x0, len=5, rcv_info=0x7f88339b8638) at receive.c:196

#16 0x00000000005b806b in tcp_read_req (con=0x7f88339b8620, bytes_read=0x7fff65fc1d50, read_flags=0x7fff65fc1d54) at tcp_read.c:1382

#17 0x00000000005bb4e1 in handle_io (fm=0xb, events=5, idx=865773108) at tcp_read.c:1568

#18 0x00000000005c191a in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at io_wait.h:1061

#19 tcp_receive_loop (unix_sock=938890560) at tcp_read.c:1733

#20 0x00000000004d3447 in tcp_init_children () at tcp_main.c:4787

#21 0x0000000000506863 in main_loop () at main.c:1658

#22 0x000000000041b944 in main (argc=0, argv=0x0) at main.c:2533

It seems to be on reception of REGISTER from client.

On 10/09/15 14:36, Thibault Gueslin wrote:

2015-09-10 14:25 GMT+02:00 Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com>:

Do you have msrp enabled in configuration file

I don't think so

The last frames of backtrace indicates code related to msrp, but might be just some code lines mismatching.

The issue seems to be in tsilo. I looke over the code and I spotted some "unclear" mechanisms that can lead to race conditions, which may result in invalid access to memory, as it happens in this case, ptr becomes 0x8b08578b49642454 -- from my short investigation, that is likely to be due to following a ->next field in a freed structure.

Not being the author of tsilo module, I can't do much more right now. I will open an issue on bug tracker explaining what I found, assigning Federico (cc-ed, author of the module) to analyze and see if anything is wrong there.

Cheers, Daniel

Send the output from gdb for next commands:

frame 0

#0 ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30, table=0x7f883bf7e390 "location") at ts_append.c:60

60in ts_append.c

info locals

_r = 0x7f88339bcfd0

ptr = 0x8b08578b49642454

res = 2

__FUNCTION__ = "ts_append"

p *msg




p *ruri
p *ptr
p *_r

| p *msg

$21 = {id = 2, pid = 31171, tval = {tv_sec = 1441885042, tv_usec = 162339}, fwd_send_flags = {f = 0 '\000', blst_imask = 0 '\000'}, rpl_send_flags = {f = 0 '\000', blst_imask = 0 '\000'}, first_line = {type = 1, flags = 1, len = 46, u = {request = {method = { s = 0x7f88339b8910 "REGISTER sip:sip-staging.serveur.com http://sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expi"..., len = 8}, uri = { s = 0x7f88339b8919 "sip:sip-staging.serveur.com http://sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\n"..., len = 27}, version = { s = 0x7f88339b8935 "SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\nMax-Forwards: 69\r\nTo: <sip:t"..., len = 7}, method_value = 32}, reply = {version = { s = 0x7f88339b8910 "REGISTER sip:sip-staging.serveur.com http://sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expi"..., len = 8}, status = { s = 0x7f88339b8919 "sip:sip-staging.serveur.com http://sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\n"..., len = 27}, reason = { s = 0x7f88339b8935 "SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\nMax-Forwards: 69\r\nTo: <sip:t"..., len = 7}, statuscode = 32}}}, via1 = 0x7f883bfa7020, via2 = 0x0, headers = 0x7f883bfa6f30, last_header = 0x7f883bfac220, parsed_flag = 18446744073709551615, h_via1 = 0x7f883bfa6f30, h_via2 = 0x0, callid = 0x7f883bfac400, to = 0x7f883bfac688, cseq = 0x7f883bfac388, from = 0x7f883bfa6fa8, contact = 0x7f883bfac778, maxforwards = 0x7f883bfac700, route = 0x0, record_route = 0x0, content_type = 0x0, content_length = 0x7f883bfac220, authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported = 0x7f883bfb6300, require = 0x0, proxy_require = 0x0, unsupported = 0x0, allow = 0x7f883bfac298, event = 0x0, accept = 0x0, accept_language = 0x0, organization = 0x0, priority = 0x0, subject = 0x0, user_agent = 0x7f883bfac310, server = 0x0, content_disposition = 0x0, diversion = 0x0, rpid = 0x0, refer_to = 0x0, session_expires = 0x0, min_se = 0x0, sipifmatch = 0x0, subscription_state = 0x0, date = 0x0, identity = 0x0, identity_info = 0x0, pai = 0x0, ppi = 0x0, path = 0x0, privacy = 0x0, body = 0x0, eoh = 0x7f88339b8b2b "\r\n", unparsed = 0x7f88339b8b2b "\r\n", rcv = {src_ip = {af = 2, len = 4, u = {addrl = {3334267998, 0}, addr32 = {3334267998, 0, 0, 0}, addr16 = {58462, 50876, 0, 0, 0, 0, 0, 0}, addr = "^\344\274\306", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {2667915013, 0}, addr32 = {2667915013, 0, 0, 0}, addr16 = {9989, 40709, 0, 0, 0, 0, 0, 0}, addr = "\005'\005\237", '\000' <repeats 11 times>}}, src_port = 52243, dst_port = 5060, proto_reserved1 = 3, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\314\023^\344\274\306\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 5068, sin_addr = {s_addr = 3334267998}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 5068, sin6_flowinfo = 3334267998, sin6_addr = {__in6_u = {__u6_addr8 = "\000\000\000\000\000\000\000\000 \206\233\063\210\177\000", __u6_addr16 = {0, 0, 0, 0, 34336, 13211, 32648, 0}, __u6_addr32 = {0, 0, 865830432, 32648}}}, sin6_scope_id = 865796800}}, bind_address = 0x7f883bfb6bd0, proto = 2 '\002'}, buf = 0x7f88339b8910 "REGISTER sip:sip-staging.serveur.com http://sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expi"..., len = 541, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len = 0}, parsed_uri_ok = 1, parsed_uri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = { s = 0x7f88339b891d "sip-staging.serveur.com http://sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\nMax-"..., len = 23}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = SIP_URI_T, flags = (unknown: 0), transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}}, parsed_orig_ruri_ok = 0, parsed_orig_ruri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = (unknown: 0), transport = { s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}}, add_rm = 0x0, body_lumps = 0x0, reply_lump = 0x7f883bfa3878, add_to_branch_s = '\000' <repeats 57 times>, add_to_branch_len = 0, hash_index = 39024, msg_flags = 129, flags = 32, set_global_address = {s = 0x0, len = 0}, set_global_port = {s = 0x0, len = 0}, force_send_socket = 0x0, path_vec = {s = 0x0, len = 0}, instance = {s = 0x0, len = 0}, reg_id = 0, ruid = {s = 0x0, len = 0}, location_ua = {s = 0x0, len = 0}, ldv = {flow = {decoded = 0, rcv = {src_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, dst_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, src_port = 0, dst_port = 0, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {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}}, bind_address = 0x0, proto = 0 '\000'}}}}

(gdb) p *ruri $22 = {s = 0x7f883bf317e8 "toto4.toto.com.Ipod_tgu", len = 23}

(gdb) p *ptr Cannot access memory at address 0x8b08578b49642454

(gdb) p *_r $23 = {ruri = {s = 0x7f88339bd040 "toto4.toto.com.Ipod_tgu", len = 23}, rurihash = 164669906, entry = 0x7f883398af08, transactions = 0x7f88339bd090, next = 0x0, prev = 0x0}

Cheers,
Daniel


On 10/09/15 14:07, Thibault Gueslin wrote:

...

[Thread debugging using libthread_db enabled]

Using host libthread_db library
"/lib/x86_64-linux-gnu/libthread_db.so.1".

Core was generated by `/usr/sbin/kamailio -f
/etc/kamailio/kamailio.cfg -P /var/run/kamailio/kamailio.'.

Program terminated with signal SIGSEGV, Segmentation fault.

#0  ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30,
table=0x7f883bf7e390 "location") at ts_append.c:60

60ts_append.c: No such file or directory.

(gdb) bt

#0  ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30,
table=0x7f883bf7e390 "location") at ts_append.c:60

#1  0x00007f8837f638fc in w_ts_append (_msg=0x7f883bfd5490,
_table=0x7f883bf7e390 "location", _ruri=0x7f88339aa634 "\002") at
tsilo.c:225

#2  0x0000000000534db0 in do_action (h=0x7fff65fc1a40,
a=0x7f883bf7d278, msg=0x7f883bfd5490) at action.c:1059

#3  0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5,
msg=0x7f88339aa634) at action.c:1548

#4  0x00000000005352e6 in do_action (h=0x7fff65fc1a40,
a=0x7f883bf7dc50, msg=0x7f883bfd5490) at action.c:1048

#5  0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5,
msg=0x7f88339aa634) at action.c:1548

#6  0x00000000005352e6 in do_action (h=0x7fff65fc1a40,
a=0x7f883bf7df48, msg=0x7f883bfd5490) at action.c:1048

#7  0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5,
msg=0x7f88339aa634) at action.c:1548

#8  0x00000000005354a3 in do_action (h=0x7fff65fc1a40,
a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

#9  0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5,
msg=0x7f88339aa634) at action.c:1548

#10 0x00000000005354a3 in do_action (h=0x7fff65fc1a40,
a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

#11 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5,
msg=0x7f88339aa634) at action.c:1548

#12 0x00000000005352e6 in do_action (h=0x7fff65fc1a40,
a=0x7f883bf56068, msg=0x7f883bfd5490) at action.c:1048

#13 0x00000000005339e8 in run_actions (h=0x7f8837f65540,
h@entry=0x7fff65fc1a40, a=0x5, a@entry=0x7f883bf4f958,
msg=0x7f88339aa634, msg@entry=0x7f883bfd5490) at action.c:1548

#14 0x000000000053f885 in run_top_route (a=0x7f883bf4f958,
msg=0x7f883bfd5490, c=<optimized out>) at action.c:1634

#15 0x00000000005407e6 in receive_msg (buf=0x0, len=5,
rcv_info=0x7f88339b8638) at receive.c:196

#16 0x00000000005b806b in tcp_read_req (con=0x7f88339b8620,
bytes_read=0x7fff65fc1d50, read_flags=0x7fff65fc1d54) at
tcp_read.c:1382

#17 0x00000000005bb4e1 in handle_io (fm=0xb, events=5,
idx=865773108) at tcp_read.c:1568

#18 0x00000000005c191a in io_wait_loop_epoll (h=<optimized out>,
t=<optimized out>, repeat=<optimized out>) at io_wait.h:1061

#19 tcp_receive_loop (unix_sock=938890560) at tcp_read.c:1733

#20 0x00000000004d3447 in tcp_init_children () at tcp_main.c:4787

#21 0x0000000000506863 in main_loop () at main.c:1658

#22 0x000000000041b944 in main (argc=0, argv=0x0) at main.c:2533


It seems to be on reception of REGISTER from client.

-- 
Daniel-Constantin Mierla
http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/miconda
Book: SIP Routing With Kamailio - http://www.asipto.com
Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

Hi Federico,

didn't get the time to write a more detailed report, but my quick look at the tsilo code revealed two potential issues:

- the ts transaction structure is cloned in shared memory to be passed as parameter to a tm callback. The clone is stil linked to the list with prev and next. In the callback, if I got it properly, it starts walking through the list, but the list chould have been updated and prev/next can point to invalid data structure now.

- there is a hash table that has locks for each slot, but those locks are not use and parallel operations (add/remove) can be done in the hash table by different kamailio processes

When I get more time I will try to check again and see if those suppositions are valid. Meanwhile, maybe you can check as well.

Cheers, Daniel

On 10/09/15 19:33, Federico Cabiddu wrote:

Hi Thibault, have you tried last tsilo code from 4.3.x branch? Recently there has been a fix (https://github.com/kamailio/kamailio/commit/6ce6803d57dabe287d7d6fa859e93c1d...) for an issue that may be related to yours. I'll keep investigating to see if I can spot something else. In the meanwhile could you describe your scenario? Are you storing multiple transactions per ruri? Did any of them got a final reply before the crash?

Regards,

Federico

On Thu, Sep 10, 2015 at 3:00 PM, Daniel-Constantin Mierla <miconda@gmail.com mailto:miconda@gmail.com> wrote:

On 10/09/15 14:36, Thibault Gueslin wrote:

...

2015-09-10 14:25 GMT+02:00 Daniel-Constantin Mierla
<miconda@gmail.com <mailto:miconda@gmail.com>>:

    Do you have msrp enabled in configuration file


I don't think so

The last frames of backtrace indicates code related to msrp, but
might be just some code lines mismatching.

The issue seems to be in tsilo. I looke over the code and I
spotted some "unclear" mechanisms that can lead to race
conditions, which may result in invalid access to memory, as it
happens in this case, ptr becomes 0x8b08578b49642454 -- from my
short investigation, that is likely to be due to following a
->next field in a freed structure.

Not being the author of tsilo module, I can't do much more right
now. I will open an issue on bug tracker explaining what I found,
assigning Federico (cc-ed, author of the module) to analyze and
see if anything is wrong there.

Cheers,
Daniel

...

    Send the output from gdb for next commands:

    frame 0


#0  ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30,
table=0x7f883bf7e390 "location") at ts_append.c:60

60in ts_append.c


    info locals

_r = 0x7f88339bcfd0

ptr = 0x8b08578b49642454

res = 2

__FUNCTION__ = "ts_append"


    p *msg




    p *ruri
    p *ptr
    p *_r


| p *msg

$21 = {id = 2, pid = 31171, tval = {tv_sec = 1441885042, tv_usec
= 162339}, fwd_send_flags = {f = 0 '\000', blst_imask = 0
'\000'}, rpl_send_flags = {f = 0 '\000', blst_imask = 0 '\000'},
first_line = {type = 1, 
    flags = 1, len = 46, u = {request = {method = {
          s = 0x7f88339b8910 "REGISTER
sip:sip-staging.serveur.com <http://sip-staging.serveur.com>
SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expi"...,
len = 8}, uri = {
          s = 0x7f88339b8919 "sip:sip-staging.serveur.com
<http://sip-staging.serveur.com> SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expires=900\r\n"...,
len = 27}, version = {
          s = 0x7f88339b8935 "SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expires=900\r\nMax-Forwards:
69\r\nTo: <sip:t"..., len = 7}, method_value = 32}, reply =
{version = {
          s = 0x7f88339b8910 "REGISTER
sip:sip-staging.serveur.com <http://sip-staging.serveur.com>
SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expi"...,
len = 8}, status = {
          s = 0x7f88339b8919 "sip:sip-staging.serveur.com
<http://sip-staging.serveur.com> SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expires=900\r\n"...,
len = 27}, reason = {
          s = 0x7f88339b8935 "SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expires=900\r\nMax-Forwards:
69\r\nTo: <sip:t"..., len = 7}, statuscode = 32}}}, via1 =
0x7f883bfa7020, via2 = 0x0, headers = 0x7f883bfa6f30, last_header
= 0x7f883bfac220, parsed_flag = 18446744073709551615, h_via1 =
0x7f883bfa6f30, 
  h_via2 = 0x0, callid = 0x7f883bfac400, to = 0x7f883bfac688,
cseq = 0x7f883bfac388, from = 0x7f883bfa6fa8, contact =
0x7f883bfac778, maxforwards = 0x7f883bfac700, route = 0x0,
record_route = 0x0, 
  content_type = 0x0, content_length = 0x7f883bfac220,
authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported =
0x7f883bfb6300, require = 0x0, proxy_require = 0x0, unsupported =
0x0, 
  allow = 0x7f883bfac298, event = 0x0, accept = 0x0,
accept_language = 0x0, organization = 0x0, priority = 0x0,
subject = 0x0, user_agent = 0x7f883bfac310, server = 0x0,
content_disposition = 0x0, diversion = 0x0, 
  rpid = 0x0, refer_to = 0x0, session_expires = 0x0, min_se =
0x0, sipifmatch = 0x0, subscription_state = 0x0, date = 0x0,
identity = 0x0, identity_info = 0x0, pai = 0x0, ppi = 0x0, path =
0x0, privacy = 0x0, 
  body = 0x0, eoh = 0x7f88339b8b2b "\r\n", unparsed =
0x7f88339b8b2b "\r\n", rcv = {src_ip = {af = 2, len = 4, u =
{addrl = {3334267998, 0}, addr32 = {3334267998, 0, 0, 0}, addr16
= {58462, 50876, 0, 0, 0, 0, 0, 
          0}, addr = "^\344\274\306", '\000' <repeats 11
times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {2667915013,
0}, addr32 = {2667915013, 0, 0, 0}, addr16 = {9989, 40709, 0, 0,
0, 0, 0, 0}, 
        addr = "\005'\005\237", '\000' <repeats 11 times>}},
src_port = 52243, dst_port = 5060, proto_reserved1 = 3,
proto_reserved2 = 0, src_su = {s = {sa_family = 2, 
        sa_data =
"\314\023^\344\274\306\000\000\000\000\000\000\000"}, sin =
{sin_family = 2, sin_port = 5068, sin_addr = {s_addr =
3334267998}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {
        sin6_family = 2, sin6_port = 5068, sin6_flowinfo =
3334267998, sin6_addr = {__in6_u = {__u6_addr8 =
"\000\000\000\000\000\000\000\000 \206\233\063\210\177\000",
__u6_addr16 = {0, 0, 0, 0, 34336, 13211, 
              32648, 0}, __u6_addr32 = {0, 0, 865830432,
32648}}}, sin6_scope_id = 865796800}}, bind_address =
0x7f883bfb6bd0, proto = 2 '\002'}, 
  buf = 0x7f88339b8910 "REGISTER sip:sip-staging.serveur.com
<http://sip-staging.serveur.com> SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expi"...,
len = 541, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len
= 0}, parsed_uri_ok = 1, parsed_uri = {user = {s = 0x0, len = 0},
passwd = {s = 0x0, len = 0}, host = {
      s = 0x7f88339b891d "sip-staging.serveur.com
<http://sip-staging.serveur.com> SIP/2.0\r\nVia: SIP/2.0/TCP
172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact:
<sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp>;expires=900\r\nMax-"...,
len = 23}, port = {s = 0x0, len = 0}, params = {s = 0x0, len =
0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len =
0}, port_no = 0, proto = 0, type = SIP_URI_T, 
    flags = (unknown: 0), transport = {s = 0x0, len = 0}, ttl =
{s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s =
0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len =
0}, r2 = {s = 0x0, 
      len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s =
0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s
= 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s
= 0x0, len = 0}, 
    lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0},
gr_val = {s = 0x0, len = 0}}, parsed_orig_ruri_ok = 0,
parsed_orig_ruri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0,
len = 0}, host = {s = 0x0, 
      len = 0}, port = {s = 0x0, len = 0}, params = {s = 0x0, len
= 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len =
0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = (unknown:
0), transport = {
      s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param =
{s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s =
0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0},
gr = {s = 0x0, 
      len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s
= 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val =
{s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s
= 0x0, len = 0}, 
    r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}},
add_rm = 0x0, body_lumps = 0x0, reply_lump = 0x7f883bfa3878,
add_to_branch_s = '\000' <repeats 57 times>, add_to_branch_len =
0, hash_index = 39024, 
  msg_flags = 129, flags = 32, set_global_address = {s = 0x0, len
= 0}, set_global_port = {s = 0x0, len = 0}, force_send_socket =
0x0, path_vec = {s = 0x0, len = 0}, instance = {s = 0x0, len =
0}, reg_id = 0, 
  ruid = {s = 0x0, len = 0}, location_ua = {s = 0x0, len = 0},
ldv = {flow = {decoded = 0, rcv = {src_ip = {af = 0, len = 0, u =
{addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0,
0, 0, 0}, 
            addr = '\000' <repeats 15 times>}}, dst_ip = {af = 0,
len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0,
0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}},
src_port = 0, 
        dst_port = 0, proto_reserved1 = 0, proto_reserved2 = 0,
src_su = {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}}, bind_address = 0x0, proto = 0 '\000'}}}}



(gdb) p *ruri
$22 = {s = 0x7f883bf317e8 "toto4.toto.com.Ipod_tgu", len = 23}

(gdb) p *ptr
Cannot access memory at address 0x8b08578b49642454

(gdb) p *_r
$23 = {ruri = {s = 0x7f88339bd040 "toto4.toto.com.Ipod_tgu", len
= 23}, rurihash = 164669906, entry = 0x7f883398af08, transactions
= 0x7f88339bd090, next = 0x0, prev = 0x0}



    Cheers,
    Daniel


    On 10/09/15 14:07, Thibault Gueslin wrote:

...

    [Thread debugging using libthread_db enabled]

    Using host libthread_db library
    "/lib/x86_64-linux-gnu/libthread_db.so.1".

    Core was generated by `/usr/sbin/kamailio -f
    /etc/kamailio/kamailio.cfg -P /var/run/kamailio/kamailio.'.

    Program terminated with signal SIGSEGV, Segmentation fault.

    #0  ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30,
    table=0x7f883bf7e390 "location") at ts_append.c:60

    60ts_append.c: No such file or directory.

    (gdb) bt

    #0  ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30,
    table=0x7f883bf7e390 "location") at ts_append.c:60

    #1  0x00007f8837f638fc in w_ts_append (_msg=0x7f883bfd5490,
    _table=0x7f883bf7e390 "location", _ruri=0x7f88339aa634
    "\002") at tsilo.c:225

    #2  0x0000000000534db0 in do_action (h=0x7fff65fc1a40,
    a=0x7f883bf7d278, msg=0x7f883bfd5490) at action.c:1059

    #3  0x00000000005339e8 in run_actions (h=0x7f8837f65540,
    a=0x5, msg=0x7f88339aa634) at action.c:1548

    #4  0x00000000005352e6 in do_action (h=0x7fff65fc1a40,
    a=0x7f883bf7dc50, msg=0x7f883bfd5490) at action.c:1048

    #5  0x00000000005339e8 in run_actions (h=0x7f8837f65540,
    a=0x5, msg=0x7f88339aa634) at action.c:1548

    #6  0x00000000005352e6 in do_action (h=0x7fff65fc1a40,
    a=0x7f883bf7df48, msg=0x7f883bfd5490) at action.c:1048

    #7  0x00000000005339e8 in run_actions (h=0x7f8837f65540,
    a=0x5, msg=0x7f88339aa634) at action.c:1548

    #8  0x00000000005354a3 in do_action (h=0x7fff65fc1a40,
    a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

    #9  0x00000000005339e8 in run_actions (h=0x7f8837f65540,
    a=0x5, msg=0x7f88339aa634) at action.c:1548

    #10 0x00000000005354a3 in do_action (h=0x7fff65fc1a40,
    a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

    #11 0x00000000005339e8 in run_actions (h=0x7f8837f65540,
    a=0x5, msg=0x7f88339aa634) at action.c:1548

    #12 0x00000000005352e6 in do_action (h=0x7fff65fc1a40,
    a=0x7f883bf56068, msg=0x7f883bfd5490) at action.c:1048

    #13 0x00000000005339e8 in run_actions (h=0x7f8837f65540,
    h@entry=0x7fff65fc1a40, a=0x5, a@entry=0x7f883bf4f958,
    msg=0x7f88339aa634, msg@entry=0x7f883bfd5490) at action.c:1548

    #14 0x000000000053f885 in run_top_route (a=0x7f883bf4f958,
    msg=0x7f883bfd5490, c=<optimized out>) at action.c:1634

    #15 0x00000000005407e6 in receive_msg (buf=0x0, len=5,
    rcv_info=0x7f88339b8638) at receive.c:196

    #16 0x00000000005b806b in tcp_read_req (con=0x7f88339b8620,
    bytes_read=0x7fff65fc1d50, read_flags=0x7fff65fc1d54) at
    tcp_read.c:1382

    #17 0x00000000005bb4e1 in handle_io (fm=0xb, events=5,
    idx=865773108) at tcp_read.c:1568

    #18 0x00000000005c191a in io_wait_loop_epoll (h=<optimized
    out>, t=<optimized out>, repeat=<optimized out>) at
    io_wait.h:1061

    #19 tcp_receive_loop (unix_sock=938890560) at tcp_read.c:1733

    #20 0x00000000004d3447 in tcp_init_children () at
    tcp_main.c:4787

    #21 0x0000000000506863 in main_loop () at main.c:1658

    #22 0x000000000041b944 in main (argc=0, argv=0x0) at main.c:2533


    It seems to be on reception of REGISTER from client.

    -- 
    Daniel-Constantin Mierla
    http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/miconda
    Book: SIP Routing With Kamailio - http://www.asipto.com
    Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

-- 
Daniel-Constantin Mierla
http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/miconda
Book: SIP Routing With Kamailio - http://www.asipto.com
Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

Hi Federico,

I will try last code in 4.3.x branch.

The scenario is very easy: I am calling a SIP client (running on a mobile) First the client is stopped. Then launch the app. As expected, the calll is presented after it has registered. Then kill the application (before answering), then launching again the app, call is presented... Then waiting for call timeout. It works one or 2 times then call never timeouts on the client which initiates the call (which means Kamailio is dead and does not send 408 Timeout)

2015-09-10 19:33 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

Hi Thibault, have you tried last tsilo code from 4.3.x branch? Recently there has been a fix ( https://github.com/kamailio/kamailio/commit/6ce6803d57dabe287d7d6fa859e93c1d...) for an issue that may be related to yours. I'll keep investigating to see if I can spot something else. In the meanwhile could you describe your scenario? Are you storing multiple transactions per ruri? Did any of them got a final reply before the crash?

Regards,

Federico

On Thu, Sep 10, 2015 at 3:00 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:

...

On 10/09/15 14:36, Thibault Gueslin wrote:

2015-09-10 14:25 GMT+02:00 Daniel-Constantin Mierla < miconda@gmail.com miconda@gmail.com>:

...

Do you have msrp enabled in configuration file

I don't think so

The last frames of backtrace indicates code related to msrp, but might be just some code lines mismatching.

The issue seems to be in tsilo. I looke over the code and I spotted some "unclear" mechanisms that can lead to race conditions, which may result in invalid access to memory, as it happens in this case, ptr becomes 0x8b08578b49642454 -- from my short investigation, that is likely to be due to following a ->next field in a freed structure.

Not being the author of tsilo module, I can't do much more right now. I will open an issue on bug tracker explaining what I found, assigning Federico (cc-ed, author of the module) to analyze and see if anything is wrong there.

Cheers, Daniel

...

Send the output from gdb for next commands:

frame 0

#0 ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30, table=0x7f883bf7e390 "location") at ts_append.c:60 60 in ts_append.c

...

info locals

_r = 0x7f88339bcfd0

ptr = 0x8b08578b49642454

res = 2 __FUNCTION__ = "ts_append"

...

p *msg

...

p *ruri p *ptr p *_r

| p *msg

$21 = {id = 2, pid = 31171, tval = {tv_sec = 1441885042, tv_usec = 162339}, fwd_send_flags = {f = 0 '\000', blst_imask = 0 '\000'}, rpl_send_flags = {f = 0 '\000', blst_imask = 0 '\000'}, first_line = {type = 1, flags = 1, len = 46, u = {request = {method = { s = 0x7f88339b8910 "REGISTER sip:sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expi"..., len = 8}, uri = { s = 0x7f88339b8919 "sip:sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\n"..., len = 27}, version = { s = 0x7f88339b8935 "SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\nMax-Forwards: 69\r\nTo: <sip:t"..., len = 7}, method_value = 32}, reply = {version = { s = 0x7f88339b8910 "REGISTER sip:sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expi"..., len = 8}, status = { s = 0x7f88339b8919 "sip:sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\n"..., len = 27}, reason = { s = 0x7f88339b8935 "SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\nMax-Forwards: 69\r\nTo: <sip:t"..., len = 7}, statuscode = 32}}}, via1 = 0x7f883bfa7020, via2 = 0x0, headers = 0x7f883bfa6f30, last_header = 0x7f883bfac220, parsed_flag = 18446744073709551615, h_via1 = 0x7f883bfa6f30, h_via2 = 0x0, callid = 0x7f883bfac400, to = 0x7f883bfac688, cseq = 0x7f883bfac388, from = 0x7f883bfa6fa8, contact = 0x7f883bfac778, maxforwards = 0x7f883bfac700, route = 0x0, record_route = 0x0, content_type = 0x0, content_length = 0x7f883bfac220, authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported = 0x7f883bfb6300, require = 0x0, proxy_require = 0x0, unsupported = 0x0, allow = 0x7f883bfac298, event = 0x0, accept = 0x0, accept_language = 0x0, organization = 0x0, priority = 0x0, subject = 0x0, user_agent = 0x7f883bfac310, server = 0x0, content_disposition = 0x0, diversion = 0x0, rpid = 0x0, refer_to = 0x0, session_expires = 0x0, min_se = 0x0, sipifmatch = 0x0, subscription_state = 0x0, date = 0x0, identity = 0x0, identity_info = 0x0, pai = 0x0, ppi = 0x0, path = 0x0, privacy = 0x0, body = 0x0, eoh = 0x7f88339b8b2b "\r\n", unparsed = 0x7f88339b8b2b "\r\n", rcv = {src_ip = {af = 2, len = 4, u = {addrl = {3334267998, 0}, addr32 = {3334267998, 0, 0, 0}, addr16 = {58462, 50876, 0, 0, 0, 0, 0, 0}, addr = "^\344\274\306", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {2667915013, 0}, addr32 = {2667915013, 0, 0, 0}, addr16 = {9989, 40709, 0, 0, 0, 0, 0, 0}, addr = "\005'\005\237", '\000' <repeats 11 times>}}, src_port = 52243, dst_port = 5060, proto_reserved1 = 3, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\314\023^\344\274\306\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 5068, sin_addr = {s_addr = 3334267998}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 5068, sin6_flowinfo = 3334267998, sin6_addr = {__in6_u = {__u6_addr8 = "\000\000\000\000\000\000\000\000 \206\233\063\210\177\000", __u6_addr16 = {0, 0, 0, 0, 34336, 13211, 32648, 0}, __u6_addr32 = {0, 0, 865830432, 32648}}}, sin6_scope_id = 865796800}}, bind_address = 0x7f883bfb6bd0, proto = 2 '\002'}, buf = 0x7f88339b8910 "REGISTER sip:sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expi"..., len = 541, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len = 0}, parsed_uri_ok = 1, parsed_uri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = { s = 0x7f88339b891d "sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:52242;branch=z9hG4bK20965be26f6a6324;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:52242;transport=tcp;expires=900\r\nMax-"..., len = 23}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = SIP_URI_T, flags = (unknown: 0), transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}}, parsed_orig_ruri_ok = 0, parsed_orig_ruri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = (unknown: 0), transport = { s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}}, add_rm = 0x0, body_lumps = 0x0, reply_lump = 0x7f883bfa3878, add_to_branch_s = '\000' <repeats 57 times>, add_to_branch_len = 0, hash_index = 39024, msg_flags = 129, flags = 32, set_global_address = {s = 0x0, len = 0}, set_global_port = {s = 0x0, len = 0}, force_send_socket = 0x0, path_vec = {s = 0x0, len = 0}, instance = {s = 0x0, len = 0}, reg_id = 0, ruid = {s = 0x0, len = 0}, location_ua = {s = 0x0, len = 0}, ldv = {flow = {decoded = 0, rcv = {src_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, dst_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, src_port = 0, dst_port = 0, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {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}}, bind_address = 0x0, proto = 0 '\000'}}}}

(gdb) p *ruri $22 = {s = 0x7f883bf317e8 "toto4.toto.com.Ipod_tgu", len = 23}

(gdb) p *ptr Cannot access memory at address 0x8b08578b49642454

(gdb) p *_r $23 = {ruri = {s = 0x7f88339bd040 "toto4.toto.com.Ipod_tgu", len = 23}, rurihash = 164669906, entry = 0x7f883398af08, transactions = 0x7f88339bd090, next = 0x0, prev = 0x0}

...

Cheers, Daniel

On 10/09/15 14:07, Thibault Gueslin wrote:

[Thread debugging using libthread_db enabled]

Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Core was generated by `/usr/sbin/kamailio -f /etc/kamailio/kamailio.cfg -P /var/run/kamailio/kamailio.'.

Program terminated with signal SIGSEGV, Segmentation fault.

#0 ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30, table=0x7f883bf7e390 "location") at ts_append.c:60

60 ts_append.c: No such file or directory.

(gdb) bt

#0 ts_append (msg=0x7f883bfd5490, ruri=0x7fff65fbfe30, table=0x7f883bf7e390 "location") at ts_append.c:60

#1 0x00007f8837f638fc in w_ts_append (_msg=0x7f883bfd5490, _table=0x7f883bf7e390 "location", _ruri=0x7f88339aa634 "\002") at tsilo.c:225

#2 0x0000000000534db0 in do_action (h=0x7fff65fc1a40, a=0x7f883bf7d278, msg=0x7f883bfd5490) at action.c:1059

#3 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#4 0x00000000005352e6 in do_action (h=0x7fff65fc1a40, a=0x7f883bf7dc50, msg=0x7f883bfd5490) at action.c:1048

#5 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#6 0x00000000005352e6 in do_action (h=0x7fff65fc1a40, a=0x7f883bf7df48, msg=0x7f883bfd5490) at action.c:1048

#7 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#8 0x00000000005354a3 in do_action (h=0x7fff65fc1a40, a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

#9 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#10 0x00000000005354a3 in do_action (h=0x7fff65fc1a40, a=0x7f883bfa8ab8, msg=0x7f883bfd5490) at action.c:677

#11 0x00000000005339e8 in run_actions (h=0x7f8837f65540, a=0x5, msg=0x7f88339aa634) at action.c:1548

#12 0x00000000005352e6 in do_action (h=0x7fff65fc1a40, a=0x7f883bf56068, msg=0x7f883bfd5490) at action.c:1048

#13 0x00000000005339e8 in run_actions (h=0x7f8837f65540, h@entry=0x7fff65fc1a40, a=0x5, a@entry=0x7f883bf4f958, msg=0x7f88339aa634, msg@entry=0x7f883bfd5490) at action.c:1548

#14 0x000000000053f885 in run_top_route (a=0x7f883bf4f958, msg=0x7f883bfd5490, c=<optimized out>) at action.c:1634

#15 0x00000000005407e6 in receive_msg (buf=0x0, len=5, rcv_info=0x7f88339b8638) at receive.c:196

#16 0x00000000005b806b in tcp_read_req (con=0x7f88339b8620, bytes_read=0x7fff65fc1d50, read_flags=0x7fff65fc1d54) at tcp_read.c:1382

#17 0x00000000005bb4e1 in handle_io (fm=0xb, events=5, idx=865773108) at tcp_read.c:1568

#18 0x00000000005c191a in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at io_wait.h:1061

#19 tcp_receive_loop (unix_sock=938890560) at tcp_read.c:1733

#20 0x00000000004d3447 in tcp_init_children () at tcp_main.c:4787

#21 0x0000000000506863 in main_loop () at main.c:1658

#22 0x000000000041b944 in main (argc=0, argv=0x0) at main.c:2533

It seems to be on reception of REGISTER from client.

-- Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

-- Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com Kamailio Advanced Training, Sep 28-30, 2015, in Berlin - http://asipto.com/u/kat

Hello Federico,

I have built from 4.3 branch.

I got a crash again... However it seems different than previous one:

Issue seems located in tm module.

It appears if the remote denied the incoming call, then quit application .

thibault

Core was generated by `sbin/kamailio -f /etc/kamailio/kamailio.cfg -L ./lib64/kamailio/modules/'.

Program terminated with signal SIGSEGV, Segmentation fault.

#0 0x00007fc279f64855 in lock_entry (entry=0x7fc2761d6068) at ts_hash.c:156

156 ts_lock(t_table, entry);

(gdb) bt full

#0 0x0000000000000001 in ?? ()

No symbol table info available.

#1 0x00007fc27cd77fd9 in free_faked_req (faked_req=0x7fc27d029100 <faked_req>, t=0x7fc2761f2fc0) at t_reply.c:931

hdr = 0x0

__FUNCTION__ = "free_faked_req"

#2 0x00007fc27cd78df4 in run_failure_handlers (t=0x7fc2761f2fc0, rpl=0xffffffffffffffff, code=408, extra_flags=96) at t_reply.c:997

faked_req = {id = 3, pid = 15569, tval = {tv_sec = 1442326316, tv_usec = 475922}, fwd_send_flags = {f = 4 '\004', blst_imask = 0 '\000'}, rpl_send_flags = {f = 0 '\000', blst_imask = 0 '\000'},

first_line = {type = 1, flags = 1, len = 68, u = {request = {method = {

s = 0x7fc2761efc08 "INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 6}, uri = {

s = 0x7fc2761efc0f " sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;tran"..., len = 51}, version = {

s = 0x7fc2761efc43 "SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;transport=tcp\r\nMax-Forwards: 69\r\nTo: <sip:toto4.toto.co"..., len = 7}, method_value = 1}, reply = {version = {

s = 0x7fc2761efc08 "INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 6}, status = {

s = 0x7fc2761efc0f " sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;tran"..., len = 51}, reason = {

s = 0x7fc2761efc43 "SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;transport=tcp\r\nMax-Forwards: 69\r\nTo: <sip:toto4.toto.co"..., len = 7}, statuscode = 1}}}, via1 = 0x7fc2761f0008, via2 = 0x0, headers = 0x7fc2761effc8, last_header = 0x7fc2761f07c0, parsed_flag = 18446744073709551615,

h_via1 = 0x7fc2761effc8, h_via2 = 0x0, callid = 0x7fc2761f0650, to = 0x7fc2761f01f0, cseq = 0x7fc2761f0690, from = 0x7fc2761f0408, contact = 0x7fc2761f0170, maxforwards = 0x7fc2761f01b0, route = 0x0,

record_route = 0x0, content_type = 0x7fc2761f0780, content_length = 0x7fc2761f07c0, authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported = 0x0, require = 0x0, proxy_require = 0x0,

unsupported = 0x0, allow = 0x7fc2761f0740, event = 0x0, accept = 0x0, accept_language = 0x0, organization = 0x0, priority = 0x0, subject = 0x0, user_agent = 0x7fc2761f0700, server = 0x0,

content_disposition = 0x0, diversion = 0x0, rpid = 0x0, refer_to = 0x0, session_expires = 0x0, min_se = 0x0, sipifmatch = 0x0, subscription_state = 0x0, date = 0x0, identity = 0x0, identity_info = 0x0,

pai = 0x0, ppi = 0x0, path = 0x0, privacy = 0x0, body = 0x7fc27e026c70,

eoh = 0x7fc2761efe45 "\r\nv=0\r\no=- 791306690 125312959 IN IP4 172.16.224.222\r\ns=-\r\nc=IN IP4 172.16.224.222\r\nt=0 0\r\na=tool:baresip 0.4.3\r\nm=audio 25940 RTP/AVP 96 97 98 8 0 101\r\nb=AS:125\r\na=rtpmap:96 opus/48000/2\r\na=rtpmap:97"...,

unparsed = 0x7fc2761efe45 "\r\nv=0\r\no=- 791306690 125312959 IN IP4 172.16.224.222\r\ns=-\r\nc=IN IP4 172.16.224.222\r\nt=0 0\r\na=tool:baresip 0.4.3\r\nm=audio 25940 RTP/AVP 96 97 98 8 0 101\r\nb=AS:125\r\na=rtpmap:96 opus/48000/2\r\na=rtpmap:97"..., rcv = {src_ip = {af = 2, len = 4, u = {addrl = {3334267998, 0}, addr32 = {3334267998, 0, 0, 0}, addr16 = {58462, 50876, 0, 0, 0, 0, 0, 0},

addr = "^\344\274\306", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {2667915013, 0}, addr32 = {2667915013, 0, 0, 0}, addr16 = {9989, 40709, 0, 0, 0, 0, 0, 0},

addr = "\005'\005\237", '\000' <repeats 11 times>}}, src_port = 54927, dst_port = 5060, proto_reserved1 = 1, proto_reserved2 = 0, src_su = {s = {sa_family = 2,

sa_data = "\326\217^\344\274\306\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 36822, sin_addr = {s_addr = 3334267998}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {

sin6_family = 2, sin6_port = 36822, sin6_flowinfo = 3334267998, 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 = 1979090440}}, bind_address = 0x7fc27e03d9f0, proto = 2 '\002'},

buf = 0x7fc2761efc08 "INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 959, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len = 0}, parsed_uri_ok = 0, parsed_uri = {user = {

s = 0x7fc2761efba4 "toto4.toto.com.Thibault@172.16.230.61:52915 ;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:"..., len = 23}, passwd = {s = 0x0, len = 0}, host = {

s = 0x7fc2761efbbc "172.16.230.61:52915 ;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b8"..., len = 13}, port = {

s = 0x7fc2761efbca "52915;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;r"..., len = 5}, params = {

s = 0x7fc2761efbd0 "transport=tcpP/2sip:94.228.188.198:52919 ;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\n"..., len = 13}, sip_params = {s = 0x7fc27e02a260 ' ' <repeats 88 times>, "HK\001~\302\177", len = 13}, headers = {s = 0x0, len = 0}, port_no = 52915, proto = 2, type = SIP_URI_T,

flags = (unknown: 0), transport = {

s = 0x7fc2761efbd0 "transport=tcpP/2sip:94.228.188.198:52919 ;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\n"..., len = 13}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {

s = 0x0, len = 0}, transport_val = {

s = 0x7fc2761efbda "tcpP/2sip:94.228.188.198:52919 ;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <"..., len = 3}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {

s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}}, parsed_orig_ruri_ok = 0, parsed_orig_ruri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0,

len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = (unknown: 0), transport = {s = 0x0, len = 0},

ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0},

transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0},

r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}}, add_rm = 0x7fc2761f4ac8, body_lumps = 0x0, reply_lump = 0x0,

add_to_branch_s = "z9hG4bK4d8.005be33152cbbe2a3c79d27fff052452.3", '\000' <repeats 12 times>, add_to_branch_len = 45, hash_index = 2260, msg_flags = 266481, flags = 34, set_global_address = {s = 0x0,

len = 0}, set_global_port = {s = 0x0, len = 0}, force_send_socket = 0x7fc27e03d9f0, path_vec = {s = 0x0, len = 0}, instance = {s = 0x0, len = 0}, reg_id = 0, ruid = {s = 0x0, len = 0}, location_ua = {

s = 0x0, len = 0}, ldv = {flow = {decoded = 0, rcv = {src_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}},

dst_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, src_port = 0, dst_port = 0, proto_reserved1 = 0,

__FUNCTION__ = "run_failure_handlers"

#3 0x00007fc27cd7ba3b in t_should_relay_response (Trans=0x7fc2761f2fc0, new_code=408, branch=3, should_store=0x7fff9a9b9248, should_relay=0x7fff9a9b924c, cancel_data=0x7fff9a9b92e0, reply=0xffffffffffffffff)

at t_reply.c:1342

branch_cnt = 4

picked_code = 408

new_branch = 1

inv_through = 0

extra_flags = 96

i = 32706

replies_dropped = 0

__FUNCTION__ = "t_should_relay_response"

#4 0x00007fc27cd7e7d6 in relay_reply (t=0x7fc2761f2fc0, p_msg=0xffffffffffffffff, branch=3, msg_status=408, cancel_data=0x7fff9a9b92e0, do_put_on_wait=0) at t_reply.c:1745

relay = -1

save_clone = 0

buf = 0x0

res_len = 0

relayed_code = 0

relayed_msg = 0x0

reply_bak = 0x1

bm = {to_tag_val = {s = 0x200000000 <error: Cannot access memory at address 0x200000000>, len = 1981755328}}

totag_retr = 0

reply_status = RPS_ERROR

uas_rb = 0xffffffffffffffff

to_tag = 0x7fc2761f3780

reason = {s = 0x735c44 "Request Timeout", len = -1701080344}

onsend_params = {req = 0x76203528, rpl = 0x7fc2761f35c0, param = 0x18f59272ffffffff, code = 418744713, flags = 320, branch = 0, t_rbuf = 0x3ef3ee10, dst = 0x415ed0 <_start>, send_buf = {

s = 0x7fff9a9b92c0 "\020\223\233\232\377\177", len = 2094439873}}

ip = {af = 2593886736, len = 32767, u = {addrl = {140473294816037, 18446744069414584320}, addr32 = {2094433061, 32706, 0, 4294967295}, addr16 = {33573, 31958, 32706, 0, 0, 0, 65535, 65535},

addr = "%\203\326|\302\177\000\000\000\000\000\000\377\377\377\377"}}

__FUNCTION__ = "relay_reply"

#5 0x00007fc27cda99d8 in fake_reply (t=0x7fc2761f2fc0, branch=3, code=408) at timer.c:328

cancel_data = {cancel_bitmap = 0, reason = {cause = 0, u = {text = {s = 0x0, len = 1981755328}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 1981755328}}}}

do_cancel_branch = 1

reply_status = 15561

#6 0x00007fc27cda9e5f in final_response_handler (r_buf=0x7fc2761f36e8, t=0x7fc2761f2fc0) at timer.c:500

silent = 0

branch_ret = 0

prev_branch = 1056173584

now = 0

#7 0x00007fc27cda9f02 in retr_buf_handler (ticks=418744835, tl=0x7fc2761f3708, p=0xfffffffe) at timer.c:558

rbuf = 0x7fc2761f36e8

fr_remainder = 2593887152

retr_remainder = 32706

retr_interval = 1979369672

new_retr_interval_ms = 140473182140168

crt_retr_interval_ms = 140473179752648

t = 0x7fc2761f2fc0

__FUNCTION__ = "retr_buf_handler"

#8 0x000000000048d82f in slow_timer_main () at timer.c:1130

n = 12

ret = 1

tl = 0x7fc2761f3708

i = 147

__FUNCTION__ = "slow_timer_main"

2015-09-15 10:35 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

Hi Thibault, I have not been able to get the crash reproducing the scenario you described. Could you try the last 4.3.x code? Are you still seeing the crash?

Regards,

Federico

On Fri, Sep 11, 2015 at 11:34 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hi Federico,

I will try last code in 4.3.x branch.

The scenario is very easy: I am calling a SIP client (running on a mobile) First the client is stopped. Then launch the app. As expected, the calll is presented after it has registered. Then kill the application (before answering), then launching again the app, call is presented... Then waiting for call timeout. It works one or 2 times then call never timeouts on the client which initiates the call (which means Kamailio is dead and does not send 408 Timeout)

2015-09-10 19:33 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

...

Hi Thibault, have you tried last tsilo code from 4.3.x branch? Recently there has been a fix ( https://github.com/kamailio/kamailio/commit/6ce6803d57dabe287d7d6fa859e93c1d...) for an issue that may be related to yours. I'll keep investigating to see if I can spot something else. In the meanwhile could you describe your scenario? Are you storing multiple transactions per ruri? Did any of them got a final reply before the crash?

Regards,

Federico

On Thu, Sep 10, 2015 at 3:00 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:

...

On 10/09/15 14:36, Thibault Gueslin wrote:

2015-09-10 14:25 GMT+02:00 Daniel-Constantin Mierla < miconda@gmail.commiconda@gmail.com>:

...

Do you have msrp enabled in configuration file

I don't think so

The last frames of backtrace indicates code related to msrp, but might be just some code lines mismatching.

The issue seems to be in tsilo. I looke over the code and I spotted some "unclear" mechanisms that can lead to race conditions, which may result in invalid access to memory, as it happens in this case, ptr becomes 0x8b08578b49642454 -- from my short investigation, that is likely to be due to following a ->next field in a freed structure.

Not being the author of tsilo module, I can't do much more right now. I will open an issue on bug tracker explaining what I found, assigning Federico (cc-ed, author of the module) to analyze and see if anything is wrong there.

Cheers, Daniel

Hello Federico,

You are right. The first line comes from the other core dump (which is related to normal sig handling on crash).

In my scenario, I have only 2 SIP client: one caller and one callee I am starting the callee after call is initiated then kill the callee, then relaunch the callee. Each time I expect the call to be presented again. It seems that the issue arrives when I wait for timeout after this scenario.

Its confirmed by the log where the issue arrives each time in MANAGE_FAILURE

failure_route[MANAGE_FAILURE] { route(NATMANAGE);

if (t_is_canceled()) { exit; } .... }

9(30189) DEBUG: tm [t_reply.c:1230]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=408 9(30189) exec: *** cfgtrace:failure_route=[MANAGE_FAILURE] c=[/etc/kamailio/kamailio.cfg] l=1089 a=5 n=route 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=950 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=943 a=24 n=is_request 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=949 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=944 a=24 n=has_totag 9(30189) DEBUG: siputils [checks.c:97]: has_totag(): no totag 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=953 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=950 a=41 n=isflagset 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=953 a=25 n=rtpproxy_manage 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=962 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=955 a=24 n=is_request 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=961 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=956 a=24 n=has_totag 9(30189) DEBUG: siputils [checks.c:97]: has_totag(): no totag 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=960 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=957 a=24 n=t_is_branch_route 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=969 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=962 a=24 n=is_reply 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=969 a=2 n=return 9(30189) exec: *** cfgtrace:failure_route=[MANAGE_FAILURE] c=[/etc/kamailio/kamailio.cfg] l=1112 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[MANAGE_FAILURE] c=[/etc/kamailio/kamailio.cfg] l=1091 a=24 n=t_is_canceled 9(30189) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=9 global id=9 T start=0x7f088e376a78 9(30189) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!

19(30199) CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 20 19(30199) DEBUG: <core> [tcp_main.c:3448]: handle_ser_child(): dead child 9, pid 30189 (shutting down?) 19(30199) DEBUG: <core> [io_wait.h:598]: io_watch_del(): DBG: io_watch_del (0x9ddc40, 20, -1, 0x0) fd_no=25 called 0(30180) ALERT: <core> [main.c:728]: handle_sigs(): child process 30189 exited by a signal 11 0(30180) ALERT: <core> [main.c:731]: handle_sigs(): core was generated 0(30180) INFO: <core> [main.c:743]: handle_sigs(): terminating due to SIGCHLD

The conf comes from your presentation ! (http://fr.slideshare.net/FedericoCabiddu/kamailioinamobileworld-51617342)

Small changes:

request_route { .. # account only INVITEs if (is_method("INVITE")) { setflag(FLT_ACC); # do accounting route(RELAY); route(INVITE); exit; }

# Wrapper for relaying requests route[RELAY] {

# enable additional event routes for forwarded requests # - serial forking, RTP relaying handling, a.s.o. if (is_method("INVITE|BYE|SUBSCRIBE|UPDATE")) { if(!t_is_set("branch_route")) t_on_branch("MANAGE_BRANCH"); } if (is_method("INVITE|SUBSCRIBE|UPDATE")) { if(!t_is_set("onreply_route")) t_on_reply("MANAGE_REPLY"); } if (is_method("INVITE")) { if(!t_is_set("failure_route")) t_on_failure("MANAGE_FAILURE"); } else {

if (!t_relay()) { sl_reply_error(); } exit; }

}

the other part is like you: # manage incoming REGISTERs route[INVITE] { if (!lookup("location")) { send_reply("100", "Trying"); route(SUSPEND); } else { t_relay(); ts_store(); $sht(vtp=>stored::$rU) = 1; xdbg("stored transaction [$T(id_index):$T(id_label)] $fU => $rU\n"); } route(SENDPUSH); }

#suspend route route[SUSPEND] { if(!t_suspend()) { xlog("failed suspending trasaction [$T(id_index): $T(id_label)]n"); send_reply("501", "Unknown destination"); exit; } xdbg("suspended transaction [$T(id_index):$T(id_label)] $fU => $rU\n"); $sht(vtp=>join::$rU) = "" + $T(id_index) + ":" + $T(id_label); xdbg("htable key value [$sht(vtp=>join::$rU)]n"); }

route[REGISTER] { if(isflagset(FLT_NATS)) { setbflag(FLB_NATB); #!ifdef WITH_NATSIPPING # do SIP NAT pinging setbflag(FLB_NATSIPPING); #!endif } if (!save("location")) sl_reply_error(); route(PUSHJOIN); exit; }

route[PUSHJOIN] { $var(hjoin) = 0; lock("$tU"); $var(hjoin) = $sht(vtp=>join::$tU); $var(hstored) = $sht(vtp=>stored::$tU); $sht(vtp=>join::$tU) = $null; unlock("$tU"); if ($var(hjoin)==0) { if ($var(hstored)) ts_append("location", "$tU"); return; } $var(id_index) = $(var(hjoin){s.select,0,:}{s.int}); $var(id_label) = $(var(hjoin){s.select,1,:}{s.int}); xdbg("resuming transaction [$var(id_index):$var(id_label)] $tU ($var(hjoin))n"); t_continue("$var(id_index)", "$var(id_label)", "INVRESUME"); }

route[INVRESUME] { lookup("location"); t_relay(); ts_store(); $sht(vtp=>stored::$rU) = 1; xdbg("stored transaction [$T(id_index):$T(id_label)] $fU => $rU\n"); }

regards

2015-09-16 8:23 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

Hi Thibault, I'm not sure I understand the scenario of your crash. Is the branch rejecting the call a branch added with ts_append? What are you doing upon receiving the 603 (supposing that's how the application is rejecting the call)? Are you appending other branches? In the bt it looks like the transaction timed out but then the the log line

"#0 0x00007fc279f64855 in lock_entry (entry=0x7fc2761d6068) at ts_hash.c:156"

and the core seem unrelated. Maybe you can share the relevant parts of your routing script so that I can get better what's going on. Also it would be very useful if you could provide the logs of your test with debug level 3. Thanks for your collaboration.

Regards,

Federico

On Tue, Sep 15, 2015 at 5:53 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hello Federico,

I have built from 4.3 branch.

I got a crash again... However it seems different than previous one:

Issue seems located in tm module.

It appears if the remote denied the incoming call, then quit application .

thibault

Core was generated by `sbin/kamailio -f /etc/kamailio/kamailio.cfg -L ./lib64/kamailio/modules/'.

Program terminated with signal SIGSEGV, Segmentation fault.

#0 0x00007fc279f64855 in lock_entry (entry=0x7fc2761d6068) at ts_hash.c:156

156 ts_lock(t_table, entry);

(gdb) bt full

#0 0x0000000000000001 in ?? ()

No symbol table info available.

#1 0x00007fc27cd77fd9 in free_faked_req (faked_req=0x7fc27d029100 <faked_req>, t=0x7fc2761f2fc0) at t_reply.c:931

    hdr = 0x0

    __FUNCTION__ = "free_faked_req"

#2 0x00007fc27cd78df4 in run_failure_handlers (t=0x7fc2761f2fc0, rpl=0xffffffffffffffff, code=408, extra_flags=96) at t_reply.c:997

    faked_req = {id = 3, pid = 15569, tval = {tv_sec = 1442326316,

tv_usec = 475922}, fwd_send_flags = {f = 4 '\004', blst_imask = 0 '\000'}, rpl_send_flags = {f = 0 '\000', blst_imask = 0 '\000'},

      first_line = {type = 1, flags = 1, len = 68, u = {request =

{method = {

              s = 0x7fc2761efc08 "INVITE

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 6}, uri = {

              s = 0x7fc2761efc0f "

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;tran"..., len = 51}, version = {

              s = 0x7fc2761efc43 "SIP/2.0\r\nVia: SIP/2.0/TCP

172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;transport=tcp\r\nMax-Forwards: 69\r\nTo: <sip:toto4.toto.co"..., len = 7}, method_value = 1}, reply = {version = {

              s = 0x7fc2761efc08 "INVITE

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 6}, status = {

              s = 0x7fc2761efc0f "

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;tran"..., len = 51}, reason = {

              s = 0x7fc2761efc43 "SIP/2.0\r\nVia: SIP/2.0/TCP

172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;transport=tcp\r\nMax-Forwards: 69\r\nTo: <sip:toto4.toto.co"..., len = 7}, statuscode = 1}}}, via1 = 0x7fc2761f0008, via2 = 0x0, headers = 0x7fc2761effc8, last_header = 0x7fc2761f07c0, parsed_flag = 18446744073709551615,

      h_via1 = 0x7fc2761effc8, h_via2 = 0x0, callid = 0x7fc2761f0650,

to = 0x7fc2761f01f0, cseq = 0x7fc2761f0690, from = 0x7fc2761f0408, contact = 0x7fc2761f0170, maxforwards = 0x7fc2761f01b0, route = 0x0,

      record_route = 0x0, content_type = 0x7fc2761f0780,

content_length = 0x7fc2761f07c0, authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported = 0x0, require = 0x0, proxy_require = 0x0,

      unsupported = 0x0, allow = 0x7fc2761f0740, event = 0x0, accept

= 0x0, accept_language = 0x0, organization = 0x0, priority = 0x0, subject = 0x0, user_agent = 0x7fc2761f0700, server = 0x0,

      content_disposition = 0x0, diversion = 0x0, rpid = 0x0,

refer_to = 0x0, session_expires = 0x0, min_se = 0x0, sipifmatch = 0x0, subscription_state = 0x0, date = 0x0, identity = 0x0, identity_info = 0x0,

      pai = 0x0, ppi = 0x0, path = 0x0, privacy = 0x0, body =

0x7fc27e026c70,

      eoh = 0x7fc2761efe45 "\r\nv=0\r\no=- 791306690 125312959 IN IP4

172.16.224.222\r\ns=-\r\nc=IN IP4 172.16.224.222\r\nt=0 0\r\na=tool:baresip 0.4.3\r\nm=audio 25940 RTP/AVP 96 97 98 8 0 101\r\nb=AS:125\r\na=rtpmap:96 opus/48000/2\r\na=rtpmap:97"...,

      unparsed = 0x7fc2761efe45 "\r\nv=0\r\no=- 791306690 125312959

IN IP4 172.16.224.222\r\ns=-\r\nc=IN IP4 172.16.224.222\r\nt=0 0\r\na=tool:baresip 0.4.3\r\nm=audio 25940 RTP/AVP 96 97 98 8 0 101\r\nb=AS:125\r\na=rtpmap:96 opus/48000/2\r\na=rtpmap:97"..., rcv = {src_ip = {af = 2, len = 4, u = {addrl = {3334267998, 0}, addr32 = {3334267998, 0, 0, 0}, addr16 = {58462, 50876, 0, 0, 0, 0, 0, 0},

            addr = "^\344\274\306", '\000' <repeats 11 times>}},

dst_ip = {af = 2, len = 4, u = {addrl = {2667915013, 0}, addr32 = {2667915013, 0, 0, 0}, addr16 = {9989, 40709, 0, 0, 0, 0, 0, 0},

            addr = "\005'\005\237", '\000' <repeats 11 times>}},

src_port = 54927, dst_port = 5060, proto_reserved1 = 1, proto_reserved2 = 0, src_su = {s = {sa_family = 2,

            sa_data =

"\326\217^\344\274\306\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 36822, sin_addr = {s_addr = 3334267998}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {

            sin6_family = 2, sin6_port = 36822, sin6_flowinfo =

3334267998, 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 = 1979090440}}, bind_address =

0x7fc27e03d9f0, proto = 2 '\002'},

      buf = 0x7fc2761efc08 "INVITE

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 959, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len = 0}, parsed_uri_ok = 0, parsed_uri = {user = {

          s = 0x7fc2761efba4

"toto4.toto.com.Thibault@172.16.230.61:52915 ;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:"..., len = 23}, passwd = {s = 0x0, len = 0}, host = {

          s = 0x7fc2761efbbc "172.16.230.61:52915

;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b8"..., len = 13}, port = {

          s = 0x7fc2761efbca

"52915;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;r"..., len = 5}, params = {

          s = 0x7fc2761efbd0 "transport=tcpP/2sip:94.228.188.198:52919

;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\n"..., len = 13}, sip_params = {s = 0x7fc27e02a260 ' ' <repeats 88 times>, "HK\001~\302\177", len = 13}, headers = {s = 0x0, len = 0}, port_no = 52915, proto = 2, type = SIP_URI_T,

        flags = (unknown: 0), transport = {

          s = 0x7fc2761efbd0 "transport=tcpP/2sip:94.228.188.198:52919

;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\n"..., len = 13}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {

          s = 0x0, len = 0}, transport_val = {

          s = 0x7fc2761efbda "tcpP/2sip:94.228.188.198:52919

;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <"..., len = 3}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {

          s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}},

parsed_orig_ruri_ok = 0, parsed_orig_ruri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0,

          len = 0}, params = {s = 0x0, len = 0}, sip_params = {s =

0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = (unknown: 0), transport = {s = 0x0, len = 0},

        ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0},

maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0},

        transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len =

0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0},

        r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}},

add_rm = 0x7fc2761f4ac8, body_lumps = 0x0, reply_lump = 0x0,

      add_to_branch_s =

"z9hG4bK4d8.005be33152cbbe2a3c79d27fff052452.3", '\000' <repeats 12 times>, add_to_branch_len = 45, hash_index = 2260, msg_flags = 266481, flags = 34, set_global_address = {s = 0x0,

        len = 0}, set_global_port = {s = 0x0, len = 0},

force_send_socket = 0x7fc27e03d9f0, path_vec = {s = 0x0, len = 0}, instance = {s = 0x0, len = 0}, reg_id = 0, ruid = {s = 0x0, len = 0}, location_ua = {

        s = 0x0, len = 0}, ldv = {flow = {decoded = 0, rcv = {src_ip

= {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}},

            dst_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 =

{0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, src_port = 0, dst_port = 0, proto_reserved1 = 0,

    __FUNCTION__ = "run_failure_handlers"

#3 0x00007fc27cd7ba3b in t_should_relay_response (Trans=0x7fc2761f2fc0, new_code=408, branch=3, should_store=0x7fff9a9b9248, should_relay=0x7fff9a9b924c, cancel_data=0x7fff9a9b92e0, reply=0xffffffffffffffff)

at t_reply.c:1342

    branch_cnt = 4

    picked_code = 408

    new_branch = 1

    inv_through = 0

    extra_flags = 96

    i = 32706

    replies_dropped = 0

    __FUNCTION__ = "t_should_relay_response"

#4 0x00007fc27cd7e7d6 in relay_reply (t=0x7fc2761f2fc0, p_msg=0xffffffffffffffff, branch=3, msg_status=408, cancel_data=0x7fff9a9b92e0, do_put_on_wait=0) at t_reply.c:1745

    relay = -1

    save_clone = 0

    buf = 0x0

    res_len = 0

    relayed_code = 0

    relayed_msg = 0x0

    reply_bak = 0x1

    bm = {to_tag_val = {s = 0x200000000 <error: Cannot access memory

at address 0x200000000>, len = 1981755328}}

    totag_retr = 0

    reply_status = RPS_ERROR

    uas_rb = 0xffffffffffffffff

    to_tag = 0x7fc2761f3780

    reason = {s = 0x735c44 "Request Timeout", len = -1701080344}

    onsend_params = {req = 0x76203528, rpl = 0x7fc2761f35c0, param =

0x18f59272ffffffff, code = 418744713, flags = 320, branch = 0, t_rbuf = 0x3ef3ee10, dst = 0x415ed0 <_start>, send_buf = {

        s = 0x7fff9a9b92c0 "\020\223\233\232\377\177", len =

2094439873}}

    ip = {af = 2593886736, len = 32767, u = {addrl =

{140473294816037, 18446744069414584320}, addr32 = {2094433061, 32706, 0, 4294967295}, addr16 = {33573, 31958, 32706, 0, 0, 0, 65535, 65535},

        addr =

"%\203\326|\302\177\000\000\000\000\000\000\377\377\377\377"}}

    __FUNCTION__ = "relay_reply"

#5 0x00007fc27cda99d8 in fake_reply (t=0x7fc2761f2fc0, branch=3, code=408) at timer.c:328

    cancel_data = {cancel_bitmap = 0, reason = {cause = 0, u = {text

= {s = 0x0, len = 1981755328}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 1981755328}}}}

    do_cancel_branch = 1

    reply_status = 15561

#6 0x00007fc27cda9e5f in final_response_handler (r_buf=0x7fc2761f36e8, t=0x7fc2761f2fc0) at timer.c:500

    silent = 0

    branch_ret = 0

    prev_branch = 1056173584

    now = 0

#7 0x00007fc27cda9f02 in retr_buf_handler (ticks=418744835, tl=0x7fc2761f3708, p=0xfffffffe) at timer.c:558

    rbuf = 0x7fc2761f36e8

    fr_remainder = 2593887152

    retr_remainder = 32706

    retr_interval = 1979369672

    new_retr_interval_ms = 140473182140168

    crt_retr_interval_ms = 140473179752648

    t = 0x7fc2761f2fc0

    __FUNCTION__ = "retr_buf_handler"

#8 0x000000000048d82f in slow_timer_main () at timer.c:1130

    n = 12

    ret = 1

    tl = 0x7fc2761f3708

    i = 147

    __FUNCTION__ = "slow_timer_main"

2015-09-15 10:35 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

...

Hi Thibault, I have not been able to get the crash reproducing the scenario you described. Could you try the last 4.3.x code? Are you still seeing the crash?

Regards,

Federico

On Fri, Sep 11, 2015 at 11:34 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hi Federico,

I will try last code in 4.3.x branch.

The scenario is very easy: I am calling a SIP client (running on a mobile) First the client is stopped. Then launch the app. As expected, the calll is presented after it has registered. Then kill the application (before answering), then launching again the app, call is presented... Then waiting for call timeout. It works one or 2 times then call never timeouts on the client which initiates the call (which means Kamailio is dead and does not send 408 Timeout)

2015-09-10 19:33 GMT+02:00 Federico Cabiddu <federico.cabiddu@gmail.com

...

:

...

Hi Thibault, have you tried last tsilo code from 4.3.x branch? Recently there has been a fix ( https://github.com/kamailio/kamailio/commit/6ce6803d57dabe287d7d6fa859e93c1d...) for an issue that may be related to yours. I'll keep investigating to see if I can spot something else. In the meanwhile could you describe your scenario? Are you storing multiple transactions per ruri? Did any of them got a final reply before the crash?

Regards,

Federico

On Thu, Sep 10, 2015 at 3:00 PM, Daniel-Constantin Mierla < miconda@gmail.com> wrote:

...

On 10/09/15 14:36, Thibault Gueslin wrote:

2015-09-10 14:25 GMT+02:00 Daniel-Constantin Mierla < miconda@gmail.commiconda@gmail.com>:

> Do you have msrp enabled in configuration file >

I don't think so

The last frames of backtrace indicates code related to msrp, but might be just some code lines mismatching.

The issue seems to be in tsilo. I looke over the code and I spotted some "unclear" mechanisms that can lead to race conditions, which may result in invalid access to memory, as it happens in this case, ptr becomes 0x8b08578b49642454 -- from my short investigation, that is likely to be due to following a ->next field in a freed structure.

Not being the author of tsilo module, I can't do much more right now. I will open an issue on bug tracker explaining what I found, assigning Federico (cc-ed, author of the module) to analyze and see if anything is wrong there.

Cheers, Daniel

Hi Federico,

Thank you to keep looking at this.

I have sent you all my changes to default config. So there is nothing done after t_is_canceled (no voice mail, ...)

I have just enabled WITH_NAT & WITH_NATSIPPING.

I am sure if it is related but do you do special tricks for DECLINE (when enabling tsilo) ? (

The trace is always ending up with:

Program terminated with signal SIGSEGV, Segmentation fault.

#0 0x00007f5741b4efd7 in free_faked_req (faked_req=0x7f5741e00100 <faked_req>, t=0x7f573adb3c60) at t_reply.c:931

931 faked_req->body->free(&faked_req->body);

(gdb) p* faked_req->body->free

Cannot access memory at address 0x312e3838312e3832

It seems that the address of the "free" pointer is corrupted somewhere. I think I need to trace when it is modified (if it is possible).

Regards

thibault

2015-09-18 14:15 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

Hi Thibault, I tried again to reproduce the issue but with no luck. Are you doing something "special" in the failure route after calling t_is_canceled?

Regards,

Federico

On Wed, Sep 16, 2015 at 7:33 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hello Federico,

You are right. The first line comes from the other core dump (which is related to normal sig handling on crash).

In my scenario, I have only 2 SIP client: one caller and one callee I am starting the callee after call is initiated then kill the callee, then relaunch the callee. Each time I expect the call to be presented again. It seems that the issue arrives when I wait for timeout after this scenario.

Its confirmed by the log where the issue arrives each time in MANAGE_FAILURE

failure_route[MANAGE_FAILURE] { route(NATMANAGE);

if (t_is_canceled()) { exit; } .... }

9(30189) DEBUG: tm [t_reply.c:1230]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=408 9(30189) exec: *** cfgtrace:failure_route=[MANAGE_FAILURE] c=[/etc/kamailio/kamailio.cfg] l=1089 a=5 n=route 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=950 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=943 a=24 n=is_request 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=949 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=944 a=24 n=has_totag 9(30189) DEBUG: siputils [checks.c:97]: has_totag(): no totag 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=953 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=950 a=41 n=isflagset 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=953 a=25 n=rtpproxy_manage 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=962 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=955 a=24 n=is_request 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=961 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=956 a=24 n=has_totag 9(30189) DEBUG: siputils [checks.c:97]: has_totag(): no totag 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=960 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=957 a=24 n=t_is_branch_route 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=969 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=962 a=24 n=is_reply 9(30189) exec: *** cfgtrace:failure_route=[NATMANAGE] c=[/etc/kamailio/kamailio.cfg] l=969 a=2 n=return 9(30189) exec: *** cfgtrace:failure_route=[MANAGE_FAILURE] c=[/etc/kamailio/kamailio.cfg] l=1112 a=16 n=if 9(30189) exec: *** cfgtrace:failure_route=[MANAGE_FAILURE] c=[/etc/kamailio/kamailio.cfg] l=1091 a=24 n=t_is_canceled 9(30189) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=9 global id=9 T start=0x7f088e376a78 9(30189) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!

19(30199) CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 20 19(30199) DEBUG: <core> [tcp_main.c:3448]: handle_ser_child(): dead child 9, pid 30189 (shutting down?) 19(30199) DEBUG: <core> [io_wait.h:598]: io_watch_del(): DBG: io_watch_del (0x9ddc40, 20, -1, 0x0) fd_no=25 called 0(30180) ALERT: <core> [main.c:728]: handle_sigs(): child process 30189 exited by a signal 11 0(30180) ALERT: <core> [main.c:731]: handle_sigs(): core was generated 0(30180) INFO: <core> [main.c:743]: handle_sigs(): terminating due to SIGCHLD

The conf comes from your presentation ! (http://fr.slideshare.net/FedericoCabiddu/kamailioinamobileworld-51617342 )

Small changes:

request_route { .. # account only INVITEs if (is_method("INVITE")) { setflag(FLT_ACC); # do accounting route(RELAY); route(INVITE); exit; }

# Wrapper for relaying requests route[RELAY] {

# enable additional event routes for forwarded requests # - serial forking, RTP relaying handling, a.s.o. if (is_method("INVITE|BYE|SUBSCRIBE|UPDATE")) { if(!t_is_set("branch_route")) t_on_branch("MANAGE_BRANCH"); } if (is_method("INVITE|SUBSCRIBE|UPDATE")) { if(!t_is_set("onreply_route")) t_on_reply("MANAGE_REPLY"); } if (is_method("INVITE")) { if(!t_is_set("failure_route")) t_on_failure("MANAGE_FAILURE"); } else {

if (!t_relay()) { sl_reply_error(); } exit; }

}

the other part is like you: # manage incoming REGISTERs route[INVITE] { if (!lookup("location")) { send_reply("100", "Trying"); route(SUSPEND); } else { t_relay(); ts_store(); $sht(vtp=>stored::$rU) = 1; xdbg("stored transaction [$T(id_index):$T(id_label)] $fU => $rU\n"); } route(SENDPUSH); }

#suspend route route[SUSPEND] { if(!t_suspend()) { xlog("failed suspending trasaction [$T(id_index): $T(id_label)]n"); send_reply("501", "Unknown destination"); exit; } xdbg("suspended transaction [$T(id_index):$T(id_label)] $fU => $rU\n"); $sht(vtp=>join::$rU) = "" + $T(id_index) + ":" + $T(id_label); xdbg("htable key value [$sht(vtp=>join::$rU)]n"); }

route[REGISTER] { if(isflagset(FLT_NATS)) { setbflag(FLB_NATB); #!ifdef WITH_NATSIPPING # do SIP NAT pinging setbflag(FLB_NATSIPPING); #!endif } if (!save("location")) sl_reply_error(); route(PUSHJOIN); exit; }

route[PUSHJOIN] { $var(hjoin) = 0; lock("$tU"); $var(hjoin) = $sht(vtp=>join::$tU); $var(hstored) = $sht(vtp=>stored::$tU); $sht(vtp=>join::$tU) = $null; unlock("$tU"); if ($var(hjoin)==0) { if ($var(hstored)) ts_append("location", "$tU"); return; } $var(id_index) = $(var(hjoin){s.select,0,:}{s.int}); $var(id_label) = $(var(hjoin){s.select,1,:}{s.int}); xdbg("resuming transaction [$var(id_index):$var(id_label)] $tU ($var(hjoin))n"); t_continue("$var(id_index)", "$var(id_label)", "INVRESUME"); }

route[INVRESUME] { lookup("location"); t_relay(); ts_store(); $sht(vtp=>stored::$rU) = 1; xdbg("stored transaction [$T(id_index):$T(id_label)] $fU => $rU\n"); }

regards

2015-09-16 8:23 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

...

Hi Thibault, I'm not sure I understand the scenario of your crash. Is the branch rejecting the call a branch added with ts_append? What are you doing upon receiving the 603 (supposing that's how the application is rejecting the call)? Are you appending other branches? In the bt it looks like the transaction timed out but then the the log line

"#0 0x00007fc279f64855 in lock_entry (entry=0x7fc2761d6068) at ts_hash.c:156"

and the core seem unrelated. Maybe you can share the relevant parts of your routing script so that I can get better what's going on. Also it would be very useful if you could provide the logs of your test with debug level 3. Thanks for your collaboration.

Regards,

Federico

On Tue, Sep 15, 2015 at 5:53 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hello Federico,

I have built from 4.3 branch.

I got a crash again... However it seems different than previous one:

Issue seems located in tm module.

It appears if the remote denied the incoming call, then quit application .

thibault

Core was generated by `sbin/kamailio -f /etc/kamailio/kamailio.cfg -L ./lib64/kamailio/modules/'.

Program terminated with signal SIGSEGV, Segmentation fault.

#0 0x00007fc279f64855 in lock_entry (entry=0x7fc2761d6068) at ts_hash.c:156

156 ts_lock(t_table, entry);

(gdb) bt full

#0 0x0000000000000001 in ?? ()

No symbol table info available.

#1 0x00007fc27cd77fd9 in free_faked_req (faked_req=0x7fc27d029100 <faked_req>, t=0x7fc2761f2fc0) at t_reply.c:931

    hdr = 0x0

    __FUNCTION__ = "free_faked_req"

#2 0x00007fc27cd78df4 in run_failure_handlers (t=0x7fc2761f2fc0, rpl=0xffffffffffffffff, code=408, extra_flags=96) at t_reply.c:997

    faked_req = {id = 3, pid = 15569, tval = {tv_sec = 1442326316,

tv_usec = 475922}, fwd_send_flags = {f = 4 '\004', blst_imask = 0 '\000'}, rpl_send_flags = {f = 0 '\000', blst_imask = 0 '\000'},

      first_line = {type = 1, flags = 1, len = 68, u = {request =

{method = {

              s = 0x7fc2761efc08 "INVITE

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 6}, uri = {

              s = 0x7fc2761efc0f "

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;tran"..., len = 51}, version = {

              s = 0x7fc2761efc43 "SIP/2.0\r\nVia: SIP/2.0/TCP

172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;transport=tcp\r\nMax-Forwards: 69\r\nTo: <sip:toto4.toto.co"..., len = 7}, method_value = 1}, reply = {version = {

              s = 0x7fc2761efc08 "INVITE

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 6}, status = {

              s = 0x7fc2761efc0f "

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;tran"..., len = 51}, reason = {

              s = 0x7fc2761efc43 "SIP/2.0\r\nVia: SIP/2.0/TCP

172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: sip:toto4.toto.com.Ipod_tgu@172.16.224.222:54924;transport=tcp\r\nMax-Forwards: 69\r\nTo: <sip:toto4.toto.co"..., len = 7}, statuscode = 1}}}, via1 = 0x7fc2761f0008, via2 = 0x0, headers = 0x7fc2761effc8, last_header = 0x7fc2761f07c0, parsed_flag = 18446744073709551615,

      h_via1 = 0x7fc2761effc8, h_via2 = 0x0, callid =

0x7fc2761f0650, to = 0x7fc2761f01f0, cseq = 0x7fc2761f0690, from = 0x7fc2761f0408, contact = 0x7fc2761f0170, maxforwards = 0x7fc2761f01b0, route = 0x0,

      record_route = 0x0, content_type = 0x7fc2761f0780,

content_length = 0x7fc2761f07c0, authorization = 0x0, expires = 0x0, proxy_auth = 0x0, supported = 0x0, require = 0x0, proxy_require = 0x0,

      unsupported = 0x0, allow = 0x7fc2761f0740, event = 0x0,

accept = 0x0, accept_language = 0x0, organization = 0x0, priority = 0x0, subject = 0x0, user_agent = 0x7fc2761f0700, server = 0x0,

      content_disposition = 0x0, diversion = 0x0, rpid = 0x0,

refer_to = 0x0, session_expires = 0x0, min_se = 0x0, sipifmatch = 0x0, subscription_state = 0x0, date = 0x0, identity = 0x0, identity_info = 0x0,

      pai = 0x0, ppi = 0x0, path = 0x0, privacy = 0x0, body =

0x7fc27e026c70,

      eoh = 0x7fc2761efe45 "\r\nv=0\r\no=- 791306690 125312959 IN

IP4 172.16.224.222\r\ns=-\r\nc=IN IP4 172.16.224.222\r\nt=0 0\r\na=tool:baresip 0.4.3\r\nm=audio 25940 RTP/AVP 96 97 98 8 0 101\r\nb=AS:125\r\na=rtpmap:96 opus/48000/2\r\na=rtpmap:97"...,

      unparsed = 0x7fc2761efe45 "\r\nv=0\r\no=- 791306690 125312959

IN IP4 172.16.224.222\r\ns=-\r\nc=IN IP4 172.16.224.222\r\nt=0 0\r\na=tool:baresip 0.4.3\r\nm=audio 25940 RTP/AVP 96 97 98 8 0 101\r\nb=AS:125\r\na=rtpmap:96 opus/48000/2\r\na=rtpmap:97"..., rcv = {src_ip = {af = 2, len = 4, u = {addrl = {3334267998, 0}, addr32 = {3334267998, 0, 0, 0}, addr16 = {58462, 50876, 0, 0, 0, 0, 0, 0},

            addr = "^\344\274\306", '\000' <repeats 11 times>}},

dst_ip = {af = 2, len = 4, u = {addrl = {2667915013, 0}, addr32 = {2667915013, 0, 0, 0}, addr16 = {9989, 40709, 0, 0, 0, 0, 0, 0},

            addr = "\005'\005\237", '\000' <repeats 11 times>}},

src_port = 54927, dst_port = 5060, proto_reserved1 = 1, proto_reserved2 = 0, src_su = {s = {sa_family = 2,

            sa_data =

"\326\217^\344\274\306\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 36822, sin_addr = {s_addr = 3334267998}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {

            sin6_family = 2, sin6_port = 36822, sin6_flowinfo =

3334267998, 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 = 1979090440}}, bind_address =

0x7fc27e03d9f0, proto = 2 '\002'},

      buf = 0x7fc2761efc08 "INVITE

sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <sip:toto4.toto.com.Ipod_tgu@172.16.224.222:549"..., len = 959, new_uri = {s = 0x0, len = 0}, dst_uri = {s = 0x0, len = 0}, parsed_uri_ok = 0, parsed_uri = {user = {

          s = 0x7fc2761efba4

"toto4.toto.com.Thibault@172.16.230.61:52915 ;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:"..., len = 23}, passwd = {s = 0x0, len = 0}, host = {

          s = 0x7fc2761efbbc "172.16.230.61:52915

;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b8"..., len = 13}, port = {

          s = 0x7fc2761efbca

"52915;transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.com SIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;r"..., len = 5}, params = {

          s = 0x7fc2761efbd0

"transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\n"..., len = 13}, sip_params = {s = 0x7fc27e02a260 ' ' <repeats 88 times>, "HK\001~\302\177", len = 13}, headers = {s = 0x0, len = 0}, port_no = 52915, proto = 2, type = SIP_URI_T,

        flags = (unknown: 0), transport = {

          s = 0x7fc2761efbd0

"transport=tcpP/2sip:94.228.188.198:52919;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\n"..., len = 13}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {

          s = 0x0, len = 0}, transport_val = {

          s = 0x7fc2761efbda "tcpP/2sip:94.228.188.198:52919

;transport=tcp92INVITE sip:toto4.toto.com.Thibault@sip-staging.serveur.comSIP/2.0\r\nVia: SIP/2.0/TCP 172.16.224.222:54924;branch=z9hG4bK44b87ead2c84b31a;rport\r\nContact: <"..., len = 3}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {

          s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}},

parsed_orig_ruri_ok = 0, parsed_orig_ruri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0,

          len = 0}, params = {s = 0x0, len = 0}, sip_params = {s =

0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = (unknown: 0), transport = {s = 0x0, len = 0},

        ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0},

maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0},

        transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len

= 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0},

        r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}},

add_rm = 0x7fc2761f4ac8, body_lumps = 0x0, reply_lump = 0x0,

      add_to_branch_s =

"z9hG4bK4d8.005be33152cbbe2a3c79d27fff052452.3", '\000' <repeats 12 times>, add_to_branch_len = 45, hash_index = 2260, msg_flags = 266481, flags = 34, set_global_address = {s = 0x0,

        len = 0}, set_global_port = {s = 0x0, len = 0},

force_send_socket = 0x7fc27e03d9f0, path_vec = {s = 0x0, len = 0}, instance = {s = 0x0, len = 0}, reg_id = 0, ruid = {s = 0x0, len = 0}, location_ua = {

        s = 0x0, len = 0}, ldv = {flow = {decoded = 0, rcv =

{src_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}},

            dst_ip = {af = 0, len = 0, u = {addrl = {0, 0}, addr32

= {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}}, src_port = 0, dst_port = 0, proto_reserved1 = 0,

    __FUNCTION__ = "run_failure_handlers"

#3 0x00007fc27cd7ba3b in t_should_relay_response (Trans=0x7fc2761f2fc0, new_code=408, branch=3, should_store=0x7fff9a9b9248, should_relay=0x7fff9a9b924c, cancel_data=0x7fff9a9b92e0, reply=0xffffffffffffffff)

at t_reply.c:1342

    branch_cnt = 4

    picked_code = 408

    new_branch = 1

    inv_through = 0

    extra_flags = 96

    i = 32706

    replies_dropped = 0

    __FUNCTION__ = "t_should_relay_response"

#4 0x00007fc27cd7e7d6 in relay_reply (t=0x7fc2761f2fc0, p_msg=0xffffffffffffffff, branch=3, msg_status=408, cancel_data=0x7fff9a9b92e0, do_put_on_wait=0) at t_reply.c:1745

    relay = -1

    save_clone = 0

    buf = 0x0

    res_len = 0

    relayed_code = 0

    relayed_msg = 0x0

    reply_bak = 0x1

    bm = {to_tag_val = {s = 0x200000000 <error: Cannot access

memory at address 0x200000000>, len = 1981755328}}

    totag_retr = 0

    reply_status = RPS_ERROR

    uas_rb = 0xffffffffffffffff

    to_tag = 0x7fc2761f3780

    reason = {s = 0x735c44 "Request Timeout", len = -1701080344}

    onsend_params = {req = 0x76203528, rpl = 0x7fc2761f35c0, param

= 0x18f59272ffffffff, code = 418744713, flags = 320, branch = 0, t_rbuf = 0x3ef3ee10, dst = 0x415ed0 <_start>, send_buf = {

        s = 0x7fff9a9b92c0 "\020\223\233\232\377\177", len =

2094439873}}

    ip = {af = 2593886736, len = 32767, u = {addrl =

{140473294816037, 18446744069414584320}, addr32 = {2094433061, 32706, 0, 4294967295}, addr16 = {33573, 31958, 32706, 0, 0, 0, 65535, 65535},

        addr =

"%\203\326|\302\177\000\000\000\000\000\000\377\377\377\377"}}

    __FUNCTION__ = "relay_reply"

#5 0x00007fc27cda99d8 in fake_reply (t=0x7fc2761f2fc0, branch=3, code=408) at timer.c:328

    cancel_data = {cancel_bitmap = 0, reason = {cause = 0, u =

{text = {s = 0x0, len = 1981755328}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 1981755328}}}}

    do_cancel_branch = 1

    reply_status = 15561

#6 0x00007fc27cda9e5f in final_response_handler (r_buf=0x7fc2761f36e8, t=0x7fc2761f2fc0) at timer.c:500

    silent = 0

    branch_ret = 0

    prev_branch = 1056173584

    now = 0

#7 0x00007fc27cda9f02 in retr_buf_handler (ticks=418744835, tl=0x7fc2761f3708, p=0xfffffffe) at timer.c:558

    rbuf = 0x7fc2761f36e8

    fr_remainder = 2593887152

    retr_remainder = 32706

    retr_interval = 1979369672

    new_retr_interval_ms = 140473182140168

    crt_retr_interval_ms = 140473179752648

    t = 0x7fc2761f2fc0

    __FUNCTION__ = "retr_buf_handler"

#8 0x000000000048d82f in slow_timer_main () at timer.c:1130

    n = 12

    ret = 1

    tl = 0x7fc2761f3708

    i = 147

    __FUNCTION__ = "slow_timer_main"

2015-09-15 10:35 GMT+02:00 Federico Cabiddu <federico.cabiddu@gmail.com

...

:

...

Hi Thibault, I have not been able to get the crash reproducing the scenario you described. Could you try the last 4.3.x code? Are you still seeing the crash?

Regards,

Federico

On Fri, Sep 11, 2015 at 11:34 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hi Federico,

I will try last code in 4.3.x branch.

The scenario is very easy: I am calling a SIP client (running on a mobile) First the client is stopped. Then launch the app. As expected, the calll is presented after it has registered. Then kill the application (before answering), then launching again the app, call is presented... Then waiting for call timeout. It works one or 2 times then call never timeouts on the client which initiates the call (which means Kamailio is dead and does not send 408 Timeout)

2015-09-10 19:33 GMT+02:00 Federico Cabiddu < federico.cabiddu@gmail.com>:

> Hi Thibault, > have you tried last tsilo code from 4.3.x branch? > Recently there has been a fix ( > https://github.com/kamailio/kamailio/commit/6ce6803d57dabe287d7d6fa859e93c1d...) > for an issue that may be related to yours. > I'll keep investigating to see if I can spot something else. In the > meanwhile could you describe your scenario? Are you storing multiple > transactions per ruri? Did any of them got a final reply before the crash? > > Regards, > > Federico > > On Thu, Sep 10, 2015 at 3:00 PM, Daniel-Constantin Mierla < > miconda@gmail.com> wrote: > >> >> >> On 10/09/15 14:36, Thibault Gueslin wrote: >> >> >> >> 2015-09-10 14:25 GMT+02:00 Daniel-Constantin Mierla < >> miconda@gmail.commiconda@gmail.com>: >> >>> Do you have msrp enabled in configuration file >>> >> >> I don't think so >> >> >> The last frames of backtrace indicates code related to msrp, but >> might be just some code lines mismatching. >> >> The issue seems to be in tsilo. I looke over the code and I spotted >> some "unclear" mechanisms that can lead to race conditions, which may >> result in invalid access to memory, as it happens in this case, ptr becomes >> 0x8b08578b49642454 -- from my short investigation, that is likely to be due >> to following a ->next field in a freed structure. >> >> Not being the author of tsilo module, I can't do much more right >> now. I will open an issue on bug tracker explaining what I found, assigning >> Federico (cc-ed, author of the module) to analyze and see if anything is >> wrong there. >> >> Cheers, >> Daniel >> >> >>

Hi, I've finally managed to understand what was causing the crash. I've submitted a pull request with a proposal for a fix ( https://github.com/kamailio/kamailio/pull/346). Let's wait Daniel thoughts about it :)

Regards,

Federico

On Sun, Sep 20, 2015 at 4:17 PM, Federico Cabiddu < federico.cabiddu@gmail.com> wrote:

Hi Thibault, there is no need for special decline handling when using tsilo, so the default basic should work with the modifications you've done. I tested your scenario with this config and I haven't been able to get the crash. Could you please perform a test with debug level 3 and send me the whole log and the trace, sending them to my email address or sharing them?

Regards,

Federico

On Fri, Sep 18, 2015 at 3:38 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hi Federico,

Thank you to keep looking at this.

I have sent you all my changes to default config. So there is nothing done after t_is_canceled (no voice mail, ...)

I have just enabled WITH_NAT & WITH_NATSIPPING.

I am sure if it is related but do you do special tricks for DECLINE (when enabling tsilo) ? (

The trace is always ending up with:

Program terminated with signal SIGSEGV, Segmentation fault.

#0 0x00007f5741b4efd7 in free_faked_req (faked_req=0x7f5741e00100 <faked_req>, t=0x7f573adb3c60) at t_reply.c:931

931 faked_req->body->free(&faked_req->body);

(gdb) p* faked_req->body->free

Cannot access memory at address 0x312e3838312e3832

It seems that the address of the "free" pointer is corrupted somewhere. I think I need to trace when it is modified (if it is possible).

Regards

thibault

Federico,

I have tried to apply your commit on the branch 4.3 (just the modifications on t_append_branch.c)

The result is not very good (failure route not called, 408 timeout not send...)

Have you a patch for the 4.3 branch ?

Regards

thibault

2015-09-28 11:45 GMT+02:00 Thibault Gueslin thibault.gueslin@gmail.com:

Federico,

This is good news!

I will try it as soon as possible

Regards

thibault

2015-09-28 9:25 GMT+02:00 Federico Cabiddu federico.cabiddu@gmail.com:

...

Hi, I've finally managed to understand what was causing the crash. I've submitted a pull request with a proposal for a fix ( https://github.com/kamailio/kamailio/pull/346). Let's wait Daniel thoughts about it :)

Regards,

Federico

On Sun, Sep 20, 2015 at 4:17 PM, Federico Cabiddu < federico.cabiddu@gmail.com> wrote:

...

Hi Thibault, there is no need for special decline handling when using tsilo, so the default basic should work with the modifications you've done. I tested your scenario with this config and I haven't been able to get the crash. Could you please perform a test with debug level 3 and send me the whole log and the trace, sending them to my email address or sharing them?

Regards,

Federico

On Fri, Sep 18, 2015 at 3:38 PM, Thibault Gueslin < thibault.gueslin@gmail.com> wrote:

...

Hi Federico,

Thank you to keep looking at this.

I have sent you all my changes to default config. So there is nothing done after t_is_canceled (no voice mail, ...)

I have just enabled WITH_NAT & WITH_NATSIPPING.

I am sure if it is related but do you do special tricks for DECLINE (when enabling tsilo) ? (

The trace is always ending up with:

Program terminated with signal SIGSEGV, Segmentation fault.

#0 0x00007f5741b4efd7 in free_faked_req (faked_req=0x7f5741e00100 <faked_req>, t=0x7f573adb3c60) at t_reply.c:931

931 faked_req->body->free(&faked_req->body);

(gdb) p* faked_req->body->free

Cannot access memory at address 0x312e3838312e3832

It seems that the address of the "free" pointer is corrupted somewhere. I think I need to trace when it is modified (if it is possible).

Regards

thibault

---

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