[Users] CANCEL problem
Bogdan-Andrei Iancu
bogdan at voice-system.ro
Mon Nov 28 21:41:16 CET 2005
Hi Klaus,
this is a quite interesting case .....interesting because is tricky to
detected it. What happens is that the CANCEL hits after the INVITE
transaction is build but before its branches to be forwarded. So
t_check_trans() sees the INVITE transaction, but there is nothing to be
cancel as nothing was set yet out....
The problem is how to make difference between a transaction that doesn't
have a branch at all and one which has no branch because is still under
processing....first though...an internal flag -> transaction still under
processing....
but not sure....it may screw other thing ...like failure_route
processing....
regards,
bogdan
Klaus Darilion wrote:
> 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.
> .
>
> _______________________________________________
> Users mailing list
> Users at openser.org
> http://openser.org/cgi-bin/mailman/listinfo/users
>
More information about the sr-users
mailing list