<h3>Description</h3>
<p>Hi<br>
We have a situation where Kamailio crashes always just after receiving a SIP ACK. We are using the following setup:<br>
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</p>
<p>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.</p>
<p>KamailioA is listening on interface 192.168.147.1<br>
KamailioB is listening on interface 192.168.148.1</p>
<p>Both Kamailios are running on version 5.2.2</p>
<p>I can see a strange warning in the log of KamailioA which says:<br>
<code><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...</code><br>
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.</p>
<p><strong>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.</strong></p>
<h3>Troubleshooting</h3>
<h4>Reproduction</h4>
<p>The crash happens always using the scenario described above.</p>
<h4>Debugging Data</h4>
<pre><code>(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.6b8>ac3d2e1o0;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"
</code></pre>
<pre><code>(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.6b8>ac3d2e1o0;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"
</code></pre>
<pre><code>(gdb) list
252 in dlg_handlers.c
</code></pre>
<h4>Log Messages</h4>
<pre><code>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
</code></pre>
<h3>Additional Information</h3>
<ul>
<li><strong>Kamailio Version</strong> - output of <code>kamailio -v</code></li>
</ul>
<pre><code>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
</code></pre>
<ul>
<li><strong>Operating System</strong>:</li>
</ul>
<p>This is an own Linux distribution. So nothing common...</p>
<pre><code>uname -a
Linux bs3-1 4.9.155 #1 SMP Sat Jul 27 16:32:51 UTC 2019 i686 GNU/Linux
</code></pre>
<p style="font-size:small;-webkit-text-size-adjust:none;color:#666;">—<br />You are receiving this because you are subscribed to this thread.<br />Reply to this email directly, <a href="https://github.com/kamailio/kamailio/issues/2028?email_source=notifications&email_token=ABO7UZJBCFAG3UVXBCO7FCTQDKBZFA5CNFSM4IJ5YDKKYY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4HD2MBXA">view it on GitHub</a>, or <a href="https://github.com/notifications/unsubscribe-auth/ABO7UZMLPCZNCD6ELLTNH6LQDKBZFANCNFSM4IJ5YDKA">mute the thread</a>.<img src="https://github.com/notifications/beacon/ABO7UZJV3QUUKTTIC2MAHILQDKBZFA5CNFSM4IJ5YDKKYY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4HD2MBXA.gif" height="1" width="1" alt="" /></p>
<script type="application/ld+json">[
{
"@context": "http://schema.org",
"@type": "EmailMessage",
"potentialAction": {
"@type": "ViewAction",
"target": "https://github.com/kamailio/kamailio/issues/2028?email_source=notifications\u0026email_token=ABO7UZJBCFAG3UVXBCO7FCTQDKBZFA5CNFSM4IJ5YDKKYY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4HD2MBXA",
"url": "https://github.com/kamailio/kamailio/issues/2028?email_source=notifications\u0026email_token=ABO7UZJBCFAG3UVXBCO7FCTQDKBZFA5CNFSM4IJ5YDKKYY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4HD2MBXA",
"name": "View Issue"
},
"description": "View this Issue on GitHub",
"publisher": {
"@type": "Organization",
"name": "GitHub",
"url": "https://github.com"
}
}
]</script>