i have been wondering why my proxy is not forwarding 180 ringing reply to caller that it receives from callee. invite was forwarded to callee by t_relay(). proxy does not print any error messages to syslog. the only thing i get is the message i have in onreply_route:
onreply_route [REPLY] { xlog("L_INFO", "Received reply\n"); return; }
level 3 debug of 180 reply processing is below. does it tell anything to tm gurus that would explain why kamailio does nothing to the reply?
180 reply itself looks like this:
Session Initiation Protocol Status-Line: SIP/2.0 180 Ringing Message Header Record-Route: sip:192.98.102.30;transport=tcp;r2=on;lr Record-Route: sip:192.98.102.30;r2=on;lr Via: SIP/2.0/TCP 192.98.102.30;branch=z9hG4bK84cf.498ea35cdde08fdfad989b 9212a2a9a5.0 Via: SIP/2.0/UDP 192.98.102.31:55419;branch=z9hG4bKd6e2f0db78e2df94;rpor t=55419 To: sip:test@test.tutpro.com;tag=8e143c1b780cfb1b From: sip:jh@test.tutpro.com;tag=630450233fa9bc92 Call-ID: d0b328ba01bcc483 CSeq: 22643 INVITE Server: baresip v0.4.6 (i586/linux) Contact: sip:0x94fa6e8@192.98.102.30:49240;transport=tcp Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,REFER,NOTIFY,SUBSCRIBE,INFO Content-Length: 0
-- juha
Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [tcp_read.c:1510]: handle_io(): received n=4 con=0xb4252638, fd=15 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [tcp_read.c:1317]: tcp_read_req(): tcp_read_req: content-length= 0 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:633]: parse_msg(): SIP Reply (status): Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:635]: parse_msg(): version: <SIP/2.0> Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:637]: parse_msg(): status: <180> Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:639]: parse_msg(): reason: <Ringing> Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK84cf.498ea35cdde08fdfad989b9212a2a9a5.0>; state=16 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [receive.c:151]: receive_msg(): After parse_msg... Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: tm [t_lookup.c:1071]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=4 T start=0xffffffff Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKd6e2f0db78e2df94>; state=6 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 235, <rport> = <55419>; state=16 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=62 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:526]: parse_headers(): parse_headers: this is the second via Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=8e143c1b780cfb1b Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/parse_addr_spec.c:885]: parse_addr_spec(): end of header reached, state=29 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [49]; uri=[sip:test@test.tutpro.com] Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [sip:test@test.tutpro.com] Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <22643> <INVITE> Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: tm [t_lookup.c:949]: t_reply_matching(): DEBUG: t_reply_matching: hash 64584 label 0 branch 0 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: tm [t_lookup.c:1003]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0xb4256d88)! Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0xb4256d88, callback type 2, id 0 entered Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: acc [acc_logic.c:538]: tmcb_func(): acc callback called for t(0xb4256d88) event type 2, reply code 180 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: tm [t_lookup.c:1140]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=5 T end=0xb4256d88 Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: tm [t_reply.c:2258]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=1) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: INFO: Received reply Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil) Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [receive.c:295]: receive_msg(): receive_msg: cleaning up Oct 23 17:40:51 rautu /usr/sbin/sip-proxy[8730]: DEBUG: <core> [io_wait.h:390]: io_watch_add(): DBG: io_watch_add(0x82ca540, 15, 2, 0xb4252638), fd_no=1