[sr-dev] [kamailio/kamailio] Suddenly found kamailio dead (#1717)
Mathias Schneuwly
notifications at github.com
Fri Nov 9 08:14:30 CET 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.6.150.163:5071} DEBUG: <script>: incoming reply
Nov 8 15:06:45 ttel-gw /usr/sbin/kamailio[8618]: {2 102 INVITE 3330f000756ae87e5a59eff0349f4e3b at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20181108/c439f305/attachment-0001.html>
More information about the sr-dev
mailing list