[Serusers] CANCEL and ACK in 0.8.12 problems (noise)

I just loaded the 0.8.12 server on my lab linux 9.x box. Running postgres/2 current registrations, 123456(a)named.com and 9723937976(a)named.com. My configuration allows calls between these two no problem. I can hangup from either end with no problem. I am seeing a problem with a CANCEL message. If one end calls the other, and than CANCELs the communication before the other end ACKs, I get several messages CANCEL ACK CANCEL ACK ... I read the serusers list and see that Maxim and Andrea reported the same problem. I don't see the problem in my production configuration on 0.8.11. What can I do to make the CANCEL work? Here is my configuration: UA1 XTEN XPRO UA2 Cisco 7960 SER 0.8.12 configuration: -------------start--------------- route{ # initial sanity checks -- messages with # max_forwards==0, or excessively long requests if (!mf_process_maxfwd_header("10")) { sl_send_reply("483","Too Many Hops"); break; }; if (msg:len >= max_len ) { sl_send_reply("513", "Message too big"); break; }; # we record-route all messages -- to make sure that # subsequent messages will go through our proxy; that's # particularly good if upstream and downstream entities # use different transport protocol if (!method=="REGISTER") record_route(); # subsequent messages withing a dialog should take the # path determined by record-routing if (loose_route()) { # mark routing logic in request append_hf("P-hint: rr-enforced\r\n"); xlog("L_WARN", "LOOSE: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); setflag(1); setflag(2); route(1); break; }; if (!uri==myself) { # mark routing logic in request append_hf("P-hint: outbound\r\n"); route(1); break; }; # if the request is for other domain use UsrLoc # (in case, it does not work, use the following command # with proper names and addresses in it) if (uri==myself) { if (method=="REGISTER") { if (!www_authorize("named.com", "subscriber")) { www_challenge("named.com", "0"); break; }; save("location"); break; }; lookup("aliases"); if (!uri==myself) { append_hf("P-hint: outbound alias\r\n"); route(1); break; }; if (method=="INVITE") { if (!www_authorize("named.com", "subscriber")) { www_challenge("named.com", "0"); break; }; xlog("L_WARN", "INVITE: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); # if (lookup("location")) { route(1); break; }; if(uri=~"sip:[0-9]{10}@.*") { xlog("L_WARN", "10DIGIT: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); route(2); break; } xlog("L_WARN", "UNKNOWN: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); sl_send_reply("580", "Sorry"); break; }; if (method=="CANCEL") { xlog("L_WARN", "CANCEL: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); route(2); break; }; if (method=="BYE") { xlog("L_WARN", "BYE: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); route(2); break; }; if (method=="ACK") { xlog("L_WARN", "ACK: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); break; }; sl_send_reply("404", "Not Found"); break; }; xlog("L_WARN", "FAILATBOTTOM: %Ts call-id:%ci cseq:%ci contact:%ct from:%fu fromtag:%ft to:%tu totag:%tt method:%rm ruri:%ru messageid:%mi\n"); break; } route[1] { # send it out now; use stateful forwarding as it works reliably # even for UDP2TCP if (!t_relay()) { sl_reply_error(); }; } route[2] { consume_credentials(); rewritehostport("1.2.3.4:5060"); if(!t_relay()) { sl_reply_error(); break; }; } -------------------- here are the ngrep packets, from invite to duplicate CANCEL packets... # U 2003/11/22 13:10:32.356665 66.228.44.254:5060 -> 66.228.53.218:5060 INVITE sip:9723937976@66.228.53.218:5060 SIP/2.0. Max-Forwards: 10. Record-Route: <sip:9723937976@66.228.44.254;ftag=320951244;lr>. Via: SIP/2.0/UDP 66.228.44.254;branch=z9hG4bKe198.142630c1.0. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>. Contact: <sip:123456@66.228.53.216:5060>. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 INVITE. Authorization: Digest username="123456",realm="named.com",nonce="3fbfb5d42576afa9e9384c4f0f16427e46909d1d",response="7bf9fe190978d98811d56ddb60dded2f",uri="sip:9723937976@named.com". Content-Type: application/sdp. User-Agent: X-PRO build 1050. Content-Length: 322. . v=0. o=123456 485850365 485850365 IN IP4 66.228.53.216. s=X-PRO. c=IN IP4 66.228.53.216. t=0 0. m=audio 8000 RTP/AVP 0 8 3 4 98 97 101. a=rtpmap:0 pcmu/8000. a=rtpmap:8 pcma/8000. a=rtpmap:3 gsm/8000. a=rtpmap:4 G723/8000. a=rtpmap:98 iLBC/8000. a=rtpmap:97 speex/8000. a=rtpmap:101 telephone-event/8000. a=fmtp:101 0-15. # U 2003/11/22 13:10:32.619424 66.228.53.218:50560 -> 66.228.44.254:5060 SIP/2.0 100 Trying. Via: SIP/2.0/UDP 66.228.44.254;branch=z9hG4bKe198.142630c1.0,SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 INVITE. Server: CSCO/5. Contact: <sip:9723937976@66.228.53.218:5060>. Record-Route: <sip:9723937976@66.228.44.254;ftag=320951244;lr>. Content-Length: 0. . # U 2003/11/22 13:10:32.728062 66.228.53.218:50561 -> 66.228.44.254:5060 SIP/2.0 180 Ringing. Via: SIP/2.0/UDP 66.228.44.254;branch=z9hG4bKe198.142630c1.0,SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=000b5faab82400151dddd662-025452b6. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 INVITE. Server: CSCO/5. Contact: <sip:9723937976@66.228.53.218:5060>. Record-Route: <sip:9723937976@66.228.44.254;ftag=320951244;lr>. Content-Length: 0. . # U 2003/11/22 13:10:32.728480 66.228.44.254:5060 -> 66.228.53.216:5060 SIP/2.0 180 Ringing. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=000b5faab82400151dddd662-025452b6. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 INVITE. Server: CSCO/5. Contact: <sip:9723937976@66.228.53.218:5060>. Record-Route: <sip:9723937976@66.228.44.254;ftag=320951244;lr>. Content-Length: 0. . # U 2003/11/22 13:10:34.846506 66.228.53.216:5060 -> 66.228.44.254:5060 CANCEL sip:9723937976@named.com SIP/2.0. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>. Contact: <sip:123456@66.228.53.216:5060>. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 CANCEL. User-Agent: X-PRO build 1050. Content-Length: 0. . # U 2003/11/22 13:10:34.847662 66.228.44.254:5060 -> 66.228.53.218:5060 CANCEL sip:9723937976@66.228.53.218:5060 SIP/2.0. Max-Forwards: 10. Record-Route: <sip:9723937976@66.228.44.254;ftag=320951244;lr>. Via: SIP/2.0/UDP 66.228.44.254;branch=z9hG4bKe198.142630c1.0. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>. Contact: <sip:123456@66.228.53.216:5060>. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 CANCEL. User-Agent: X-PRO build 1050. Content-Length: 0. . # U 2003/11/22 13:10:34.847761 66.228.44.254:5060 -> 66.228.53.216:5060 SIP/2.0 200 cancelling. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-6763. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 CANCEL. Server: Sip EXpress router (0.8.12 (i386/linux)). Content-Length: 0. Warning: 392 66.228.44.254:5060 "Noisy feedback tells: pid=10695 req_src_ip=66.228.53.216 req_src_port=5060 in_uri=sip:9723937976@named.com out_uri=sip:9723937976@65.77.154.243:5060 via_cnt==1". . # U 2003/11/22 13:10:34.847806 66.228.44.254:5060 -> 66.228.53.216:5060 SIP/2.0 487 Request cancelled. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-6763. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 INVITE. Server: Sip EXpress router (0.8.12 (i386/linux)). Content-Length: 0. Warning: 392 66.228.44.254:5060 "Noisy feedback tells: pid=10695 req_src_ip=66.228.53.216 req_src_port=5060 in_uri=sip:9723937976@named.com out_uri=sip:9723937976@66.228.53.218:5060 via_cnt==1". . # U 2003/11/22 13:10:34.875833 66.228.53.216:5060 -> 66.228.44.254:5060 ACK sip:9723937976@named.com SIP/2.0. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-6763. Contact: <sip:123456@66.228.53.216:5060>. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 ACK. Max-Forwards: 70. Content-Length: 0. . # U 2003/11/22 13:10:34.906960 66.228.53.218:50562 -> 66.228.44.254:5060 SIP/2.0 200 OK. Via: SIP/2.0/UDP 66.228.44.254;branch=z9hG4bKe198.142630c1.0,SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=000b5faab82400151dddd662-025452b6. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 CANCEL. Server: CSCO/5. Content-Length: 0. . # U 2003/11/22 13:10:34.942865 66.228.53.218:50563 -> 66.228.44.254:5060 SIP/2.0 487 Request Cancelled. Via: SIP/2.0/UDP 66.228.44.254;branch=z9hG4bKe198.142630c1.0,SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=000b5faab82400151dddd662-025452b6. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 INVITE. Server: CSCO/5. Contact: <sip:9723937976@66.228.53.218:5060>. Record-Route: <sip:9723937976@66.228.44.254;ftag=320951244;lr>. Content-Length: 0. . # U 2003/11/22 13:10:34.943103 66.228.44.254:5060 -> 66.228.53.218:5060 ACK sip:9723937976@66.228.53.218:5060 SIP/2.0. Via: SIP/2.0/UDP 66.228.44.254;branch=z9hG4bKe198.142630c1.0. From: 123456 <sip:123456@named.com>;tag=320951244. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. To: <sip:9723937976@named.com>;tag=000b5faab82400151dddd662-025452b6. CSeq: 19721 ACK. User-Agent: Sip EXpress router(0.8.12 (i386/linux)). Content-Length: 0. . # U 2003/11/22 13:10:35.649964 66.228.44.254:5060 -> 66.228.53.216:5060 SIP/2.0 487 Request cancelled. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-6763. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 INVITE. Server: Sip EXpress router (0.8.12 (i386/linux)). Content-Length: 0. Warning: 392 66.228.44.254:5060 "Noisy feedback tells: pid=10695 req_src_ip=66.228.53.216 req_src_port=5060 in_uri=sip:9723937976@named.com out_uri=sip:9723937976@66.228.53.218:5060 via_cnt==1". . # U 2003/11/22 13:10:35.671936 66.228.53.216:5060 -> 66.228.44.254:5060 ACK sip:9723937976@named.com SIP/2.0. Via: SIP/2.0/UDP 66.228.53.216:5060. From: 123456 <sip:123456@named.com>;tag=320951244. To: <sip:9723937976@named.com>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-6763. Contact: <sip:123456@66.228.53.216:5060>. Call-ID: A7A5E0C3-865F-41A1-9CAD-EE1B104D7244(a)66.228.53.216. CSeq: 19721 ACK. Max-Forwards: 70. Content-Length: 0. . The 487CANCEL/ACK/CANCEL/ACK/CANCEL/ACK goes on and on until something eventually times out. Anybody have any ideas? The CANCEL works, but the excess chatter isn't wanted. Thanks, ---greg