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