[sr-dev] [kamailio/kamailio] Suddenly found kamailio dead (#1717)

9 Nov 2018

### Description

While doing some fail over tests I suddenly found one kamailio dead. 

### Troubleshooting

#### Debugging Data

```
(gdb) bt full
#0  0xb6be2dd7 in populate_leg_info (dlg=0xb4d848bc, msg=0xb728901c, t=0xb4dfcbe8, leg=1,
tag=0xbfee046c) at dlg_handlers.c:251
        __llevel = 3
        skip_recs = 1
        cseq = {s = 0x0, len = 0}
        contact = {
          s = 0xb4e3f17c
"sip:3030911@10.6.148.164:5061;transport=tls>;+u.sip!devicename.ccm.cisco.com=\"SEP00451D6E4F37\"\r\nContent-Type:
application/sdp\r\nContent-Length: 308\r\n\r\nv=0\r\no=CiscoSystemsCCM-SIP 1475 1 IN IP4
10.6.148."..., len = 43}
        rr_set = {s = 0xb728945c
"<sip:10.6.150.163:5061;transport=tls;lr;did=e83.ac6>\300\300\300\300\355\357\315\253",
len = 52}
        __FUNCTION__ = "populate_leg_info"
#1  0xb6be5817 in dlg_onreply (t=0xb4dfcbe8, type=1048576, param=0xbfee05a8) at
dlg_handlers.c:497
        dlg = 0xb4d848bc
        iuid = 0xb4ceaba4
        new_state = 3
        old_state = 2
        unref = 0
        event = 3
        tag = {
          s = 0xb4e3ee33 "1475~853040b9-3e40-4c54-a456-6aead5ad927d-42986430\r\nDate:
Thu, 08 Nov 2018 13:59:40 GMT\r\nCall-ID:
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071\r\nCSeq: 102 INVITE\r\nAllow: INVITE,
OPTIONS, INFO, BY"..., len = 50}
        req = 0xb4dfa58c
        rpl = 0xb728901c
        __FUNCTION__ = "dlg_onreply"
#2  0xb6fa1d98 in run_trans_callbacks_internal (cb_lst=0xb4dfcc28, type=1048576,
trans=0xb4dfcbe8, params=0xbfee05a8) at t_hooks.c:260
        cbp = 0xb4cf417c
        backup_from = 0x8491090
        backup_to = 0x8491094
        backup_dom_from = 0x8491098
        backup_dom_to = 0x849109c
        backup_uri_from = 0x8491088
        backup_uri_to = 0x849108c
        backup_xavps = 0x849111c
        __FUNCTION__ = "run_trans_callbacks_internal"
#3  0xb6fa1f8b in run_trans_callbacks_with_buf (type=1048576, rbuf=0xb4dfcc58,
req=0xb4dfa58c, repl=0xb728901c, flags=0) at t_hooks.c:305
        params = {req = 0xb4dfa58c, rpl = 0xb728901c, param = 0xb4cf4188, code = 200,
flags = 0, branch = 0, t_rbuf = 0xb4dfcc58, dst = 0xb4dfcc8c, send_buf = {
            s = 0xb4df6844 "SIP/2.0 200 OK\r\nVia: SIP/2.0/TLS
10.6.150.163:5071;branch=z9hG4bK08efd17b\r\nFrom: \"Personal/Zimmer 4322\"
<sip:4322@10.6.150.163:5071>;tag=as3df2635b\r\nTo: <sip:3030911@<Domain
A>:5061>"..., len = 1504}}
        trans = 0xb4dfcbe8
#4  0xb6fe49c8 in relay_reply (t=0xb4dfcbe8, p_msg=0xb728901c, branch=1, msg_status=200,
cancel_data=0xbfee0a68, do_put_on_wait=1) at t_reply.c:1948
        relay = 1
        save_clone = 0
        buf = 0xb728ba7c "SIP/2.0 200 OK\r\nVia: SIP/2.0/TLS
10.6.150.163:5071;branch=z9hG4bK08efd17b\r\nFrom: \"Personal/Zimmer 4322\"
<sip:4322@10.6.150.163:5071>;tag=as3df2635b\r\nTo: <sip:3030911@<Domain
A>:5061>"...
        res_len = 1504
        relayed_code = 200
        relayed_msg = 0xb728901c
        reply_bak = 0x837c358
        bm = {to_tag_val = {s = 0x83e7bb4 "core: core/parser/msg_parser.c", len
= 0}}
        totag_retr = 0
        reply_status = RPS_COMPLETED
        uas_rb = 0xb4dfcc58
        to_tag = 0xbfee07c8
        reason = {s = 0xb71d8008 "\001", len = -1222393428}
        onsend_params = {req = 0xb6fcf41e, rpl = 0xb4dfcd04, param = 0x0, code = 1, flags
= 36997, branch = 2086, t_rbuf = 0xb4916780, dst = 0x0, send_buf = {s = 0xe10 <Address
0xe10 out of bounds>, 
            len = 147776392}}
        ip = {af = 0, len = 0, u = {addrl = {0, 0, 1024, 3220047736}, addr32 = {0, 0,
1024, 3220047736}, addr16 = {0, 0, 0, 0, 1024, 0, 1912, 49134}, 
            addr =
"\000\000\000\000\000\000\000\000\000\004\000\000x\a\356\277"}}
        __FUNCTION__ = "relay_reply"
#5  0xb6fe86eb in reply_received (p_msg=0xb728901c) at t_reply.c:2528
        msg_status = 200
        last_uac_status = 180
        ack = 0x76 <Address 0x76 out of bounds>
---Type <return> to continue, or q <return> to quit---
        ack_len = 3076795573
        branch = 1
        reply_status = 1717986920
        onreply_route = 1
        cancel_data = {cancel_bitmap = 0, reason = {cause = 200, u = {text = {s = 0x0, len
= -1218037806}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = -1218037806}}}}
        uac = 0xb4dfce80
        t = 0xb4dfcbe8
        lack_dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data =
"\000\000\000\000\000\000\000\000\000\000X\000\000"}, sin = {sin_family = 0,
sin_port = 0, sin_addr = {s_addr = 0}, 
              sin_zero = "\000\000\000\000X\000\000"}, sin6 = {sin6_family = 0,
sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {
                  __u6_addr8 =
"\000\000\000\000X\000\000\000\224\353\343\264\214\221(\267", __u6_addr16 = {0,
0, 88, 0, 60308, 46307, 37260, 46888}, __u6_addr32 = {0, 88, 3034835860, 3072889228}}}, 
              sin6_scope_id = 3220049176}}, id = 137018730, proto = -55 '\311',
send_flags = {f = 13620, blst_imask = 12276}}
        backup_user_from = 0x8491090
        backup_user_to = 0x8491094
        backup_domain_from = 0x8491098
        backup_domain_to = 0x849109c
        backup_uri_from = 0x8491088
        backup_uri_to = 0x849108c
        backup_xavps = 0x849111c
        replies_locked = 1
        branch_ret = -1222075128
        prev_branch = 0
        blst_503_timeout = 0
        hf = 0x0
        onsend_params = {req = 0xbfee0bb8, rpl = 0xb6e62aad, param = 0xb728901c, code =
-1222221576, flags = 2920, branch = 49134, t_rbuf = 0xbfee0b64, dst = 0xb7289d08, send_buf
= {s = 0x0, len = 0}}
        ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf =
{-1224346812, 7, 66, -1074919704, -1424352641, 1731596048}, __mask_was_saved = 0,
__saved_mask = {__val = {138311512, 
                  138316452, 3220047960, 3220048648, 137024000, 892600471, 539368703,
8929416, 4294967295, 4294967295, 3076933691, 149363642, 4294967295, 4294967295,
3072573868, 3034837520, 3034837520, 
                  3034837830, 0, 0, 3072588424, 3077505129, 3077505112, 3077511086,
147776392, 2, 3076537489, 0, 1, 3069025416, 137872216, 137986862}}}}}
        bctx = 0x0
        keng = 0x0
        __FUNCTION__ = "reply_received"
#6  0x080ebf53 in do_forward_reply (msg=0xb728901c, mode=0) at core/forward.c:744
        new_buf = 0x0
        dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000'
<repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0},
sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {
              sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u =
{__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0,
0}, __u6_addr32 = {0, 0, 0, 0}}}, 
              sin6_scope_id = 0}}, id = 0, proto = 0 '\000', send_flags = {f = 0,
blst_imask = 0}}
        new_len = 1
        r = 0
        ip = {af = 3070802102, len = 3070845392, u = {addrl = {137872216, 3220049044,
3070802450, 31}, addr32 = {137872216, 3220049044, 3070802450, 31}, addr16 = {50008, 2103,
3220, 49134, 47634, 46856, 31, 
              0}, addr =
"X\303\067\b\224\f\356\277\022\272\b\267\037\000\000"}}
        s = 0x0
        len = 50
        __FUNCTION__ = "do_forward_reply"
#7  0x080ed6d2 in forward_reply (msg=0xb728901c) at core/forward.c:845
No locals.
#8  0x08168157 in receive_msg (
    buf=0xb4e3ecf8 "SIP/2.0 200 OK\r\nVia: SIP/2.0/TLS
10.6.150.163:5061;branch=z9hG4bKc522.e107b15bca467ea76ea50f1758747d2a.1;i=3;received=10.6.133.183,SIP/2.0/TLS
10.6.150.163:5071;branch=z9hG4bK08efd17b\r\nFrom: \"Personal"..., len=1614,
rcv_info=0xb4e3eb34) at core/receive.c:354
        msg = 0xb728901c
        ctx = {rec_lev = -1217462186, run_flags = 149363644, last_retcode = -1260131436,
jmp_env = {{__jmpbuf = {14769, 1643, 16383, 1614, -1260876176, -1261526144},
__mask_was_saved = 0, __saved_mask = {
                __val = {4294967295, 3065255242, 3220049776, 3077169805, 149363624,
892664008, 3077648372, 3220049908, 149363636, 3220049560, 3076929490, 3077505103,
3076795573, 3220049587, 3077645312, 4, 
                  1717986920, 6, 0, 3077648372, 3077168368, 0 <repeats 11
times>}}}}}
        bctx = 0x0
        ret = 0
        stats_on = 0
        tvb = {tv_sec = 1541686005, tv_usec = 59356}
        tve = {tv_sec = 0, tv_usec = 0}
        tz = {tz_minuteswest = 0, tz_dsttime = 0}
        diff = 0
        inb = {
          s = 0xb4e3ecf8 "SIP/2.0 200 OK\r\nVia: SIP/2.0/TLS
10.6.150.163:5061;branch=z9hG4bKc522.e107b15bca467ea76ea50f1758747d2a.1;i=3;received=10.6.133.183,SIP/2.0/TLS
10.6.150.163:5071;branch=z9hG4bK08efd17b\r\nFrom: \"Personal"..., len = 1614}
---Type <return> to continue, or q <return> to quit---
        netinfo = {data = {s = 0x0, len = -1074917264}, rcv = 0xb769e28d, dst =
0x8e71ba8}
        keng = 0x0
        evp = {data = 0xbfee0ed0, rcv = 0xb4e3eb34, dst = 0x0}
        __FUNCTION__ = "receive_msg"
#9  0x0825c84e in receive_tcp_msg (
    tcpbuf=0xb4e3ecf8 "SIP/2.0 200 OK\r\nVia: SIP/2.0/TLS
10.6.150.163:5061;branch=z9hG4bKc522.e107b15bca467ea76ea50f1758747d2a.1;i=3;received=10.6.133.183,SIP/2.0/TLS
10.6.150.163:5071;branch=z9hG4bK08efd17b\r\nFrom: \"Personal"..., len=1614,
rcv_info=0xb4e3eb34, con=0xb4e3eb20) at core/tcp_read.c:1379
        buf = 0x0
        bsize = 0
        blen = 308
        __FUNCTION__ = "receive_tcp_msg"
#10 0x0825eb3e in tcp_read_req (con=0xb4e3eb20, bytes_read=0xbfee16d4,
read_flags=0xbfee16cc) at core/tcp_read.c:1611
        bytes = 1614
        total_bytes = 1614
        resp = 1
        size = 0
        req = 0xb4e3eb94
        dst = {send_sock = 0xa, to = {s = {sa_family = 8193, sa_data =
"\000\000t\242'\267\067\001\000\000t\242'\267"}, sin = {sin_family =
8193, sin_port = 0, sin_addr = {s_addr = 3072828020}, 
              sin_zero = "7\001\000\000t\242'\267"}, sin6 = {sin6_family =
8193, sin6_port = 0, sin6_flowinfo = 3072828020, sin6_addr = {__in6_u = {
                  __u6_addr8 =
"7\001\000\000t\242'\267\020\016\000\000\000\000\000", __u6_addr16 = {311,
0, 41588, 46887, 3600, 0, 0, 0}, __u6_addr32 = {311, 3072828020, 3600, 0}}}, 
              sin6_scope_id = 4294967295}}, id = 0, proto = 4 '\004', send_flags =
{f = 0, blst_imask = 0}}
        c = 0 '\000'
        ret = 0
        __FUNCTION__ = "tcp_read_req"
#11 0x082624ea in handle_io (fm=0xb727a274, events=1, idx=-1) at core/tcp_read.c:1843
        ret = 0
        n = 477
        read_flags = 1
        con = 0xb4e3eb20
        s = 12
        resp = 1
        t = 188163427
        __FUNCTION__ = "handle_io"
#12 0x0825138b in io_wait_loop_epoll (h=0x845eca0, t=2, repeat=0) at core/io_wait.h:1065
        n = 1
        r = 0
        fm = 0xb727a274
        revents = 1
        __FUNCTION__ = "io_wait_loop_epoll"
#13 0x082637df in tcp_receive_loop (unix_sock=43) at core/tcp_read.c:1955
        __FUNCTION__ = "tcp_receive_loop"
#14 0x08247c77 in tcp_init_children () at core/tcp_main.c:4853
        r = 6
        i = 7
        reader_fd_1 = 43
        pid = 0
        si_desc = "tcp receiver
(generic)\000\264\a\000\000\000\237{\"\267\031\000\000\000\070\032\356\277i\300&\b\377\377\377\377)]=\b\001\000\000\000\271\272&\b\000\000\000\000\001\000\000\000\000\000\000\000\bys\267\317\000\000\000\006\002y\005\364\217u\267\350(\005\bH\230u\267
\032\356\277G\204t\267H\230u\267\027\000\000\000\030\000\000\000\003\000\000\000\n\000\000\000\236!\000"
        si = 0x0
        __FUNCTION__ = "tcp_init_children"
#15 0x08066a21 in main_loop () at main.c:1716
        i = 8
        pid = 8606
        si = 0x0
        si_desc = "udp receiver child=7 sock=10.6.150.163:5060\000\003",
'\000' <repeats 59 times>,
"3\000\000\000'\000\000\000\v\000\000\000\022\000\000\000\t\000\000\000v\000\000"
        nrprocs = 8
        woneinit = 1
        __FUNCTION__ = "main_loop"
#16 0x0806d2cb in main (argc=13, argv=0xbfee20b4) at main.c:2645
        cfg_stream = 0x8ce8008
        c = -1
---Type <return> to continue, or q <return> to quit---
        r = 0
        tmp = 0xbfee2920 ""
        tmp_len = 0
        port = 0
        proto = 5
        options = 0x8367210
":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:"
        ret = -1
        seed = 14026375
        rfd = 12
        debug_save = 0
        debug_flag = 0
        dont_fork_cnt = 0
        n_lst = 0xb7759848
        p = 0xbfee2034 "p \356\277G\204t\267H\230u\267(|s\267\364/q\267"
        st = {st_dev = 18, __pad1 = 0, st_ino = 19230, st_mode = 16877, st_nlink = 2,
st_uid = 0, st_gid = 0, st_rdev = 0, __pad2 = 0, st_size = 40, st_blksize = 4096,
st_blocks = 0, st_atim = {
            tv_sec = 1539686948, tv_nsec = 794098330}, st_mtim = {tv_sec = 1539855591,
tv_nsec = 115278659}, st_ctim = {tv_sec = 1539855591, tv_nsec = 115278659}, __unused4 = 0,
__unused5 = 0}
        __FUNCTION__ = "main"

(gdb) info locals
__llevel = 3
skip_recs = 1
cseq = {s = 0x0, len = 0}
contact = {
  s = 0xb4e3f17c
"sip:3030911@10.6.148.164:5061;transport=tls>;+u.sip!devicename.ccm.cisco.com=\"SEP00451D6E4F37\"\r\nContent-Type:
application/sdp\r\nContent-Length: 308\r\n\r\nv=0\r\no=CiscoSystemsCCM-SIP 1475 1 IN IP4
10.6.148."..., len = 43}
rr_set = {s = 0xb728945c
"<sip:10.6.150.163:5061;transport=tls;lr;did=e83.ac6>\300\300\300\300\355\357\315\253",
len = 52}
__FUNCTION__ = "populate_leg_info"

(gdb) list
246	in dlg_handlers.c
```

#### Log Messages

```
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/tcp_read.c:1540]: tcp_read_req(): content-length=308 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status): 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0> 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg():  status:  <200> 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg():  reason:  <OK> 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> =
<z9hG4bKc522.e107b15bca467ea76ea50f1758747d2a.1>; state=6 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 236, <i> =
<3>; state=6 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received>
= <10.6.133.183>; state=9 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_via.c:2681]: parse_via(): parsing via: next via 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> =
<z9hG4bK08efd17b>; state=16 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=1475~853040b9-3e40-4c54-a456-6aead5ad927d-42986430 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [104];
uri=[sip:3030911@<Domain A>:5061] 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:3030911@<DOMAIN
A>:5061>] 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <102>
<INVITE> 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/receive.c:205]: receive_msg(): --- received sip message - reply - call-id:
[3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071] - cseq: [102 INVITE] 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=308 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0xb728901c) id=11298 global id=11297 T start=0xffffffff 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 8796 label 0 branch 1 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0xb728901c) matched an active transaction (T=0xb4dfcbe8)! 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_hooks.c:258]:
run_trans_callbacks_internal(): DBG: trans=0xb4dfcbe8, callback type 2, id 0 entered 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: acc [acc_logic.c:671]:
tmcb_func(): acc callback called for t(0xb4dfcbe8) event type 2, reply code 200 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_hooks.c:258]:
run_trans_callbacks_internal(): DBG: trans=0xb4dfcbe8, callback type 2, id 0 entered 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:704]:
dlg_lookup(): ref dlg 0xb4d848bc with 1 -> 2 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:706]:
dlg_lookup(): dialog id=1738 found on entry 910 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_profile.c:536]:
set_current_dialog(): setting current dialog [910:1738] 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:936]:
dlg_unref_helper(): unref op on 0xb4d848bc with 1 from dlg_hash.c:954 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:940]:
dlg_unref_helper(): unref dlg 0xb4d848bc with 1 -> 1 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0xb728901c) id=11298 global id=11298 T end=0xb4dfcbe8 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=180, uac[1]=180 local=0 is_invite=1) 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: <script>: incoming reply

Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=200

Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=1, save=0, relay=1 icode=0 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_hooks.c:258]:
run_trans_callbacks_internal(): DBG: trans=0xb4dfcbe8, callback type 32, id 0 entered 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:704]:
dlg_lookup(): ref dlg 0xb4d848bc with 1 -> 2 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:706]:
dlg_lookup(): dialog id=1738 found on entry 910 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:936]:
dlg_unref_helper(): unref op on 0xb4d848bc with 1 from dlg_hash.c:954 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:940]:
dlg_unref_helper(): unref dlg 0xb4d848bc with 1 -> 1 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: <core>
[core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size: 1614, new size:
1504 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: <core>
[core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size: orig:131, new:
21, rest: 1483 msg= SIP/2.0 200 OK^M Via: SIP/2.0/TLS
10.6.150.163:5071;branch=z9hG4bK08efd17b^M From: "Personal/Zimmer 4322"
<sip:4322@10.6.150.163:5071>;tag=as3df2635b^M To: <sip:3030911@<Domain
A>:5061>;tag=1475~853040b9-3e40-4c54-a456-6aead5ad927d-42986430^M Date: Thu, 08 Nov
2018 13:59:40 GMT^M Call-ID: 3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071^M CSeq:
102 INVITE^M Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER,
SUBSCRIBE, NOTIFY^M Allow-Events: presence, kpml^M Record-Route:
<sip:10.6.150.163:5061;transport=tls;lr;did=e83.ac6>^M Supported: replaces^M Server:
Cisco-CUCM11.5^M Call-Info: <urn:x-cisco-remotecc:callinfo>; security= Unknown; gci=
2-3013; isVoip^M Call-Info:
<urn:x-cisco-remotecc:callinfo>;x-cisco-video-traffic-class=DESKTOP^M Suppo
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_reply.c:331]:
update_totag_set(): new totag  
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: tm [t_hooks.c:258]:
run_trans_callbacks_internal(): DBG: trans=0xb4dfcbe8, callback type 1048576, id 0 entered

Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:704]:
dlg_lookup(): ref dlg 0xb4d848bc with 1 -> 2 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:706]:
dlg_lookup(): dialog id=1738 found on entry 910 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_hash.c:1137]:
next_state_dlg(): dialog 0xb4d848bc changed from state 2 to state 3, due event 3 (ref 2) 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: dialog [dlg_handlers.c:478]:
dlg_onreply(): dialog 0xb4d848bc confirmed (ACK pending) 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: <core>
[core/parser/parse_rr.c:381]: print_rr_body(): current rr is
<sip:10.6.150.163:5061;transport=tls;lr;did=e83.ac6> 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: <core>
[core/parser/parse_rr.c:406]: print_rr_body(): skipping 0 route records 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: <core>
[core/parser/parse_rr.c:444]: print_rr_body(): out rr
[<sip:10.6.150.163:5061;transport=tls;lr;did=e83.ac6>] 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE
3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071} DEBUG: <core>
[core/parser/parse_rr.c:445]: print_rr_body(): we have 1 records 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8620]: DEBUG: <core>
[core/tcp_main.c:3281]: handle_tcp_child(): dead tcp child 6 (pid 8618, no 22) (shutting
down?) 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8620]: DEBUG: <core>
[core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x843ca20, 42, -1, 0x0) fd_no=36
called 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8620]: CRITICAL: <core>
[core/pass_fd.c:277]: receive_fd(): EOF on 39 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8620]: DEBUG: <core>
[core/tcp_main.c:3513]: handle_ser_child(): dead child 22, pid 8618 (shutting down?) 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8620]: DEBUG: <core>
[core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x843ca20, 39, -1, 0x0) fd_no=35
called 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: ALERT: <core> [main.c:746]:
handle_sigs(): child process 8618 exited by a signal 11 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: ALERT: <core> [main.c:749]:
handle_sigs(): core was generated 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: INFO: <core> [main.c:771]:
handle_sigs(): terminating due to SIGCHLD 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: <core> [main.c:773]:
handle_sigs(): terminating due to SIGCHLD 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8620]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8619]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8616]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8608]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8613]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8615]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8610]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8609]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8614]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8605]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8604]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8612]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8607]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8597]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8603]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8611]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8602]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8601]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8599]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8617]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8606]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8598]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8600]: INFO: <core> [main.c:826]:
sig_usr(): signal 15 received 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: dialog [dlg_hash.c:338]:
destroy_dlg(): destroying dialog 0xb4d848bc (ref 2) 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: dialog [dlg_hash.c:354]:
destroy_dlg(): removed timer for dlg 0xb4d848bc [910:1738] with clid
'3330f000756ae87e5a59eff0349f4e3b@10.6.150.163:5071' and tags 'as3df2635b'
'' 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: <core> [db_pool.c:100]:
pool_remove(): removing connection from the pool 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [t_funcs.c:85]: tm_shutdown():
start 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [t_funcs.c:88]: tm_shutdown():
emptying hash table 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [h_table.c:129]:
free_cell_helper(): freeing transaction 0xb4dfcbe8 from h_table.c:448 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: dialog [dlg_handlers.c:304]:
dlg_iuid_sfree(): freeing dlg iuid [910:1738] (0xb4ceaba4) 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [h_table.c:204]:
free_cell_helper(): branch 0 -> dns_h.srv (_sips._tcp.<Domain B>) ref=3, dns_h.a
(<Domain B>) ref=2 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [h_table.c:204]:
free_cell_helper(): branch 1 -> dns_h.srv (_sips._tcp.<Domain B>) ref=2, dns_h.a
(<Domain B>) ref=2 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [t_funcs.c:90]: tm_shutdown():
removing semaphores 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [t_funcs.c:92]: tm_shutdown():
destroying tmcb lists 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tm [t_funcs.c:95]: tm_shutdown():
done 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: INFO: db_sqlite [db_sqlite.c:227]:
sqlite_mod_destroy(): SQlite terminate 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: tls [tls_init.c:853]:
destroy_tls_h(): tls module final tls destroy 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: INFO: <core>
[core/sctp_core.c:53]: sctp_core_destroy(): SCTP API not initialized 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: <core>
[core/mem/shm.c:261]: shm_destroy_manager(): destroying memory manager: q_malloc 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: <core>
[core/mem/q_malloc.c:1165]: qm_shm_lock_destroy(): destroying the shared memory lock 
Nov  8 15:06:45 ttel-gw /usr/sbin/kamailio[8591]: DEBUG: <core> [core/mem/pkg.c:91]:
pkg_destroy_manager(): destroying memory manager: q_malloc 
```

### Additional Information

```
version: kamailio 5.1.2 (i386/linux) 
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST,
DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC,
DBG_SR_MEMORY, 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 on 01:09:03 Sep  6 2018 with i586-akira_i586v2-linux-gnu-gcc 4.4.7
```

* **Operating System**:

We are using a home brew linux.

```
uname -a
Linux <hostname> 4.9.129 #1 SMP Tue Oct 2 04:17:37 UTC 2018 i686 GNU/Linux
```

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1717

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

[sr-dev] [kamailio/kamailio] Suddenly found kamailio dead (#1717)