[Users] CANCEL problem

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@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@iptel.org] openser[3670]: DEBUG: to body [<sip:klaus3000@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@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@83.136.33.3:8722>. To: <sip:klaus3000@iptel.org>. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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@iptel.org>. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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@iptel.org out_uri=sip:klaus3000@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@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@iptel.org>. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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@iptel.org>;tag=fa997f81440371de71ab448ebdb9af56-3f94. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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@iptel.org out_uri=sip:klaus3000@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@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@83.136.33.3:8722>. To: <sip:klaus3000@iptel.org>. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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@iptel.org>. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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@iptel.org out_uri=sip:klaus3000@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@iptel.org>;tag=5afee18c3cf2167ei1. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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@iptel.org>;tag=5afee18c3cf2167ei1. From: "klaus dk.labs.nic.at"<sip:klaus@dk.labs.nic.at>;tag=a83eae01. Call-ID: 9843d9424930591d@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. .