[Users] CANCEL problem

Klaus Darilion klaus.mailinglists at pernau.at
Mon Nov 28 15:04:40 CET 2005 

Hi!

looks like there is a problem if the CANCEL is received during DNS 
lookup of the ongoing transaction.

The CANCEL is answered with 200 Ok, but the cancel will not send 
upstream, although the INVITE is sent. No 487 either.

My CANCEL config:

if ( is_method("CANCEL") && !t_check_trans() ) {
   # CANCEL without matching INVITE transaction, ignore
   # may happen if  the INVITE is slower than the CANCEL
   #  ignore the CANCEL, as the client will retransmit it,  and maybe 
next time
   # the INVITE transaction is already created
   xlog("L_WARN","CANCEL without matching transaction ... ignore and 
discard.\n");
   exit;
}

if ( is_method("CANCEL") ) {
   # CANCEL with matching INVITE transaction, just
   # t_relay
   xlog("L_INFO","CANCEL with matching transaction  ... t_relay.\n");
   t_relay();
   exit;

below are the SIP call flow and the syslog output

regards
klaus
openser[3670]: SIP Request:
openser[3670]:  method:  <CANCEL>
openser[3670]:  uri:     <sip:klaus3000 at iptel.org>
openser[3670]:  version: <SIP/2.0>
openser[3670]: parse_headers: flags=2
openser[3670]: Found param type 232, <branch> = 
<z9hG4bK-d87543-5b192d3a37574d15-1--d87543->; state=6
openser[3670]: Found param type 235, <rport> = <n/a>; state=17
openser[3670]: end of header reached, state=5
openser[3670]: parse_headers: Via found, flags=2
openser[3670]: parse_headers: this is the first via
openser[3670]: After parse_msg...
openser[3670]: preparing to run routing scripts...
openser[3670]: parse_headers: flags=100
openser[3670]: DEBUG:parse_to:end of header reached, state=9
openser[3670]: DEBUG: get_hdr_field: <To> [27]; 
uri=[sip:klaus3000 at iptel.org]
openser[3670]: DEBUG: to body [<sip:klaus3000 at iptel.org>^M ]
openser[3670]: get_hdr_field: cseq <CSeq>: <1> <CANCEL>
openser[3670]: DEBUG: get_hdr_body : content_length=0
openser[3670]: found end of header
openser[3670]: DEBUG: is_maxfwd_present: max_forwards header not found!
openser[3670]: parse_headers: flags=ffffffffffffffff
openser[3670]: DEBUG: add_param: tag=a83eae01
openser[3670]: DEBUG:parse_to:end of header reached, state=29
openser[3670]: parse_headers: flags=200
openser[3670]: find_first_route: No Route headers found
openser[3670]: loose_route: There is no Route HF
openser[3670]: parse_headers: flags=78
openser[3670]: DEBUG: t_lookupOriginalT: searching on hash entry 62046
openser[3670]: DEBUG: RFC3261 transaction matched, 
tid=-d87543-5b192d3a37574d15-1--d87543-
openser[3670]: DEBUG: t_lookupOriginalT: canceled transaction found 
(0x40484280)!
openser[3670]: DEBUG: t_lookupOriginalT completed
openser[3670]: xl_printf: final buffer length 46
openser[3670]: CANCEL with matching transaction ... t_relay.
openser[3670]: DEBUG: t_newtran: msg id=3 , global msg id=2 , T on 
entrance=0xffffffff
openser[3670]: parse_headers: flags=ffffffffffffffff
openser[3670]: parse_headers: flags=78
openser[3670]: t_lookup_request: start searching: hash=62046, isACK=0
openser[3670]: DEBUG: RFC3261 transaction matching failed
openser[3670]: DEBUG: t_lookup_request: no transaction found
openser[3670]: DEBUG: t_lookupOriginalT: searching on hash entry 62046
openser[3670]: DEBUG: RFC3261 transaction matched, 
tid=-d87543-5b192d3a37574d15-1--d87543-
openser[3670]: DEBUG: t_lookupOriginalT: canceled transaction found 
(0x40484280)!
openser[3670]: DEBUG: t_lookupOriginalT completed
openser[3670]: DEBUG: e2e_cancel: e2e cancel -- no more pending branches
openser[3670]: parse_headers: flags=ffffffffffffffff
openser[3670]: check_via_address(83.136.33.3, 83.136.33.3, 0)
openser[3670]: WARNING:vqm_resize: resize(0) called
openser[3670]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
openser[3670]: DEBUG: add_to_tail_of_timer[2]: 0x40486168
openser[3670]: DEBUG:tm:_reply_light: reply sent out. buf=0x8117520: 
SIP/2.0 2..., shmem=0x40485d00: SIP/2.0 2
openser[3670]: DEBUG:tm:_reply_light: finished
openser[3670]: SER: new transaction fwd'ed
openser[3670]: DEBUG:destroy_avp_list: destroying list (nil)
openser[3670]: receive_msg: cleaning up





U 2005/11/28 13:55:39.652279 83.136.33.3:8722 -> 213.239.207.29:5060
INVITE sip:klaus3000 at iptel.org SIP/2.0.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport.
Max-Forwards: 70.
Contact: <sip:klaus at 83.136.33.3:8722>.
To: <sip:klaus3000 at iptel.org>.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 INVITE.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, 
SUBSCRIBE, INFO.
Content-Type: application/sdp.
Supported: eventlist.
User-Agent: eyeBeam release 3010n stamp 19039.
Content-Length: 201.
.
v=0.
o=- 15208201 15208322 IN IP4 83.136.33.3.
s=eyeBeam.
c=IN IP4 83.136.33.3.
t=0 0.
m=audio 8468 RTP/AVP 0 8 3 18 101.
a=fmtp:101 0-15.
a=ptime:18 40.
a=rtpmap:101 telephone-event/8000.
a=sendrecv.

#
U 2005/11/28 13:55:39.660699 213.239.207.29:5060 -> 83.136.33.3:8722
SIP/2.0 100 trying -- your call is important to us.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport=8722.
To: <sip:klaus3000 at iptel.org>.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 INVITE.
Server: OpenSer (1.0.0 (i386/linux)).
Content-Length: 0.
Warning: 392 213.239.207.29:5060 "Noisy feedback tells:  pid=3669 
req_src_ip=83.136.33.3 req_src_port=8722 in_uri=sip:klaus3000 at iptel.org 
out_uri=sip:klaus3000 at iptel.org via_cnt==1".
.

#
U 2005/11/28 13:55:39.661561 213.239.207.29:32792 -> 213.133.98.96:53
............._sip._udp.iptel.org..!..
#
U 2005/11/28 13:55:39.718959 213.133.98.96:53 -> 213.239.207.29:32792
............._sip._udp.iptel.org..!.....!....N%.........sip.iptel.org.........N%...ns7
fraunhofer.de.........N%...ns1.V........N%...ns2.V........N%...ns3.V........N%...ns5.V.sip........N&...%Mc.R.......>...6"..q......"....,%..............`..
#
U 2005/11/28 13:55:39.719287 213.239.207.29:32792 -> 213.133.98.96:53
.............sip.iptel.org.....
#
U 2005/11/28 13:55:39.913552 83.136.33.3:8722 -> 213.239.207.29:5060
CANCEL sip:klaus3000 at iptel.org SIP/2.0.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport.
To: <sip:klaus3000 at iptel.org>.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 CANCEL.
User-Agent: eyeBeam release 3010n stamp 19039.
Content-Length: 0.
.

#
U 2005/11/28 13:55:39.918736 213.239.207.29:5060 -> 83.136.33.3:8722
SIP/2.0 200 ok -- no more pending branches.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport=8722.
To: <sip:klaus3000 at iptel.org>;tag=fa997f81440371de71ab448ebdb9af56-3f94.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 CANCEL.
Server: OpenSer (1.0.0 (i386/linux)).
Content-Length: 0.
Warning: 392 213.239.207.29:5060 "Noisy feedback tells:  pid=3670 
req_src_ip=83.136.33.3 req_src_port=8722 in_uri=sip:klaus3000 at iptel.org 
out_uri=sip:klaus3000 at iptel.org via_cnt==1".
.

#
U 2005/11/28 13:55:40.083745 213.133.98.96:53 -> 213.239.207.29:32792
.............sip.iptel.org.............N&...%Mc........N%...ns7
fraunhofer.de.........N%...ns1.?........N%...ns2.?........N%...ns3.?........N%...ns5.?.;.......>...6"..Z......"....,%..l...........`..
#
U 2005/11/28 13:55:40.084090 213.239.207.29:5060 -> 195.37.77.99:5060
INVITE sip:klaus3000 at iptel.org SIP/2.0.
Record-Route: <sip:213.239.207.29;ftag=a83eae01;lr=on>.
DomainKey-Signature: a=rsa-sha1; q=dns; c=simple; s=2005; 
d=dk.labs.nic.at; h=To:From; 
b=gQHw1V0nzlaGJgDtZX3DY+9MCck/NlieDzMnVseDjJALaG6/vtgZG98jPtas6CZx.
Via: SIP/2.0/UDP 213.239.207.29;branch=z9hG4bKe52f.c88e2d42.0.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport=8722.
Max-Forwards: 69.
Contact: <sip:klaus at 83.136.33.3:8722>.
To: <sip:klaus3000 at iptel.org>.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 INVITE.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, 
SUBSCRIBE, INFO.
Content-Type: application/sdp.
Supported: eventlist.
User-Agent: eyeBeam release 3010n stamp 19039.
Content-Length: 201.
P-hint: outbound.
.
v=0.
o=- 15208201 15208322 IN IP4 83.136.33.3.
s=eyeBeam.
c=IN IP4 83.136.33.3.
t=0 0.
m=audio 8468 RTP/AVP 0 8 3 18 101.
a=fmtp:101 0-15.
a=ptime:18 40.
a=rtpmap:101 telephone-event/8000.
a=sendrecv.

#
U 2005/11/28 13:55:40.105264 195.37.77.99:5060 -> 213.239.207.29:5060
SIP/2.0 100 trying -- your call is important to us.
Via: SIP/2.0/UDP 213.239.207.29;branch=z9hG4bKe52f.c88e2d42.0;rport=5060.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport=8722.
To: <sip:klaus3000 at iptel.org>.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 INVITE.
Server: Sip EXpress router (0.9.0udpfifo (i386/linux)).
Content-Length: 0.
Warning: 392 195.37.77.99:5060 "Noisy feedback tells:  pid=16799 
req_src_ip=213.239.207.29 req_src_port=5060 
in_uri=sip:klaus3000 at iptel.org out_uri=sip:klaus3000 at 192.168.2.3:5061 
via_cnt==2".
.

#
U 2005/11/28 13:55:40.956023 195.37.77.99:5060 -> 213.239.207.29:5060
SIP/2.0 180 Ringing.
To: <sip:klaus3000 at iptel.org>;tag=5afee18c3cf2167ei1.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 INVITE.
Via: SIP/2.0/UDP 213.239.207.29;rport=5060;branch=z9hG4bKe52f.c88e2d42.0.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport=8722.
Record-Route: <sip:195.37.77.99;ftag=a83eae01;lr=on>.
Record-Route: <sip:213.239.207.29;ftag=a83eae01;lr=on>.
Server: Sipura/SPA2000-3.1.2(NTb).
Content-Length: 0.
P-NAT-Check: YES.
.

#
U 2005/11/28 13:55:40.958703 213.239.207.29:5060 -> 83.136.33.3:8722
SIP/2.0 180 Ringing.
To: <sip:klaus3000 at iptel.org>;tag=5afee18c3cf2167ei1.
From: "klaus dk.labs.nic.at"<sip:klaus at dk.labs.nic.at>;tag=a83eae01.
Call-ID: 9843d9424930591d at a2xhdXNwYw...
CSeq: 1 INVITE.
Via: SIP/2.0/UDP 
83.136.33.3:8722;branch=z9hG4bK-d87543-5b192d3a37574d15-1--d87543-;rport=8722.
Record-Route: <sip:195.37.77.99;ftag=a83eae01;lr=on>.
Record-Route: <sip:213.239.207.29;ftag=a83eae01;lr=on>.
Server: Sipura/SPA2000-3.1.2(NTb).
Content-Length: 0.
P-NAT-Check: YES.
.

More information about the sr-users mailing list