[Users] cancel processing

Jose Antonio Garvayo jglara at gmail.com
Fri Jan 27 12:03:06 CET 2006


*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 at 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 at 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 at home2.jagarvayo.mot.dev]
 0(5309) DEBUG: to body [<sip:user4 at 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 at 10.161.14.105 ft=6661
tt=<null> cseq=1 sip:user4 at 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 at 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 at 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 at home2.jagarvayo.mot.dev]
 0(5309) DEBUG: to body [<sip:user4 at 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 at home2.jagarvayo.mot.dev]
 0(5309) DEBUG: to body [<sip:user4 at 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 at home2.jagarvayo.mot.dev>;tag=6661

To: <sip:user4 at home2.jagarvayo.mot.dev>;tag=9991

Call-ID: 1-26284 at 10.161.14.105

CSeq: 1 INVITE

Contact: <sip:10.161.14.105:6020>

Content-Type: application/sdp

Record-Route: <sip:xxxPT_002 at 10.161.14.59;lr>,<sip:xxxST_002 at 10.161.14.59
;lr>,<sip:10.161.14.110:7000;ftag=6661;lr>,<sip:xxxST_002 at 10.161.14.59;lr>,<
sip:xxxSO_002 at 10.161.14.59;lr>,<sip:xxxPO_002 at 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 at 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 at home2.jagarvayo.mot.dev]
 0(5309) DEBUG: to body [<sip:user4 at 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 at home2.jagarvayo.mot.dev>;tag=6661

To: <sip:user4 at home2.jagarvayo.mot.dev>;tag=9991

Call-ID: 1-26284 at 10.161.14.105

CSeq: 1 INVITE

Contact: <sip:10.161.14.105:6020>

Content-Length: 0

Record-Route: <sip:xxxPT_002 at 10.161.14.59;lr>,<sip:xxxST_002 at 10.161.14.59
;lr>,<sip:10.161.14.110:7000;ftag=6661;lr>,<sip:xxxST_002 at 10.161.14.59;lr>,<
sip:xxxSO_002 at 10.161.14.59;lr>,<sip:xxxPO_002 at 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 at 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 at home2.jagarvayo.mot.dev]
 0(5309) DEBUG: to body [<sip:user4 at 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 at 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 at home2.jagarvayo.mot.dev]
 0(5309) DEBUG: to body [<sip:user4 at home2.jagarvayo.mot.dev>

]
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20060127/aa51690f/attachment.htm>


More information about the sr-users mailing list