*Hi,
I am experiencing a problem regarding CANCEL processing, I have the normal config file plus the following (I got that in a previous mail)
*
if (is_method("CANCEL")) { t_relay(); break; }
The problem is that openserver is relaying the CANCEL, but putting a completely new branch tag in the Via header, instead of the same branch than in the INVITE that is to be cancel. I have debug dump, that shows that the CANCEL message is matched with the INVITE, but it still put a new branch in the relayed cancel, and also in the 200 OK response.
If somebody could help me it would be great
0(5309) DEBUG: callid: '2ef6f3df-5309@10.161.14.110' 0(5309) DEBUG:init_mod_child: CHILD , rank=1, module=usrloc 0(5309) DEBUG:init_mod_child: CHILD , rank=1, module=xlog 0(5309) XLOG: init_child [1] pid [5309] 0(5309) SIP Request: 0(5309) method: <INVITE> 0(5309) uri: sip:user4@home2.jagarvayo.mot.dev 0(5309) version: <SIP/2.0> 0(5309) parse_headers: flags=2 0(5309) Found param type 232, <branch> = <z9hG4bK4f9932cde5bad6c36f103563aa96f449>; state=6 0(5309) Found param type 238, <xxxST_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK6f59072ad3fe644fcf851c16d3168bee>; state=6 0(5309) Found param type 238, <xxxIT_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK80752856b61f3aaf3f1d17e57067d067>; state=6 0(5309) Found param type 238, <xxxSO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK8b46a43071f3848c711cb4bcf4b42335>; state=6 0(5309) Found param type 238, <xxxPO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) end of header reached, state=5 0(5309) parse_headers: Via found, flags=2 0(5309) parse_headers: this is the first via 0(5309) After parse_msg... 0(5309) preparing to run routing scripts... 0(5309) parse_headers: flags=100 0(5309) DEBUG:parse_to:end of header reached, state=9 0(5309) DEBUG: get_hdr_field: <To> [37]; uri=[ sip:user4@home2.jagarvayo.mot.dev] 0(5309) DEBUG: to body [sip:user4@home2.jagarvayo.mot.dev
] 0(5309) get_hdr_field: cseq <CSeq>: <1> <INVITE> 0(5309) DEBUG: get_hdr_body : content_length=95 0(5309) DEBUG:maxfwd:is_maxfwd_present: value = 66 0(5309) DEBUG: add_param: tag=6661 0(5309) DEBUG:parse_to:end of header reached, state=29 0(5309) xl_printf: final buffer length 112 0(5309) INVITE: 10.161.14.59:5060 ci=1-26284@10.161.14.105 ft=6661 tt=<null> cseq=1 sip:user4@home2.jagarvayo.mot.dev: 0(5309) parse_headers: flags=200 0(5309) is_preloaded: Yes 0(5309) grep_sock_info - checking if host==us: 13==13 && [10.161.14.110] == [10.161.14.110] 0(5309) grep_sock_info - checking if port 7000 matches port 7000 0(5309) after_loose: Topmost route URI: 'sip:10.161.14.110:7000' is me 0(5309) after_loose: URI to be processed: ' sip:csm002_c638dcee898a6df9b8a460a45e020ce4@10.161.14.59;lr' 0(5309) after_loose: Next URI is a loose router 0(5309) xl_printf: final buffer length 78 0(5309) Relying to Route: sip:csm002_c638dcee898a6df9b8a460a45e020ce4@10.161.14.59;lr 0(5309) parse_headers: flags=ffffffffffffffff 0(5309) found end of header 0(5309) DEBUG: t_newtran: msg id=1 , global msg id=0 , T on entrance=0xffffffff 0(5309) parse_headers: flags=ffffffffffffffff 0(5309) parse_headers: flags=78 0(5309) t_lookup_request: start searching: hash=61655, isACK=0 0(5309) DEBUG: RFC3261 transaction matching failed 0(5309) DEBUG: t_lookup_request: no transaction found 0(5309) parse_headers: flags=78 0(5309) DEBUG: MD5 calculated: cf43897e3c46f1bb8c4ab6702426d007 0(5309) DEBUG:tm:t_relay: new INVITE 0(5309) parse_headers: flags=ffffffffffffffff 0(5309) check_via_address(10.161.14.59, 10.161.14.59, 0) 0(5309) WARNING:vqm_resize: resize(0) called 0(5309) DEBUG:tm:_reply_light: reply sent out. buf=0x8137e38: SIP/2.0 1..., shmem=0x40357658: SIP/2.0 1 0(5309) DEBUG:tm:_reply_light: finished 0(5309) DEBUG: mk_proxy: doing DNS lookup... 0(5309) check_via_address(10.161.14.59, 10.161.14.59, 0) 0(5309) DEBUG: add_to_tail_of_timer[4]: 0x40355bf4 0(5309) DEBUG: add_to_tail_of_timer[0]: 0x40355c04 0(5309) SER: new transaction fwd'ed 0(5309) DEBUG:destroy_avp_list: destroying list (nil) 0(5309) receive_msg: cleaning up 0(5309) SIP Reply (status): 0(5309) version: <SIP/2.0> 0(5309) status: <100> 0(5309) reason: <Trying> 0(5309) parse_headers: flags=2 0(5309) DEBUG:parse_to:end of header reached, state=9 0(5309) DEBUG: get_hdr_field: <To> [37]; uri=[ sip:user4@home2.jagarvayo.mot.dev] 0(5309) DEBUG: to body [sip:user4@home2.jagarvayo.mot.dev
] 0(5309) get_hdr_field: cseq <CSeq>: <1> <INVITE> 0(5309) Found param type 232, <branch> = < z9hG4bK7d0f.cf43897e3c46f1bb8c4ab6702426d007.0>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK4f9932cde5bad6c36f103563aa96f449>; state=6 0(5309) Found param type 238, <xxxST_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK6f59072ad3fe644fcf851c16d3168bee>; state=6 0(5309) Found param type 238, <xxxIT_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK80752856b61f3aaf3f1d17e57067d067>; state=6 0(5309) Found param type 238, <xxxSO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK8b46a43071f3848c711cb4bcf4b42335>; state=6 0(5309) Found param type 238, <xxxPO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) end of header reached, state=5 0(5309) parse_headers: Via found, flags=2 0(5309) parse_headers: this is the first via 0(5309) After parse_msg... 0(5309) forward_reply: found module tm, passing reply to it 0(5309) DEBUG: t_check: msg id=2 global id=1 T start=0xffffffff 0(5309) parse_headers: flags=22 0(5309) parse_headers: flags=8 0(5309) DEBUG: t_reply_matching: hash 61655 label 0 branch 0 0(5309) DEBUG: t_reply_matching: reply matched (T=0x40355ae0)! 0(5309) DEBUG: t_check: msg id=2 global id=2 T end=0x40355ae0 0(5309) DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1) 0(5309) DEBUG:tm:t_should_relay_response: T_code=100, new_code=100 0(5309) DEBUG:tm:relay_reply: branch=0, save=0, relay=-1 0(5309) DEBUG: add_to_tail_of_timer[1]: 0x40355c04 0(5309) DEBUG:destroy_avp_list: destroying list (nil) 0(5309) receive_msg: cleaning up 0(5309) SIP Reply (status): 0(5309) version: <SIP/2.0> 0(5309) status: <183> 0(5309) reason: <Session Progress> 0(5309) parse_headers: flags=2 0(5309) DEBUG: add_param: tag=9991 0(5309) DEBUG:parse_to:end of header reached, state=29 0(5309) DEBUG: get_hdr_field: <To> [46]; uri=[ sip:user4@home2.jagarvayo.mot.dev] 0(5309) DEBUG: to body [sip:user4@home2.jagarvayo.mot.dev] 0(5309) get_hdr_field: cseq <CSeq>: <1> <INVITE> 0(5309) Found param type 232, <branch> = < z9hG4bK7d0f.cf43897e3c46f1bb8c4ab6702426d007.0>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK4f9932cde5bad6c36f103563aa96f449>; state=6 0(5309) Found param type 238, <xxxST_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK6f59072ad3fe644fcf851c16d3168bee>; state=6 0(5309) Found param type 238, <xxxIT_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK80752856b61f3aaf3f1d17e57067d067>; state=6 0(5309) Found param type 238, <xxxSO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK8b46a43071f3848c711cb4bcf4b42335>; state=6 0(5309) Found param type 238, <xxxPO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) end of header reached, state=5 0(5309) parse_headers: Via found, flags=2 0(5309) parse_headers: this is the first via 0(5309) After parse_msg... 0(5309) forward_reply: found module tm, passing reply to it 0(5309) DEBUG: t_check: msg id=3 global id=2 T start=0xffffffff 0(5309) parse_headers: flags=22 0(5309) parse_headers: flags=8 0(5309) DEBUG: t_reply_matching: hash 61655 label 0 branch 0 0(5309) DEBUG: t_reply_matching: reply matched (T=0x40355ae0)! 0(5309) DEBUG: t_check: msg id=3 global id=3 T end=0x40355ae0 0(5309) DEBUG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1) 0(5309) DEBUG:tm:t_should_relay_response: T_code=100, new_code=183 0(5309) DEBUG:tm:relay_reply: branch=0, save=0, relay=0 0(5309) old size: 1120, new size: 1035 0(5309) build_res_from_sip_res: copied size: orig:549, new: 464, rest: 571 msg= SIP/2.0 183 Session Progress
From: sip:user3@home2.jagarvayo.mot.dev;tag=6661
To: sip:user4@home2.jagarvayo.mot.dev;tag=9991
Call-ID: 1-26284@10.161.14.105
CSeq: 1 INVITE
Contact: sip:10.161.14.105:6020
Content-Type: application/sdp
Record-Route: sip:xxxPT_002@10.161.14.59;lr,sip:xxxST_002@10.161.14.59 ;lr,sip:10.161.14.110:7000;ftag=6661;lr,sip:xxxST_002@10.161.14.59;lr,< sip:xxxSO_002@10.161.14.59;lr>,sip:xxxPO_002@10.161.14.59;lr
Via: SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK4f9932cde5bad6c36f103563aa96f449;xxxST_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK6f59072ad3fe644fcf851c16d3168bee;xxxIT_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK80752856b61f3aaf3f1d17e57067d067;xxxSO_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK8b46a43071f3848c711cb4bcf4b42335;xxxPO_002,SIP/2.0/UDP 10.161.14.105:6020
P-Charging-Vector: icid-value= 43d9d426:f1135:7e37002e@pcscf.home2.jagarvayo.mot.dev;term-ioi=ims.XXX.com
v=0
o=srini - 0 IN IP4 -
s=SIPtest - -
c=IN IP4 10.161.14.59
t=0 0
m=audio 2410 RTP/AVP 0
0(5309) DEBUG:tm:relay_reply: sent buf=0x8138178: SIP/2.0 1..., shmem=0x40357f90: SIP/2.0 1 0(5309) DEBUG: add_to_tail_of_timer[1]: 0x40355c04 0(5309) DEBUG:destroy_avp_list: destroying list (nil) 0(5309) receive_msg: cleaning up 1(5311) DEBUG: timer routine:4,tl=0x40355bf4 next=(nil) 0(5309) SIP Reply (status): 0(5309) version: <SIP/2.0> 0(5309) status: <180> 0(5309) reason: <Ringing> 0(5309) parse_headers: flags=2 0(5309) DEBUG: add_param: tag=9991 0(5309) DEBUG:parse_to:end of header reached, state=29 0(5309) DEBUG: get_hdr_field: <To> [46]; uri=[ sip:user4@home2.jagarvayo.mot.dev] 0(5309) DEBUG: to body [sip:user4@home2.jagarvayo.mot.dev] 0(5309) get_hdr_field: cseq <CSeq>: <1> <INVITE> 0(5309) DEBUG: get_hdr_body : content_length=0 0(5309) Found param type 232, <branch> = < z9hG4bK7d0f.cf43897e3c46f1bb8c4ab6702426d007.0>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK4f9932cde5bad6c36f103563aa96f449>; state=6 0(5309) Found param type 238, <xxxST_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK6f59072ad3fe644fcf851c16d3168bee>; state=6 0(5309) Found param type 238, <xxxIT_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK80752856b61f3aaf3f1d17e57067d067>; state=6 0(5309) Found param type 238, <xxxSO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) Found param type 232, <branch> = <z9hG4bK8b46a43071f3848c711cb4bcf4b42335>; state=6 0(5309) Found param type 238, <xxxPO_002> = <n/a>; state=9 0(5309) parse_via: next_via 0(5309) end of header reached, state=5 0(5309) parse_headers: Via found, flags=2 0(5309) parse_headers: this is the first via 0(5309) After parse_msg... 0(5309) forward_reply: found module tm, passing reply to it 0(5309) DEBUG: t_check: msg id=4 global id=3 T start=0xffffffff 0(5309) parse_headers: flags=22 0(5309) parse_headers: flags=8 0(5309) DEBUG: t_reply_matching: hash 61655 label 0 branch 0 0(5309) DEBUG: t_reply_matching: reply matched (T=0x40355ae0)! 0(5309) DEBUG: t_check: msg id=4 global id=4 T end=0x40355ae0 0(5309) DEBUG:tm:reply_received: org. status uas=183, uac[0]=183 local=0 is_invite=1) 0(5309) DEBUG:tm:t_should_relay_response: T_code=183, new_code=180 0(5309) DEBUG:tm:relay_reply: branch=0, save=0, relay=0 0(5309) old size: 1001, new size: 916 0(5309) build_res_from_sip_res: copied size: orig:528, new: 443, rest: 473 msg= SIP/2.0 180 Ringing
From: sip:user3@home2.jagarvayo.mot.dev;tag=6661
To: sip:user4@home2.jagarvayo.mot.dev;tag=9991
Call-ID: 1-26284@10.161.14.105
CSeq: 1 INVITE
Contact: sip:10.161.14.105:6020
Content-Length: 0
Record-Route: sip:xxxPT_002@10.161.14.59;lr,sip:xxxST_002@10.161.14.59 ;lr,sip:10.161.14.110:7000;ftag=6661;lr,sip:xxxST_002@10.161.14.59;lr,< sip:xxxSO_002@10.161.14.59;lr>,sip:xxxPO_002@10.161.14.59;lr
Via: SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK4f9932cde5bad6c36f103563aa96f449;xxxST_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK6f59072ad3fe644fcf851c16d3168bee;xxxIT_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK80752856b61f3aaf3f1d17e57067d067;xxxSO_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK8b46a43071f3848c711cb4bcf4b42335;xxxPO_002,SIP/2.0/UDP 10.161.14.105:6020
P-Charging-Vector: icid-value= 43d9d426:f1135:7e37002e@pcscf.home2.jagarvayo.mot.dev;term-ioi=ims.XXX.com
0(5309) DEBUG:tm:relay_reply: sent buf=0x8138178: SIP/2.0 1..., shmem=0x40357f90: SIP/2.0 1 0(5309) DEBUG: add_to_tail_of_timer[1]: 0x40355c04 0(5309) DEBUG:destroy_avp_list: destroying list (nil) 0(5309) receive_msg: cleaning up 0(5309) SIP Request: 0(5309) method: <CANCEL> 0(5309) uri: sip:10.161.14.104:6030 0(5309) version: <SIP/2.0> 0(5309) parse_headers: flags=2 0(5309) Found param type 232, <branch> = <z9hG4bK4f9932cde5bad6c36f103563aa96f449>; state=6 0(5309) Found param type 238, <xxxST_002> = <n/a>; state=17 0(5309) end of header reached, state=5 0(5309) parse_headers: Via found, flags=2 0(5309) parse_headers: this is the first via 0(5309) After parse_msg... 0(5309) preparing to run routing scripts... 0(5309) parse_headers: flags=100 0(5309) DEBUG:parse_to:end of header reached, state=9 0(5309) DEBUG: get_hdr_field: <To> [37]; uri=[ sip:user4@home2.jagarvayo.mot.dev] 0(5309) DEBUG: to body [sip:user4@home2.jagarvayo.mot.dev
] 0(5309) get_hdr_field: cseq <CSeq>: <1> <CANCEL> 0(5309) DEBUG:maxfwd:is_maxfwd_present: value = 70 0(5309) DEBUG: add_param: tag=6661 0(5309) DEBUG:parse_to:end of header reached, state=29 0(5309) xl_printf: final buffer length 101 0(5309) CANCEL: 10.161.14.59:5060 ci=1-26284@10.161.14.105 ft=6661 tt=<null> cseq=1 sip:10.161.14.104:6030: 0(5309) parse_headers: flags=200 0(5309) DEBUG: get_hdr_body : content_length=0 0(5309) found end of header 0(5309) find_first_route: No Route headers found 0(5309) loose_route: There is no Route HF 0(5309) DEBUG: t_newtran: msg id=5 , global msg id=4 , T on entrance=0xffffffff 0(5309) parse_headers: flags=ffffffffffffffff 0(5309) parse_headers: flags=78 0(5309) t_lookup_request: start searching: hash=61655, isACK=0 0(5309) DEBUG: RFC3261 transaction matching failed 0(5309) DEBUG: t_lookup_request: no transaction found 0(5309) parse_headers: flags=78 0(5309) DEBUG: MD5 calculated: 1b7635cf6840ddd15282505b57290b27 0(5309) DEBUG: t_lookupOriginalT: searching on hash entry 61655 0(5309) DEBUG: RFC3261 transaction matched, tid=4f9932cde5bad6c36f103563aa96f449 0(5309) DEBUG: t_lookupOriginalT: canceled transaction found (0x40355ae0)! 0(5309) DEBUG: t_lookupOriginalT completed 0(5309) check_via_address(10.161.14.59, 10.161.14.59, 0) 0(5309) DEBUG: add_to_tail_of_timer[4]: 0x4035855c 0(5309) DEBUG: add_to_tail_of_timer[0]: 0x4035856c 0(5309) DEBUG: e2e_cancel: e2e cancel proceeding 0(5309) parse_headers: flags=ffffffffffffffff 0(5309) check_via_address(10.161.14.59, 10.161.14.59, 0) 0(5309) WARNING:vqm_resize: resize(0) called 0(5309) DEBUG: cleanup_uac_timers: RETR/FR timers reset 0(5309) DEBUG: add_to_tail_of_timer[2]: 0x40358490 0(5309) DEBUG:tm:_reply_light: reply sent out. buf=0x8138320: SIP/2.0 2..., shmem=0x40359558: SIP/2.0 2 0(5309) DEBUG:tm:_reply_light: finished 0(5309) SER: new transaction fwd'ed 0(5309) DEBUG:destroy_avp_list: destroying list (nil) 0(5309) receive_msg: cleaning up 0(5309) SIP Reply (status): 0(5309) version: <SIP/2.0> 0(5309) status: <481> 0(5309) reason: <Call Leg/Transaction Does Not Exist> 0(5309) parse_headers: flags=2 0(5309) DEBUG:parse_to:end of header reached, state=9 0(5309) DEBUG: get_hdr_field: <To> [37]; uri=[ sip:user4@home2.jagarvayo.mot.dev] 0(5309) DEBUG: to body [sip:user4@home2.jagarvayo.mot.dev
]
Hello,
it is hard to watch the content of the SIP messages from the debug logs. Could you please post the network trace for this situation? Use:
ngrep -qt port 5060
on the openser machine. That will show us the content of the SIP requests.
Cheers, Daniel
On 01/27/06 13:03, Jose Antonio Garvayo wrote:
*Hi,
I am experiencing a problem regarding CANCEL processing, I have the normal config file plus the following (I got that in a previous mail)
if (is_method("CANCEL")) { t_relay(); break; }
The problem is that openserver is relaying the CANCEL, but putting a completely new branch tag in the Via header, instead of the same branch than in the INVITE that is to be cancel. I have debug dump, that shows that the CANCEL message is matched with the INVITE, but it still put a new branch in the relayed cancel, and also in the 200 OK response.
If somebody could help me it would be great [...]
Hello,
I have attached the tcpdump log, and a call flow diagram, I hope it will be useful.
Maybe the problem is that the cancel request uri does not match the invite request uri. But I tried putting modparam("tm", "ruri_matching", 0) and it didn't work.
This is the openser.cfg:
route{
# initial sanity checks -- messages with # max_forwards==0, or excessively long requests if (!mf_process_maxfwd_header("10")) { sl_send_reply("483","Too Many Hops"); exit; };
if (msg:len >= 2048 ) { sl_send_reply("513", "Message too big"); exit; };
xlog("L_INFO", "$rm: ci=$ci ft=$ft tt=$tt cseq=$cs ruri:$ru received from: $si:$sp \n");
# we record-route all messages -- to make sure that # subsequent messages will go through our proxy; that's # particularly good if upstream and downstream entities # use different transport protocol if (!is_method("REGISTER|ACK|CANCEL")) { record_route(); }
if (is_method("CANCEL")) { xlog ("L_INFO", "$rm: cseq:$cs $ru: RELAYING CANCEL to $du (flags: $mF) ...\n"); t_relay(); exit(); }
# subsequent messages withing a dialog should take the # path determined by record-routing if (loose_route()) { # mark routing logic in request append_hf("P-hint: rr-enforced\r\n"); route(1); exit; };
# if the request is for other domain use UsrLoc # (in case, it does not work, use the following command # with proper names and addresses in it) if (uri==myself) {
if (method=="REGISTER") {
# Uncomment this if you want to use digest authentication #if (!www_authorize("openser.org", "subscriber")) { # www_challenge("openser.org", "0"); # exit; #};
save("location"); exit; };
# native SIP destinations are handled using our USRLOC DB if (!lookup("location")) { sl_send_reply("404", "Not Found"); exit; }; append_hf("P-hint: usrloc applied\r\n"); route(1); };
route(1); }
route[1] { xlog ("L_INFO", "$rm: cseq:$cs $ru: RELAYING to $du (flags: $mF) ...\n"); if (!t_relay()) { sl_reply_error(); };
}
This is the log of the openser:
Jan 31 11:43:36 minilab07 ./openser[15342]: INVITE: ci=1-17070@10.161.14.105ft=6661 tt=<null> cseq=1 ruri:sip:user4@home2.jagarvayo.dev received from: 10.161.14.59:5060 Jan 31 11:43:36 minilab07 ./openser[15342]: INVITE: cseq:1 sip:user4@home2.jagarvayo.dev: RELAYING to sip:csm002_9a7fa601f073fb780fec6551d45facc8@10.161.14.59;lr (flags: 00000000) ... Jan 31 11:43:38 minilab07 ./openser[15342]: CANCEL: ci=1-17070@10.161.14.105ft=6661 tt=<null> cseq=1 ruri:sip: 10.161.14.105:6030 received from: 10.161.14.59:5060 Jan 31 11:43:38 minilab07 ./openser[15342]: CANCEL: cseq:1 sip: 10.161.14.105:6030: RELAYING CANCEL to (flags: 00000000) ... Jan 31 11:43:39 minilab07 ./openser[15341]: CANCEL: ci=1-17070@10.161.14.105ft=6661 tt=<null> cseq=1 ruri:sip: 10.161.14.105:6030 received from: 10.161.14.59:5060 Jan 31 11:43:39 minilab07 ./openser[15341]: CANCEL: cseq:1 sip: 10.161.14.105:6030: RELAYING CANCEL to (flags: 00000000) ... Jan 31 11:43:40 minilab07 ./openser[15341]: CANCEL: ci=1-17070@10.161.14.105ft=6661 tt=<null> cseq=1 ruri:sip: 10.161.14.105:6030 received from: 10.161.14.59:5060 Jan 31 11:43:40 minilab07 ./openser[15341]: CANCEL: cseq:1 sip: 10.161.14.105:6030: RELAYING CANCEL to (flags: 00000000) ... Jan 31 11:43:42 minilab07 ./openser[15341]: CANCEL: ci=1-17070@10.161.14.105ft=6661 tt=<null> cseq=1 ruri:sip: 10.161.14.105:6030 received from: 10.161.14.59:50
Thanks a lot
On 1/29/06, Daniel-Constantin Mierla daniel@voice-system.ro wrote:
Hello,
it is hard to watch the content of the SIP messages from the debug logs. Could you please post the network trace for this situation? Use:
ngrep -qt port 5060
on the openser machine. That will show us the content of the SIP requests.
Cheers, Daniel
On 01/27/06 13:03, Jose Antonio Garvayo wrote:
*Hi,
I am experiencing a problem regarding CANCEL processing, I have the normal config file plus the following (I got that in a previous mail)
if (is_method("CANCEL")) { t_relay(); break; }
The problem is that openserver is relaying the CANCEL, but putting a completely new branch tag in the Via header, instead of the same branch than in the INVITE that is to be cancel. I have debug dump, that shows that the CANCEL message is matched with the INVITE, but it still put a new branch in the relayed cancel, and also in the 200 OK response.
If somebody could help me it would be great [...]
Hello Jose,
it is pretty hard to watch the netwok trace you send, next time please save it as pcap file so I can loaded easily in ethereal or use ngrep which gives more compact information.
Anyhow, there is something bad with the 10.161.14.59.
The invite comes from 10.161.14.105:20, goes through 10.161.14.59 to openser which is 10.161.14.110. OpenSER sends back to 10.161.14.59 and this device sends it to 10.161.14.105:6030.
CANCEL comes to 10.161.14.59 (this changes R-URI and this is not right), goes to openser (which sets the R-URI as it was in the INVITE forwarded by it) and then back to 10.161.14.59. The 10.161.14.59 response with "call leg transaction does not exists" while it should be. From OpenSER side, everything was OK, the CANCEL matched the initial INVITE transaction and it forwarded the CANCEL properly.
My guess is that 10.161.14.59 messes the two dialogs it keeps. What is the device running on 10.161.14.59? It does not add any signature.
Cheers, Daniel
On 01/31/06 13:22, Jose Antonio Garvayo wrote:
Hello,
I have attached the tcpdump log, and a call flow diagram, I hope it will be useful.
Maybe the problem is that the cancel request uri does not match the invite request uri. But I tried putting modparam("tm", "ruri_matching", 0) and it didn't work.
This is the openser.cfg:
Hello Daniel,
Thanks for your response, but I still think there's an error in openser. Let me explain it:
This is the first INVITE that arrives at openser (Frame #3)
Frame 3 (1257 bytes on wire, 1257 bytes captured) Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: Dell_aa:32:dd (00:11:43:aa:32:dd) Internet Protocol, Src: 10.161.14.59 (10.161.14.59), Dst: 10.161.14.110 ( 10.161.14.110) User Datagram Protocol, Src Port: 5060 (5060), Dst Port: 7000 (7000) Session Initiation Protocol Request-Line: INVITE sip:user4@home2.jagarvayo.dev SIP/2.0 Message Header Via: SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bKdbe6e7de6d54b4e9ab0b8e1dc4a09cb3;XXXIT_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bKbee4d2140af14727cd281a783633a8f From: sip:user3@home2.jagarvayo.dev;tag=6661 To: sip:user4@home2.jagarvayo.dev Supported: 100rel Call-ID: 1-17070@10.161.14.105 CSeq: 1 INVITE
This is the INVITE proxied by openser (Frame #5)
Frame 5 (1397 bytes on wire, 1397 bytes captured) Ethernet II, Src: Dell_bb:14:43 (00:11:43:bb:14:43), Dst: 00:00:00_00:00:01 (00:00:00:00:00:01) Internet Protocol, Src: 10.161.14.110 (10.161.14.110), Dst: 10.161.14.59 ( 10.161.14.59) User Datagram Protocol, Src Port: 7000 (7000), Dst Port: 5060 (5060) Session Initiation Protocol Request-Line: INVITE sip:user4@home2.jagarvayo.dev SIP/2.0 Message Header Record-Route: sip:10.161.14.110:7000;ftag=6661;lr Via: SIP/2.0/UDP 10.161.14.110:7000;branch= z9hG4bK5ead.85b42d6fbdf28af51be1fd77461ef605.0 Via: SIP/2.0/UDP 10.161.14.59;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bKdbe6e7de6d54b4e9ab0b8e1dc4a09cb3;XXXIT_002,SIP/2.0/UDP 10.161.14.59;branch=z9hG4bKbee4d2140af14727cd281a783633a8f From: sip:user3@home2.jagarvayo.dev;tag=6661 To: sip:user4@home2.jagarvayo.dev Supported: 100rel Call-ID: 1-17070@10.161.14.105 CSeq: 1 INVITE
This the CANCEL message that arrives at openser (Frame #19)
Frame 19 (349 bytes on wire, 349 bytes captured) Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: Dell_aa:32:dd (00:11:43:aa:32:dd) Internet Protocol, Src: 10.161.14.59 (10.161.14.59), Dst: 10.161.14.110 ( 10.161.14.110) User Datagram Protocol, Src Port: 5060 (5060), Dst Port: 7000 (7000) Session Initiation Protocol Request-Line: CANCEL sip:10.161.14.105:6030 SIP/2.0 Message Header Via: SIP/2.0/UDP 10.161.14.59 ;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002 Call-ID: 1-17070@10.161.14.105 From: sip:user3@home2.jagarvayo.dev;tag=6661 To: sip:user4@home2.jagarvayo.dev CSeq: 1 CANCEL Max-Forwards: 70 Content-Length: 0
This is the CANCEL message sent by openser (Frame #20), to cancel the invite in frame #5
Frame 20 (451 bytes on wire, 451 bytes captured) Ethernet II, Src: Dell_bb:14:43 (00:11:43:bb:14:43), Dst: 00:00:00_00:00:01 (00:00:00:00:00:01) Internet Protocol, Src: 10.161.14.110 (10.161.14.110), Dst: 10.161.14.59 ( 10.161.14.59) User Datagram Protocol, Src Port: 7000 (7000), Dst Port: 5060 (5060) Session Initiation Protocol Request-Line: CANCEL sip:user4@home2.jagarvayo.dev SIP/2.0 Message Header Via: SIP/2.0/UDP 10.161.14.110:7000;branch= z9hG4bK5ead.24bd76c541a061667969156e698855df.0 Via: SIP/2.0/UDP 10.161.14.59 ;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002 Call-ID: 1-17070@10.161.14.105 From: sip:user3@home2.jagarvayo.dev;tag=6661 To: sip:user4@home2.jagarvayo.dev CSeq: 1 CANCEL Max-Forwards: 69 Content-Length: 0
Should not the CANCEL in frame #20 have the same branch as in the INVITE in frame #5? (As it is said in 3261) Via: SIP/2.0/UDP 10.161.14.110:7000;branch= z9hG4bK5ead.85b42d6fbdf28af51be1fd77461ef605.0 instead of Via: SIP/2.0/UDP 10.161.14.110:7000;branch= z9hG4bK5ead.24bd76c541a061667969156e698855df.0
The proxy in 10.161.14.59 is answering "call leg transaction does not exists" because there is no transaction with that branch.
I agree that the proxy at 10.161.14.59 has changed the request-uri, but openser seems to locate the transaction to be cancelled but still does not put a right branch in the CANCEL.
Best Regards, Jose Antonio
You are right, I missed the branch value. I will investigate further, at least the initial INVITE transaction is matched, since the R-URI is restored. The problem should be in branch id generation.
Cheers, Daniel
On 02/02/06 15:54, Jose Antonio Garvayo wrote:
Hello Daniel,
Thanks for your response, but I still think there's an error in openser. Let me explain it:
This is the first INVITE that arrives at openser (Frame #3)
Frame 3 (1257 bytes on wire, 1257 bytes captured) Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: Dell_aa:32:dd (00:11:43:aa:32:dd) Internet Protocol, Src: 10.161.14.59 http://10.161.14.59 (10.161.14.59 http://10.161.14.59), Dst: 10.161.14.110 http://10.161.14.110 (10.161.14.110 http://10.161.14.110) User Datagram Protocol, Src Port: 5060 (5060), Dst Port: 7000 (7000) Session Initiation Protocol Request-Line: INVITE sip:user4@home2.jagarvayo.dev mailto:sip:user4@home2.jagarvayo.dev SIP/2.0 Message Header Via: SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002,SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bKdbe6e7de6d54b4e9ab0b8e1dc4a09cb3;XXXIT_002,SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bKbee4d2140af14727cd281a783633a8f From: <sip:user3@home2.jagarvayo.dev mailto:sip:user3@home2.jagarvayo.dev>;tag=6661 To: <sip:user4@home2.jagarvayo.dev mailto:sip:user4@home2.jagarvayo.dev> Supported: 100rel Call-ID: 1-17070@10.161.14.105 mailto:1-17070@10.161.14.105 CSeq: 1 INVITE
This is the INVITE proxied by openser (Frame #5)
Frame 5 (1397 bytes on wire, 1397 bytes captured) Ethernet II, Src: Dell_bb:14:43 (00:11:43:bb:14:43), Dst: 00:00:00_00:00:01 (00:00:00:00:00:01) Internet Protocol, Src: 10.161.14.110 http://10.161.14.110 (10.161.14.110 http://10.161.14.110), Dst: 10.161.14.59 http://10.161.14.59 (10.161.14.59 http://10.161.14.59) User Datagram Protocol, Src Port: 7000 (7000), Dst Port: 5060 (5060) Session Initiation Protocol Request-Line: INVITE sip:user4@home2.jagarvayo.dev mailto:sip:user4@home2.jagarvayo.dev SIP/2.0 Message Header Record-Route: <sip:10.161.14.110:7000 http://10.161.14.110:7000;ftag=6661;lr> Via: SIP/2.0/UDP 10.161.14.110:7000 http://10.161.14.110:7000;branch=z9hG4bK5ead.85b42d6fbdf28af51be1fd77461ef605.0 Via: SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002,SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bKdbe6e7de6d54b4e9ab0b8e1dc4a09cb3;XXXIT_002,SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bKbee4d2140af14727cd281a783633a8f From: <sip:user3@home2.jagarvayo.dev mailto:sip:user3@home2.jagarvayo.dev>;tag=6661 To: <sip:user4@home2.jagarvayo.dev mailto:sip:user4@home2.jagarvayo.dev> Supported: 100rel Call-ID: 1-17070@10.161.14.105 mailto:1-17070@10.161.14.105 CSeq: 1 INVITE
This the CANCEL message that arrives at openser (Frame #19)
Frame 19 (349 bytes on wire, 349 bytes captured) Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: Dell_aa:32:dd (00:11:43:aa:32:dd) Internet Protocol, Src: 10.161.14.59 http://10.161.14.59 (10.161.14.59 http://10.161.14.59), Dst: 10.161.14.110 http://10.161.14.110 (10.161.14.110 http://10.161.14.110) User Datagram Protocol, Src Port: 5060 (5060), Dst Port: 7000 (7000) Session Initiation Protocol Request-Line: CANCEL sip:10.161.14.105:6030 http://10.161.14.105:6030 SIP/2.0 Message Header Via: SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002 Call-ID: 1-17070@10.161.14.105 mailto:1-17070@10.161.14.105 From: <sip:user3@home2.jagarvayo.dev mailto:sip:user3@home2.jagarvayo.dev>;tag=6661 To: <sip:user4@home2.jagarvayo.dev mailto:sip:user4@home2.jagarvayo.dev> CSeq: 1 CANCEL Max-Forwards: 70 Content-Length: 0
This is the CANCEL message sent by openser (Frame #20), to cancel the invite in frame #5
Frame 20 (451 bytes on wire, 451 bytes captured) Ethernet II, Src: Dell_bb:14:43 (00:11:43:bb:14:43), Dst: 00:00:00_00:00:01 (00:00:00:00:00:01) Internet Protocol, Src: 10.161.14.110 http://10.161.14.110 (10.161.14.110 http://10.161.14.110), Dst: 10.161.14.59 http://10.161.14.59 (10.161.14.59 http://10.161.14.59) User Datagram Protocol, Src Port: 7000 (7000), Dst Port: 5060 (5060) Session Initiation Protocol Request-Line: CANCEL sip:user4@home2.jagarvayo.dev mailto:sip:user4@home2.jagarvayo.dev SIP/2.0 Message Header Via: SIP/2.0/UDP 10.161.14.110:7000 http://10.161.14.110:7000;branch=z9hG4bK5ead.24bd76c541a061667969156e698855df.0 Via: SIP/2.0/UDP 10.161.14.59 http://10.161.14.59;branch=z9hG4bK2c42bc6a078c550314f3b9c31ddcf05d;XXXST_002 Call-ID: 1-17070@10.161.14.105 mailto:1-17070@10.161.14.105 From: <sip:user3@home2.jagarvayo.dev mailto:sip:user3@home2.jagarvayo.dev>;tag=6661 To: <sip:user4@home2.jagarvayo.dev mailto:sip:user4@home2.jagarvayo.dev> CSeq: 1 CANCEL Max-Forwards: 69 Content-Length: 0
Should not the CANCEL in frame #20 have the same branch as in the INVITE in frame #5? (As it is said in 3261) Via: SIP/2.0/UDP 10.161.14.110:7000 http://10.161.14.110:7000;branch=z9hG4bK5ead.85b42d6fbdf28af51be1fd77461ef605.0 instead of Via: SIP/2.0/UDP 10.161.14.110:7000 http://10.161.14.110:7000;branch=z9hG4bK5ead.24bd76c541a061667969156e698855df.0
The proxy in 10.161.14.59 http://10.161.14.59 is answering "call leg transaction does not exists" because there is no transaction with that branch.
I agree that the proxy at 10.161.14.59 http://10.161.14.59 has changed the request-uri, but openser seems to locate the transaction to be cancelled but still does not put a right branch in the CANCEL.
Best Regards, Jose Antonio
Here is the result. By ignoring the R-URI when matching the INVITE transaction, OpenSER becomes not RFC3261 compliant. In chapter 9.1. Client behavior when canceling it is stated as MUST that R-URI must be the same.
<snip>
The following procedures are used to construct a CANCEL request. The Request-URI, Call-ID, To, the numeric part of CSeq, and From header fields in the CANCEL request MUST be identical to those in the request being cancelled, including tags.
</snip>
Because the R-URI is not the same, OpenSER generates another branch id.
What should be the solution, to remove the ruri_matching flag from OpenSER and have it all the time RFC-compliant, or keep ruri_matching and re-use the Via branch id from INVITE. What OpenSER users would like more?
Cheers, Daniel
On 02/02/06 17:44, Daniel-Constantin Mierla wrote:
You are right, I missed the branch value. I will investigate further, at least the initial INVITE transaction is matched, since the R-URI is restored. The problem should be in branch id generation.
Cheers, Daniel
On 02/02/06 15:54, Jose Antonio Garvayo wrote:
Hello Daniel,
Thanks for your response, but I still think there's an error in openser. Let me explain it: [...]
I am much in favor of the second one ... thought the other solution is OK also
On 2/2/06, Daniel-Constantin Mierla daniel@voice-system.ro wrote:
Here is the result. By ignoring the R-URI when matching the INVITE transaction, OpenSER becomes not RFC3261 compliant. In chapter 9.1. Client behavior when canceling it is stated as MUST that R-URI must be the same.
<snip>
The following procedures are used to construct a CANCEL request. The Request-URI, Call-ID, To, the numeric part of CSeq, and From header fields in the CANCEL request MUST be identical to those in the request being cancelled, including tags.
</snip>
Because the R-URI is not the same, OpenSER generates another branch id.
What should be the solution, to remove the ruri_matching flag from OpenSER and have it all the time RFC-compliant, or keep ruri_matching and re-use the Via branch id from INVITE. What OpenSER users would like more?
Cheers, Daniel
On 02/02/06 17:44, Daniel-Constantin Mierla wrote:
You are right, I missed the branch value. I will investigate further, at least the initial INVITE transaction is matched, since the R-URI is restored. The problem should be in branch id generation.
Cheers, Daniel
On 02/02/06 15:54, Jose Antonio Garvayo wrote:
Hello Daniel,
Thanks for your response, but I still think there's an error in openser. Let me explain it: [...]
What is the best way to call a stored procedure inside a block in openser ?
I have been using avp_db_query() but I would like to know if there are any other way, to do it as it force me to use cvs version.
Best Regards,
Hi,
the only other way (but very, very ugly) will be to use exec module to trigger an external script that does the mysql query.... but again, very ugly.
regards, bogdan
Elton Machado wrote:
What is the best way to call a stored procedure inside a block in openser ?
I have been using avp_db_query() but I would like to know if there are any other way, to do it as it force me to use cvs version.
Best Regards,
Users mailing list Users@openser.org http://openser.org/cgi-bin/mailman/listinfo/users
-
Bogdan-Andrei Iancu -
Daniel-Constantin Mierla -
Elton Machado -
Jose Antonio Garvayo