[Serusers] Need help to better understand transactions
Pauba, Kevin L
KLPauba at west.com
Fri Jul 11 21:37:20 CEST 2008
Hi,
I'm running SER V0.9.6 and I'm having a problem with CANCELs.
A client sends and invite to SER that relays it on to a gateway. In
this particular scenario, a CANCEL is send by the client after SER
responds with the 100 trying. I had thought that SER would match the
INVITE based on the branch tag and automatically send a CANCEL on to the
gateway. Unfortunately, SER cannot find a matching transaction and,
thus, the GATEWAY never receives a CANCEL..
Here's a snippet from the debugging output:
...
0(28802) SIP Request:
0(28802) method: <INVITE>
0(28802) uri: <sip:4027160348 at wic.west.com>
0(28802) version: <SIP/2.0>
0(28802) parse_headers: flags=1
0(28802) Found param type 232, <branch> = <z9hG4bK1249933199>; state=16
0(28802) end of header reached, state=5
0(28802) Header Type: 1
0(28802) parse_headers: Via found, flags=1
0(28802) parse_headers: this is the first via
0(28802) header field type 1, name=<Via>, body=<SIP/2.0/UDP
10.27.192.94:5060;branch=z9hG4bK1249933199>
0(28802) preparing to run routing scripts...
0(28802) parse_headers: flags=128
0(28802) Header Type: 8
0(28802) header field type 8, name=<From>,
body=<<sip:4027161000 at 10.27.192.94>;tag=3673666958>
0(28802) end of header reached, state=9
0(28802) DEBUG: get_hdr_field: <To> [31];
uri=[sip:4027160348 at wic.west.com]
0(28802) DEBUG: to body [<sip:4027160348 at wic.west.com>
]
0(28802) Header Type: 4
0(28802) header field type 4, name=<To>,
body=<<sip:4027160348 at wic.west.com>>
0(28802) Header Type: 32
0(28802) header field type 32, name=<Call-ID>,
body=<514+43+1215800190+24+t1b at 10.27.192.94>
0(28802) get_hdr_field: cseq <CSeq>: <2> <INVITE>
0(28802) Header Type: 16
0(28802) header field type 16, name=<CSeq>, body=<2 INVITE>
0(28802) Header Type: 64
0(28802) header field type 64, name=<Contact>,
body=<<sip:e514 at 10.27.192.94>>
0(28802) Header Type: 33554432
0(28802) header field type 33554432, name=<user-agent>,
body=<oSIP/wicsip-3.3.4>
0(28802) Header Type: 1073741824
0(28802) header field type 1073741824, name=<x-west-rg>, body=<0:17>
0(28802) Header Type: 1024
0(28802) header field type 1024, name=<Content-Type>,
body=<application/sdp>
0(28802) DEBUG: get_hdr_body : content_length=111
0(28802) Header Type: 2048
0(28802) header field type 2048, name=<Content-Length>, body=<111 >
0(28802) found end of header
0(28802) Header Type: -1
0(28802) DEBUG: is_maxfwd_present: max_forwards header not found!
0(28802) grep_sock_info - checking if host==us: 12==13 &&
[wic.west.com] == [10.27.193.119]
0(28802) grep_sock_info - checking if port 5060 matches port 5060
0(28802) grep_sock_info - checking if host==us: 12==13 &&
[wic.west.com] == [10.27.193.119]
0(28802) grep_sock_info - checking if port 5060 matches port 5060
0(28802) check_self: host != me
0(28802) subst_run: running. r=0
0(28802) subst_run: matched (0, 0): []
0(28802) subst_run: running. r=1
0(28802) subst_f: lst was (nil)
0(28802) subst_run: running. r=0
0(28802) subst_run: matched (0, 36):
[sip:9990001254027160348 at wic.west.com]
0(28802) textops: subst_uri_f: match - old uri=
[sip:9990001254027160348 at wic.west.com], new uri=
[sip:9990001254027160348 at 10.27.202.157]
0(28802) DEBUG: t_newtran: msg id=36 , global msg id=35 , T on
entrance=(nil)
0(28802) parse_headers: flags=-1
0(28802) parse_headers: flags=60
0(28802) t_lookup_request: start searching: hash=34792, isACK=0
0(28802) DEBUG: RFC3261 transaction matching failed
0(28802) DEBUG: t_lookup_request: no transaction found
0(28802) DEBUG: add_param: tag=3673666958
0(28802) end of header reached, state=29
0(28802) SER: new INVITE
0(28802) parse_headers: flags=-1
0(28802) check_via_address(10.27.192.94, 10.27.192.94, 0)
0(28802) WARNING:vqm_resize: resize(0) called
0(28802) DEBUG: reply sent out. buf=0x810be30: SIP/2.0 1...,
shmem=0x422c3c60: SIP/2.0 1
0(28802) DEBUG: _reply_light: finished
0(28802) DEBUG: mk_proxy: doing DNS lookup...
0(28802) check_via_address(10.27.192.94, 10.27.192.94, 0)
0(28802) DEBUG: add_to_tail_of_timer[4]: 0x422c2ac0
0(28802) DEBUG: add_to_tail_of_timer[0]: 0x422c2ad0
0(28802) SER: new transaction fwd'ed
0(28802) DEBUG:destroy_avp_list: destroying list (nil)
0(28802) receive_msg: cleaning up
0(28802)
...
0(28802) SIP Request:
0(28802) method: <CANCEL>
0(28802) uri: <sip:4027160348 at wic.west.com>
0(28802) version: <SIP/2.0>
0(28802) parse_headers: flags=1
0(28802) Found param type 232, <branch> = <z9hG4bK1249933199>; state=16
0(28802) end of header reached, state=5
0(28802) Header Type: 1
0(28802) parse_headers: Via found, flags=1
0(28802) parse_headers: this is the first via
0(28802) header field type 1, name=<Via>, body=<SIP/2.0/UDP
10.27.192.94:5060;branch=z9hG4bK1249933199>
0(28802) preparing to run routing scripts...
0(28802) parse_headers: flags=128
0(28802) Header Type: 8
0(28802) header field type 8, name=<From>,
body=<<sip:4027161000 at 10.27.192.94>;tag=3673666958>
0(28802) end of header reached, state=9
0(28802) DEBUG: get_hdr_field: <To> [31];
uri=[sip:4027160348 at wic.west.com]
0(28802) DEBUG: to body [<sip:4027160348 at wic.west.com>
]
0(28802) Header Type: 4
0(28802) header field type 4, name=<To>,
body=<<sip:4027160348 at wic.west.com>>
0(28802) Header Type: 32
0(28802) header field type 32, name=<Call-ID>,
body=<514+43+1215800190+24+t1b at 10.27.192.94>
0(28802) get_hdr_field: cseq <CSeq>: <2> <CANCEL>
0(28802) Header Type: 16
0(28802) header field type 16, name=<CSeq>, body=<2 CANCEL>
0(28802) Header Type: 64
0(28802) header field type 64, name=<Contact>,
body=<<sip:514+43+1215800190+24+t1b at 10.27.192.94>>
0(28802) Header Type: 33554432
0(28802) header field type 33554432, name=<user-agent>,
body=<oSIP/wicsip-3.3.4>
0(28802) Header Type: 1073741824
0(28802) header field type 1073741824, name=<x-west-rg>, body=<0:0>
0(28802) DEBUG: get_hdr_body : content_length=0
0(28802) Header Type: 2048
0(28802) header field type 2048, name=<Content-Length>, body=<0>
0(28802) found end of header
0(28802) Header Type: -1
0(28802) DEBUG: is_maxfwd_present: max_forwards header not found!
0(28802) grep_sock_info - checking if host==us: 12==13 &&
[wic.west.com] == [10.27.193.119]
0(28802) grep_sock_info - checking if port 5060 matches port 5060
0(28802) grep_sock_info - checking if host==us: 12==13 &&
[wic.west.com] == [10.27.193.119]
0(28802) grep_sock_info - checking if port 5060 matches port 5060
0(28802) check_self: host != me
0(28802) subst_run: running. r=0
0(28802) subst_run: matched (0, 27): [sip:4027160348 at wic.west.com]
0(28802) textops: subst_uri_f: match - old uri=
[sip:4027160348 at wic.west.com], new uri= [sip:4027160348 at 10.27.202.157]
0(28802) subst_run: running. r=0
0(28802) subst_run: matched (0, 0): []
0(28802) XLOG: xl_print_log: final buffer length 99
0(28802) time [Fri Jul 11 14:15:52 2008] KLP: CANCEL REQUEST - ruri
<sip:9990001254027160348 at 10.27.202.157>
0(28802) DEBUG: t_check: msg id=40 global id=37 T start=0xffffffff
0(28802) parse_headers: flags=-1
0(28802) parse_headers: flags=60
0(28802) t_lookup_request: start searching: hash=34792, isACK=0
0(28802) DEBUG: RFC3261 transaction matching failed
0(28802) DEBUG: t_lookup_request: no transaction found
0(28802) DEBUG: t_check: msg id=40 global id=40 T end=(nil)
0(28802) XLOG: xl_print_log: final buffer length 64
0(28802) time [Fri Jul 11 14:15:52 2008] KLP: CANCEL REQUEST --
ignoring
0(28802) DEBUG:destroy_avp_list: destroying list (nil)
0(28802) receive_msg: cleaning up
0(28802)
I've verified that the branchID of the INVITE matches that of the CANCEL
so I had expected the t_lookup_request() to succeed.
Do I misunderstand the way transactions work? Any suggestions on how I
might get this to work?
Any help is appreciated.
Thanks!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20080711/0543913a/attachment.htm>
More information about the sr-users
mailing list