### Description Hi We have a situation where Kamailio crashes always just after receiving a SIP ACK. We are using the following setup: phoneA(192.168.147.100) -(TLS)- (192.168.147.1)KamailioA(192.168.1.1) -(TLS)- (192.168.1.2)KamailioB(192.168.148.1) -(TLS)- (192.168.148.100)phoneB
If I do a call from phoneA to phoneB, the Invite is sent correctly to phoneB. phoneB sends back the ACK and then KamailioA immediately crashes.
KamailioA is listening on interface 192.168.147.1 KamailioB is listening on interface 192.168.148.1
Both Kamailios are running on version 5.2.2
I can see a strange warning in the log of KamailioA which says: `<core> [core/tcp_main.c:1148]: tcp_do_connect(): 192.168.148.1:5071: could not find corresponding listening socket for 192.168.1.1, using default...` I'm not sure if this is related to this problem. Interestingly Kamailio does not listen on interface 192.168.1.1, so why does it use this socket? If I'm using plain SIP, then it uses the specified bind interface 192.168.147.1, but not if TLS is used.
**If I turn the TLS connection between the two Kamailios to plain, then everything works fine. Kamailio used the defined socket, and it does not crash.**
### Troubleshooting
#### Reproduction The crash happens always using the scenario described above.
#### Debugging Data
<!-- If you got a core dump, use gdb to extract troubleshooting data - full backtrace, local variables and the list of the code at the issue location.
gdb /path/to/kamailio /path/to/corefile bt full info locals list
If you are familiar with gdb, feel free to attach more of what you consider to be relevant. -->
``` (gdb) bt full #0 0xb6bce4c6 in populate_leg_info (dlg=0xb4c37018, msg=0xb72fdf40, t=0xb4c352d4, leg=1, tag=0xbfd065ac) at dlg_handlers.c:257 __llevel = 3 skip_recs = 1 cseq = {s = 0x0, len = 0} contact = { s = 0xb4c226e3 "sip:2011000@192.168.148.100:5071;transport=tls>\r\nServer: Cisco-CP-8841-3PCC/11.2.3\r\nContent-Length: 295\r\nAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, UPDATE\r\nSupported: replaces, sec"..., len = 46} rr_set = { s = 0xb72aee9c "sip:192.168.148.1:5071;transport=tls;lr;ftag=c01877e49ac3d2e1o0;did=91e.6b8ac3d2e1o0;did=91e.6da>\r\nContact: "CP8841" sip:2011000@192.168.148.100:5071;tra\300\300\300\300\355\357\315\253ls\r\nSer\234", len = 77} __FUNCTION__ = "populate_leg_info" #1 0xb6bd0fb4 in dlg_onreply (t=0xb4c352d4, type=1048576, param=0xbfd066e8) at dlg_handlers.c:503 dlg = 0xb4c37018 iuid = 0xb4c378cc new_state = 3 old_state = 2 unref = 0 event = 3 tag = { s = 0xb4c224ce "2835feb24ee85510i0\r\nFrom: "CP8861" sip:1011000@192.168.147.1;tag=c01877e49ac3d2e1o0\r\nCall-ID: 12d45870-96108bc9@192.168.147.100\r\nCSeq: 101 INVITE\r\nVia: SIP/2.0/TLS 192.168.147.1:5071;received=192.16"..., len = 18} req = 0xb4c342a0 rpl = 0xb72fdf40 __FUNCTION__ = "dlg_onreply" #2 0xb6fbf850 in run_trans_callbacks_internal (cb_lst=0xb4c35318, type=1048576, trans=0xb4c352d4, params=0xbfd066e8) at t_hooks.c:260 cbp = 0xb4c3cb08 backup_from = 0x84c5e90 backup_to = 0x84c5e94 backup_dom_from = 0x84c5e98 backup_dom_to = 0x84c5e9c backup_uri_from = 0x84c5e88 backup_uri_to = 0x84c5e8c backup_xavps = 0x84c5f1c __FUNCTION__ = "run_trans_callbacks_internal" #3 0xb6fbfa43 in run_trans_callbacks_with_buf (type=1048576, rbuf=0xb4c3534c, req=0xb4c342a0, repl=0xb72fdf40, flags=0) at t_hooks.c:305 params = {req = 0xb4c342a0, rpl = 0xb72fdf40, param = 0xb4c3cb14, code = 200, flags = 0, branch = 0, t_rbuf = 0xb4c3534c, dst = 0xb4c35380, send_buf = { s = 0xb4c393c4 "SIP/2.0 200 OK\r\nTo: "2011000" sip:2011000@192.168.147.1;tag=2835feb24ee85510i0\r\nFrom: "CP8861" sip:1011000@192.168.147.1;tag=c01877e49ac3d2e1o0\r\nCall-ID: 12d45870-96108bc9@192.168.147.100\r\nCSeq: 1"..., len = 1015}} trans = 0xb4c352d4 #4 0xb7005b22 in relay_reply (t=0xb4c352d4, p_msg=0xb72fdf40, branch=0, msg_status=200, cancel_data=0xbfd06c64, do_put_on_wait=1) at t_reply.c:1986 relay = 0 save_clone = 0 buf = 0xb72ea5b4 "SIP/2.0 200 OK\r\nTo: "2011000" sip:2011000@192.168.147.1;tag=2835feb24ee85510i0\r\nFrom: "CP8861" sip:1011000@192.168.147.1;tag=c01877e49ac3d2e1o0\r\nCall-ID: 12d45870-96108bc9@192.168.147.100\r\nCSeq: 1"... res_len = 1015 relayed_code = 200 relayed_msg = 0xb72fdf40 reply_bak = 0xb6fefd71 bm = {to_tag_val = {s = 0x8d5e370 "CEST", len = -1221923564}} totag_retr = 0 reply_status = RPS_COMPLETED uas_rb = 0xb4c3534c to_tag = 0xb7085b6c reason = {s = 0x1 <Address 0x1 out of bounds>, len = 7200} onsend_params = {req = 0x0, rpl = 0x25, param = 0x36, code = 1, flags = 7, branch = 0, t_rbuf = 0xb7085b6c, dst = 0xbfd06988, send_buf = { s = 0x828077e "\213E\334\203\304l[^_]\303U\211\345WVS\203\354l\241\064]K\b\205\300t\020\241\060]K\b\307", len = -1266092160}} ip = {af = 1, len = 0, u = {addrl = {0, 0, 0, 0}, addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, addr = '\000' <repeats 15 times>}} __FUNCTION__ = "relay_reply" #5 0xb700a5a2 in reply_received (p_msg=0xb72fdf40) at t_reply.c:2558 msg_status = 200 last_uac_status = 180 ---Type <return> to continue, or q <return> to quit--- ack = 0x0 ack_len = 0 branch = 0 reply_status = 0 onreply_route = 1 cancel_data = {cancel_bitmap = 0, reason = {cause = 200, u = {text = {s = 0x0, len = 0}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 0}}}} uac = 0xb4c35440 t = 0xb4c352d4 lack_dst = {send_sock = 0x1, to = {s = {sa_family = 0, sa_data = "\000\000x\250\354\b\000\000\000\000\000\000\000"}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 149727352}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 149727352, sin6_addr = {__in6_u = { __u6_addr8 = "\000\000\000\000\000\000\000\000\377\377\377\377\b\000\000", __u6_addr16 = {0, 0, 0, 0, 65535, 65535, 8, 0}, __u6_addr32 = {0, 0, 4294967295, 8}}}, sin6_scope_id = 3077709910}}, id = 149859988, proto = 0 '\000', send_flags = {f = 0, blst_imask = 0}} backup_user_from = 0x84c5e90 backup_user_to = 0x84c5e94 backup_domain_from = 0x84c5e98 backup_domain_to = 0x84c5e9c backup_uri_from = 0x84c5e88 backup_uri_to = 0x84c5e8c backup_xavps = 0x84c5f1c replies_locked = 1 branch_ret = 119 prev_branch = -1717986917 blst_503_timeout = 822083589 hf = 0x1 onsend_params = {req = 0xb72d7f80, rpl = 0xbfd06d58, param = 0xbfd06d54, code = -1217257384, flags = 14254, branch = 46962, t_rbuf = 0x8d5e370, dst = 0x2, send_buf = { s = 0xb7635c91 "[\201\303c\363\020", len = 0}} ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {-1224189076, 7, 138001188, -1076860760, 728924134, -1680286071}, __mask_was_saved = 0, __saved_mask = {__val = {0, 4294967295, 8, 539106558, 0, 4294967295, 4294967295, 138775360, 49, 4294967295, 4294967295, 3073043760, 3032623058, 3032623058, 3032623355, 0, 0, 137132517, 926089367, 3, 3218107556, 3, 3218107538, 3077138491, 149859986, 3218107538, 3069139848, 138001188, 138129710, 3218107816, 3068640855, 3073367872}}}}} bctx = 0x0 keng = 0x0 __FUNCTION__ = "reply_received" #6 0x080f0c70 in do_forward_reply (msg=0xb72fdf40, mode=0) at core/forward.c:747 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 = 31 r = 0 ip = {af = 3342336, len = 3070983510, u = {addrl = {3071029744, 138001188, 3218108100, 3070983858}, addr32 = {3071029744, 138001188, 3218108100, 3070983858}, addr16 = {12784, 46860, 47908, 2105, 28356, 49104, 32434, 46859}, addr = "\360\061\f\267$\273\071\b\304n\320\277\262~\v\267"}} s = 0x40000004 <Address 0x40000004 out of bounds> len = 0 __FUNCTION__ = "do_forward_reply" #7 0x080f27a5 in forward_reply (msg=0xb72fdf40) at core/forward.c:852 No locals. #8 0x0817dd75 in receive_msg ( buf=0xb4c22490 "SIP/2.0 200 OK\r\nTo: "2011000" sip:2011000@192.168.147.1;tag=2835feb24ee85510i0\r\nFrom: "CP8861" sip:1011000@192.168.147.1;tag=c01877e49ac3d2e1o0\r\nCall-ID: 12d45870-96108bc9@192.168.147.100\r\nCSeq: 1"..., len=1131, rcv_info=0xb4c222cc) at core/receive.c:433 msg = 0xb72fdf40 ctx = {rec_lev = 149727352, run_flags = 0, last_retcode = 21, jmp_env = {{__jmpbuf = {1, 0, 0, -1, 8, -1217257386}, __mask_was_saved = 149859988, __saved_mask = {__val = {3032621868, 15252, 1160, 16383, 1131, 3032718380, 3032730124, 0, 4294967295, 3064727794, 10, 3032622387, 33, 926137124, 3077853172, 3218109060, 149859980, 3218108712, 3077134290, 3077709903, 3077000373, 3218108739, 3077850112, 0, 2576980379, 822083589, 0, 3077853172, 3077373168, 0, 0, 0}}}}} bctx = 0x0 ret = 0 stats_on = 0 tvb = {tv_sec = 1565164477, tv_usec = 894759} tve = {tv_sec = 0, tv_usec = -1076858112} tz = {tz_minuteswest = 0, tz_dsttime = 0} diff = 0 inb = { ---Type <return> to continue, or q <return> to quit--- s = 0xb4c22490 "SIP/2.0 200 OK\r\nTo: "2011000" sip:2011000@192.168.147.1;tag=2835feb24ee85510i0\r\nFrom: "CP8861" sip:1011000@192.168.147.1;tag=c01877e49ac3d2e1o0\r\nCall-ID: 12d45870-96108bc9@192.168.147.100\r\nCSeq: 1"..., len = 1131} netinfo = {data = {s = 0x9108 <Address 0x9108 out of bounds>, len = 149860088}, rcv = 0xb7744ff4, dst = 0xb7746380} keng = 0x0 evp = {data = 0xbfd07140, rcv = 0xb4c222cc, dst = 0x0} cidlockidx = 0 cidlockset = 0 errsipmsg = 0 __FUNCTION__ = "receive_msg" #9 0x08273e49 in receive_tcp_msg ( tcpbuf=0xb4c22490 "SIP/2.0 200 OK\r\nTo: "2011000" sip:2011000@192.168.147.1;tag=2835feb24ee85510i0\r\nFrom: "CP8861" sip:1011000@192.168.147.1;tag=c01877e49ac3d2e1o0\r\nCall-ID: 12d45870-96108bc9@192.168.147.100\r\nCSeq: 1"..., len=1131, rcv_info=0xb4c222cc, con=0xb4c222b8) at core/tcp_read.c:1399 buf = 0x0 bsize = 0 blen = 295 __FUNCTION__ = "receive_tcp_msg" #10 0x08276179 in tcp_read_req (con=0xb4c222b8, bytes_read=0xbfd07964, read_flags=0xbfd0795c) at core/tcp_read.c:1631 bytes = 1131 total_bytes = 1131 resp = 1 size = 0 req = 0xb4c2232c dst = {send_sock = 0x7, to = {s = {sa_family = 8193, sa_data = "\000\000\214\361.\267\332\000\000\000\214\361.\267"}, sin = {sin_family = 8193, sin_port = 0, sin_addr = {s_addr = 3073307020}, sin_zero = "\332\000\000\000\214\361.\267"}, sin6 = {sin6_family = 8193, sin6_port = 0, sin6_flowinfo = 3073307020, sin6_addr = {__in6_u = { __u6_addr8 = "\332\000\000\000\214\361.\267 \034\000\000\000\000\000", __u6_addr16 = {218, 0, 61836, 46894, 7200, 0, 0, 0}, __u6_addr32 = {218, 3073307020, 7200, 0}}}, sin6_scope_id = 4294967295}}, id = 0, proto = 4 '\004', send_flags = {f = 0, blst_imask = 0}} c = -13 '\363' ret = 0 __FUNCTION__ = "tcp_read_req" #11 0x08279b62 in handle_io (fm=0xb72ef18c, events=1, idx=-1) at core/tcp_read.c:1862 ret = 0 n = 0 read_flags = 1 con = 0xb4c222b8 s = 13 resp = 1 t = 484016151 __FUNCTION__ = "handle_io" #12 0x08267d1f in io_wait_loop_epoll (h=0x8493aa0, t=2, repeat=0) at core/io_wait.h:1065 n = 1 r = 0 fm = 0xb72ef18c revents = 1 __FUNCTION__ = "io_wait_loop_epoll" #13 0x0827ae67 in tcp_receive_loop (unix_sock=34) at core/tcp_read.c:1974 __FUNCTION__ = "tcp_receive_loop" #14 0x0825e55e in tcp_init_children () at core/tcp_main.c:4853 r = 1 i = 7 reader_fd_1 = 34 pid = 0 si_desc = "tcp receiver (generic)\000\000\000\000\000\000\227c)\267\031\000\000\000\310|\320\277\252\067(\b\377\377\377\377\251\221?\b\001\000\000\000\360\061(\b\000\000\000\000\001\000\000\000\000\000\000\000\237)9\b\317\000\000\000\244\037\071\b\250|\320\277\035W5\b\b\366\210\264\000\000\000\000\003\000\000\000\031\000\000\000\030\000\000\000\031\000\000\000\000\064\000\000\031\000\000\000\037\273\071\b" si = 0x0 __FUNCTION__ = "tcp_init_children" #15 0x0806899f in main_loop () at main.c:1745 i = 8 pid = 13312 si = 0x0 si_desc = "udp receiver child=7 sock=192.168.147.1:5070", '\000' <repeats 28 times>, "\003", '\000' <repeats 54 times> nrprocs = 8 ---Type <return> to continue, or q <return> to quit--- woneinit = 1 __FUNCTION__ = "main_loop" #16 0x0806f474 in main (argc=13, argv=0xbfd083f4) at main.c:2696 cfg_stream = 0x8d58008 c = -1 r = 0 tmp = 0xbfd0894d "" tmp_len = 0 port = 0 proto = 5 options = 0x8385f70 ":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 = 734287085 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0xb778b848 p = 0xbfd08374 "\260\203\320\277G\244w\267H\270x\267(\234v\267\364Ot\267" st = {st_dev = 18, __pad1 = 0, st_ino = 14575, 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 = 1565162952, tv_nsec = 144000000}, st_mtim = {tv_sec = 1565164469, tv_nsec = 12000000}, st_ctim = {tv_sec = 1565164469, tv_nsec = 12000000}, __unused4 = 0, __unused5 = 0} __FUNCTION__ = "main" ``` ``` (gdb) info locals __llevel = 3 skip_recs = 1 cseq = {s = 0x0, len = 0} contact = { s = 0xb4c226e3 "sip:2011000@192.168.148.100:5071;transport=tls>\r\nServer: Cisco-CP-8841-3PCC/11.2.3\r\nContent-Length: 295\r\nAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, UPDATE\r\nSupported: replaces, sec"..., len = 46} rr_set = { s = 0xb72aee9c "sip:192.168.148.1:5071;transport=tls;lr;ftag=c01877e49ac3d2e1o0;did=91e.6b8ac3d2e1o0;did=91e.6da>\r\nContact: "CP8841" sip:2011000@192.168.148.100:5071;tra\300\300\300\300\355\357\315\253ls\r\nSer\234", len = 77} __FUNCTION__ = "populate_leg_info" ``` ``` (gdb) list 252 in dlg_handlers.c ```
#### Log Messages
<!-- Check the syslog file and if there are relevant log messages printed by Kamailio, add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
``` Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/tcp_read.c:1560]: tcp_read_req(): content-length=295 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply (status): Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg(): version: <SIP/2.0> Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg(): status: <200> Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg(): reason: <OK> Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=2835feb24ee85510i0 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [62]; uri=[sip:2011000@192.168.147.1] Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body ["2011000" sip:2011000@192.168.147.1], to tag [2835feb24ee85510i0] Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <101> <INVITE> Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <192.168.1.1>; state=6 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKdec2.d7353bd8ebe652818b71c61e08511e1e.0>; state=6 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 236, <i> = <1>; state=16 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - reply - call-id: [12d45870-96108bc9@192.168.147.100] - cseq: [101 INVITE] Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-81f1c844>; state=16 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=ffffffffffffffff Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=295 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_lookup.c:1043]: t_check_msg(): msg (0xb72fdf40) id=3/13319 global id=2/13319 T start=0xffffffff Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_lookup.c:920]: t_reply_matching(): t_reply_matching: hash 11501 label 0 branch 0 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_lookup.c:974]: t_reply_matching(): reply (0xb72fdf40) matched an active transaction (T=0xb4c352d4)! Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_hooks.c:258]: run_trans_callbacks_internal(): DBG: trans=0xb4c352d4, callback type 2, id 0 entered Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} acc [acc_logic.c:682]: tmcb_func(): acc callback called for t(0xb4c352d4) event type 2, reply code 200 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} acc [acc_logic.c:414]: should_acc_reply(): probing acc state - code: 200 flags: 0x2 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} acc [acc_logic.c:446]: should_acc_reply(): acc is on Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_hooks.c:258]: run_trans_callbacks_internal(): DBG: trans=0xb4c352d4, callback type 2, id 0 entered Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4c37018 with 1 -> 2 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=2774 found on entry 3609 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3609:2774] Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4c37018 with 1 from dlg_hash.c:975 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4c37018 with 1 -> 1 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_lookup.c:1113]: t_check_msg(): msg (0xb72fdf40) id=3/13319 global id=3/13319 T end=0xb4c352d4 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_reply.c:2243]: reply_received(): transaction found - T:0xb4c352d4 branch:0 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_reply.c:2258]: reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1) Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <script>: incoming reply Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_reply.c:1266]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=200 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_reply.c:1518]: t_should_relay_response(): rps completed - uas status: 180 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_reply.c:1824]: relay_reply(): reply status=4 branch=0, save=0, relay=0 icode=0 msg status=200 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_hooks.c:258]: run_trans_callbacks_internal(): DBG: trans=0xb4c352d4, callback type 32, id 0 entered Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4c37018 with 1 -> 2 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=2774 found on entry 3609 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4c37018 with 1 from dlg_hash.c:975 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4c37018 with 1 -> 1 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <core> [core/msg_translator.c:2288]: generate_res_buf_from_sip_res(): old size: 1131, new size: 1015 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <core> [core/msg_translator.c:2306]: generate_res_buf_from_sip_res(): copied size: orig:327, new: 211, rest: 804 msg= SIP/2.0 200 OK^M To: "2011000" sip:2011000@192.168.147.1;tag=2835feb24ee85510i0^M From: "CP8861" sip:1011000@192.168.147.1;tag=c01877e49ac3d2e1o0^M Call-ID: 12d45870-96108bc9@192.168.147.100^M CSeq: 101 INVITE^M Via: SIP/2.0/TLS 192.168.147.100:5062;branch=z9hG4bK-81f1c844^M Record-Route: sip:192.168.148.1:5071;transport=tls;lr;ftag=c01877e49ac3d2e1o0;did=91e.6b8^M Record-Route: sip:192.168.147.1:5071;transport=tls;lr;ftag=c01877e49ac3d2e1o0;did=91e.6da^M Contact: "CP8841" sip:2011000@192.168.148.100:5071;transport=tls^M Server: Cisco-CP-8841-3PCC/11.2.3^M Content-Length: 295^M Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, UPDATE^M Supported: replaces, sec-agree^M Content-Type: application/sdp^M ^M v=0^M o=- 90523 90523 IN IP4 192.168.148.100^M s=-^M c=IN IP4 192.168 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_reply.c:332]: update_totag_set(): new totag [2835feb24ee85510i0] Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} tm [t_hooks.c:258]: run_trans_callbacks_internal(): DBG: trans=0xb4c352d4, callback type 1048576, id 0 entered Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4c37018 with 1 -> 2 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=2774 found on entry 3609 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_hash.c:1158]: next_state_dlg(): dialog 0xb4c37018 changed from state 2 to state 3, due event 3 (ref 2) Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} dialog [dlg_handlers.c:484]: dlg_onreply(): dialog 0xb4c37018 confirmed (ACK pending) Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <core> [core/parser/parse_rr.c:381]: print_rr_body(): current rr is sip:192.168.148.1:5071;transport=tls;lr;ftag=c01877e49ac3d2e1o0;did=91e.6b8 Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <core> [core/parser/parse_rr.c:381]: print_rr_body(): current rr is sip:192.168.147.1:5071;transport=tls;lr;ftag=c01877e49ac3d2e1o0;did=91e.6da Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <core> [core/parser/parse_rr.c:406]: print_rr_body(): skipping 1 route records Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <core> [core/parser/parse_rr.c:444]: print_rr_body(): out rr [sip:192.168.148.1:5071;transport=tls;lr;ftag=c01877e49ac3d2e1o0;did=91e.6b8] Aug 7 09:54:37 bs3-1 /usr/sbin/kamailio[13319]: DEBUG: {2 101 INVITE 12d45870-96108bc9@192.168.147.100} <core> [core/parser/parse_rr.c:445]: print_rr_body(): we have 1 records Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13326]: DEBUG: <core> [core/tcp_main.c:3281]: handle_tcp_child(): dead tcp child 1 (pid 13319, no 17) (shutting down?) Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13326]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x8471820, 33, -1, 0x0) fd_no=32 called Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13326]: CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 30 Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13326]: DEBUG: <core> [core/tcp_main.c:3513]: handle_ser_child(): dead child 17, pid 13319 (shutting down?) Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13326]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x8471820, 30, -1, 0x0) fd_no=31 called Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: ALERT: <core> [main.c:756]: handle_sigs(): child process 13319 exited by a signal 11 Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: ALERT: <core> [main.c:759]: handle_sigs(): core was generated Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: INFO: <core> [main.c:781]: handle_sigs(): terminating due to SIGCHLD Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: <core> [main.c:783]: handle_sigs(): terminating due to SIGCHLD Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13323]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13321]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13320]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13318]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13317]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13315]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13306]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13304]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13303]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13316]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13314]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13310]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13309]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13308]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13307]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13305]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13325]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13322]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13326]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13324]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13313]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13311]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13312]: INFO: <core> [main.c:836]: sig_usr(): signal 15 received Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: dialog [dlg_hash.c:345]: destroy_dlg(): destroying dialog 0xb4c37018 (ref 2) Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: dialog [dlg_hash.c:361]: destroy_dlg(): removed timer for dlg 0xb4c37018 [3609:2774] with clid '12d45870-96108bc9@192.168.147.100' and tags 'c01877e49ac3d2e1o0' '' Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: db_sqlite [dbase.c:223]: db_sqlite_submit_query(): submit_query: insert into location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,socket,methods,last_modified,ruid,reg_id,server_id,connection_id,keepalive,partition ) values (?1,?2,?3,?4,?5,?6,?7,?8,?9,?10,?11,?12,?13,?14,?15,?16,?17,?18) Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: <core> [db_pool.c:100]: pool_remove(): removing connection from the pool Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tm [t_funcs.c:85]: tm_shutdown(): start Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tm [t_funcs.c:88]: tm_shutdown(): emptying hash table Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tm [h_table.c:133]: free_cell_helper(): freeing transaction 0xb4c352d4 from h_table.c:465 Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: dialog [dlg_handlers.c:310]: dlg_iuid_sfree(): freeing dlg iuid [3609:2774] (0xb4c378cc) Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tm [h_table.c:222]: free_cell_helper(): branch 0 -> dns_h.srv (_sips._tcp.b.ersaimfs.ch) ref=2, dns_h.a (ttel.b.ersaimfs.ch) ref=2 Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tm [t_funcs.c:90]: tm_shutdown(): removing semaphores Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tm [t_funcs.c:92]: tm_shutdown(): destroying tmcb lists Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tm [t_funcs.c:95]: tm_shutdown(): done Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: INFO: db_sqlite [db_sqlite.c:227]: mod_destroy(): SQlite terminate Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: tls [tls_init.c:853]: destroy_tls_h(): tls module final tls destroy Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: INFO: <core> [core/sctp_core.c:53]: sctp_core_destroy(): SCTP API not initialized Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: <core> [core/mem/shm.c:283]: shm_destroy_manager(): destroying memory manager: q_malloc Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: <core> [core/mem/q_malloc.c:1178]: qm_shm_lock_destroy(): destroying the shared memory lock Aug 7 09:54:38 bs3-1 /usr/sbin/kamailio[13297]: DEBUG: <core> [core/mem/pkg.c:91]: pkg_destroy_manager(): destroying memory manager: q_malloc ```
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
``` kamailio -v version: kamailio 5.2.2 (i386/linux) 67f967 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, 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_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 67f967 compiled on 23:45:38 Jul 27 2019 with i586-akira_i586v2-linux-gnu-gcc 4.4.7 ```
* **Operating System**:
<!-- Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...; Kernel details (output of `uname -a`) --> This is an own Linux distribution. So nothing common... ``` uname -a Linux bs3-1 4.9.155 #1 SMP Sat Jul 27 16:32:51 UTC 2019 i686 GNU/Linux ```