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@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@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@wic.west.com]
0(28802) DEBUG: to
body [<sip:4027160348@wic.west.com>
]
0(28802) Header Type:
4
0(28802) header field type 4, name=<To>,
body=<<sip:4027160348@wic.west.com>>
0(28802) Header Type:
32
0(28802) header field type 32, name=<Call-ID>, body=<514+43+1215800190+24+t1b@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@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@wic.west.com]
0(28802)
textops: subst_uri_f: match - old uri= [sip:9990001254027160348@wic.west.com],
new uri= [sip:9990001254027160348@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@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@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@wic.west.com]
0(28802) DEBUG: to
body [<sip:4027160348@wic.west.com>
]
0(28802) Header Type:
4
0(28802) header field type 4, name=<To>,
body=<<sip:4027160348@wic.west.com>>
0(28802) Header Type:
32
0(28802) header field type 32, name=<Call-ID>, body=<514+43+1215800190+24+t1b@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@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@wic.west.com]
0(28802) textops: subst_uri_f: match -
old uri= [sip:4027160348@wic.west.com], new uri=
[sip:4027160348@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@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!