We had a very strange situation last night with our proxy (running OpenSer 1.3).
We received an INVITE from a UA. This was then cancelled by the UA. This then resulted in OpenSER generating 40000+ cancel messages with our server talking to itself i.e. the toip and fromip are the same in the sip_trace table.
Incidentally, this proxy processes thousands of calls a day so I'm not sure what gave rise to this problem but I guess a particular set of events has highlighted a bug in my config file.
The other very curious thing is that somehow our other SIP proxy gets in on the act. Cancel message 40000-odd looks like this: CANCEL sip:031234567@domain.com SIP/2.0 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.5d037b85.0 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.2d037b85.0 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.67037b85.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.20037b85.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.8ff27b85.0 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.e16dcb3.0 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.516dcb3.0 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.3c5dcb3.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.05e27b85.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.b4e27b85.0 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.365dcb3.0 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.52e27b85.0 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.be4dcb3.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.33c27b85.1 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.2d3dcb3.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.84a27b85.1 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.da2dcb3.1 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.002dcb3.1 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.561dcb3.1 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.111dcb3.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.4b627b85.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.ca627b85.0 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.5a627b85.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.1a627b85.0 Via: SIP/2.0/UDP 147.202.001.002;branch=z9hG4bK223e.ed0dcb3.0 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.d9627b85.1 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.c9627b85.0 Via: SIP/2.0/UDP 147.202.001.001;branch=z9hG4bK223e.b9627b85.0 Via: SIP/2.0/UDP 210.48.001.001:5060;branch=z9hG4bK519fe576;rport=5060 From: "Customer" sip:12345678@domain.com;tag=as02736614 To: sip:031234567@domain.com Contact: sip:6496306317@210.48.001.001 Call-ID: 771d537932ab79225888a341190691c2@domain.com CSeq: 102 CANCEL User-Agent: Asterisk PBX Max-Forwards: 41 Content-Length: 0
I have pasted what I think are the relevant parts from the config file. Could anyone advise where the problem might be?
route {
# ----------------------------------------------------------------- ### SipTrace. # ----------------------------------------------------------------- if ! is_method("OPTIONS|SUBSCRIBE|NOTIFY") { sip_trace(); setflag(28); }
# ----------------------------------------------------------------- # Sanity Check Section # ----------------------------------------------------------------- if (!mf_process_maxfwd_header("10")) { sl_send_reply("483", "Too Many Hops"); return; };
if (msg:len > max_len) { sl_send_reply("513", "Message Overflow"); return; };
# ----------------------------------------------------------------- # Record Route Section # ----------------------------------------------------------------- #If it's an INVITE & client is NATed, #xlog("welcome"); if (method=="INVITE" && client_nat_test("3")) { #Record-route and specify the record-route header explicitly record_route_preset("147.202.001.001:5060;nat=yes"); # insert IP address xlog("invite and nated so record_route_preset"); #If not Nated and not REGISTER then normal record-route } else if (method!="REGISTER") { record_route(); xlog("not register and not nated so record_route"); };
# ----------------------------------------------------------------- # Call Tear Down Section # ----------------------------------------------------------------- if (method=="BYE" || method=="CANCEL") { setflag(1); #call end_media_session in case we're proxying media end_media_session(); };
# ----------------------------------------------------------------- # Loose Route Section # ----------------------------------------------------------------- if (loose_route()) { #Ensure we are dealing with a re-INVITE. Only connected calls have tag= #entry in the To header. So if it's loose routed and doesn't have totag #and it's an invite or reply then something's wrong xlog("loose_route"); if ((method=="INVITE" || method=="REFER") && !has_totag()) { sl_send_reply("403", "Forbidden"); xlog("403 in lr"); return; };
if (method=="INVITE") {
if (!allow_trusted()) { xlog("!allow_ trusted for r-uri <$ru>"); if (!proxy_authorize("","subscriber")) { proxy_challenge("domain.com","1"); return; } else if (!check_from()) { sl_send_reply("403", "Use From=ID"); return; }; consume_credentials(); };
#check client is nated or that we've already identified it's nated xlog("Re-invite. rs $rs si $si rm $rm ru $ru tu $tu fu $fu fd $fd rr $rr"); if (client_nat_test("3") || search("^Route:.*;nat=yes")) { setbflag(6); xlog("Recipient is nated so setbflag 6 and use mediaproxy: r-uri <$ru>"); use_media_proxy(); };
};
route(1); return; };
# ----------------------------------------------------------------- # Call Type Processing Section # ----------------------------------------------------------------- # Processes out-of-dialogue messages i.e. # 1. new dialogue # 2. message not destined for us (but we are relaying or proxying) xlog("Call Type Processing Section"); if (!is_uri_host_local()) { xlog("!is_uri_host_local"); if (is_from_local() || allow_trusted() ) { xlog("is_from_local() || allow_trusted()"); route(5); route(1); } else { sl_send_reply("403", "Forbidden"); xlog("403 in call type processing. rs $rs si $si rm $rm ru $ru tu $tu fu $fu fd $fd rr $rr"); }; return; };
sip_trace();
if (method=="ACK") { route(1); return; } else if (method=="CANCEL") { route(1); return; } else if (method=="INVITE") { route(3); return; } else if (method=="REGISTER") { route(2); return; } else if (method=="SUBSCRIBE") { route(7); return; };
route[1] {
# ----------------------------------------------------------------- # Default Message Handler # -----------------------------------------------------------------
xlog("hit route(1). rs $rs si $si rm $rm ru $ru tu $tu fu $fu rr $rr"); #Call reply_route(1) to intercept response messages heading to the client t_on_reply("1"); #Try to relay the message to its destination if (!t_relay()) { #If it can't and it's an INVITE or ACK end the media proxying log(1,"route[1] !t_relay"); if (method=="INVITE" || method=="ACK") { end_media_session(); };
sl_reply_error(); } else { log(1,"route[1] t_relay"); }; }
onreply_route[1]
#Handles message that are returned to the sender i.e. response to caller's original request { xlog("hit onreply_route(1). rs $rs si $si rm $rm ru $ru tu $tu fu $fu rr $rr");
if (isbflagset(6)) { xlog("flag(6) is set for $fu . We're currently in onreply_route(1)"); }; if (isbflagset(7)) { xlog("flag(7) is set for $fu . We're currently in onreply_route(1)"); }; if (status=~"(180)|(183)|2[0-9][0-9]") { xlog("status matches for $fu . We're currently in onreply_route(1)"); }; if ((isbflagset(6) || isbflagset(7)) && (status=~"(180)|(183)|2[0-9][0-9]")) {
#Check the SDP payload length. Assume if we have something we can call mediaproxy if (!search("^Content-Length:[ ]*0")) { log(1,"using media proxy in onreply_route(1)"); use_media_proxy(); }; };
if (client_nat_test("1")) { fix_nated_contact(); }; }
Any advice appreciated.
Cameron
El Jueves, 8 de Octubre de 2009, CSB escribió:
We received an INVITE from a UA. This was then cancelled by the UA. This then resulted in OpenSER generating 40000+ cancel messages with our server talking to itself i.e. the toip and fromip are the same in the sip_trace table.
Can you paste a flow capture of the INVITE and CANCEL arriving to OpenSer. Isn't also a loop for the INVITE?
El Jueves, 8 de Octubre de 2009, CSB escribió:
We received an INVITE from a UA. This was then cancelled by the UA.
This
then resulted in OpenSER generating 40000+ cancel messages with our
server
talking to itself i.e. the toip and fromip are the same in the
sip_trace
table.
Can you paste a flow capture of the INVITE and CANCEL arriving to OpenSer.
Thanks
There is an extract from sip_trace at http://pastebin.com/m1365447d. I hope that gives you a bit more information. The format is not great I'm sorry.
Isn't also a loop for the INVITE?
Doesn't look like it to me.
On Thursday 08 October 2009 22:54:24 CSB wrote:
CANCEL sip:031234567@domain.com SIP/2.0 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.002;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614 Record-Route: sip:147.202.001.001;lr=on;ftag=as02736614
[...] It's obvious that you are looping over yourself. Look more about this inline ...
I have pasted what I think are the relevant parts from the config file. Could anyone advise where the problem might be?
route {
# ----------------------------------------------------------------- ### SipTrace. # ----------------------------------------------------------------- if ! is_method("OPTIONS|SUBSCRIBE|NOTIFY") { sip_trace(); setflag(28); } # ----------------------------------------------------------------- # Sanity Check Section # ----------------------------------------------------------------- if (!mf_process_maxfwd_header("10")) { sl_send_reply("483", "Too Many Hops"); return; }; if (msg:len > max_len) { sl_send_reply("513", "Message Overflow"); return; }; # ----------------------------------------------------------------- # Record Route Section # ----------------------------------------------------------------- #If it's an INVITE & client is NATed, #xlog("welcome"); if (method=="INVITE" && client_nat_test("3")) { #Record-route and specify the record-route headerexplicitly record_route_preset("147.202.001.001:5060;nat=yes"); # insert IP address
^^^^^^^ This is one of your biggest errors. 1º - Don't add that IP manualy, let the record_route function to decide witch IP it's should add. 2º - You are adding a record-route header TO EVERY INVITE you receive, no matter if a "first one" in a dialog or a reinvite, or a retrasmition, or ... so you will allways end with a loop.
xlog("invite and nated so record_route_preset"); #If not Nated and not REGISTER then normal record-route } else if (method!="REGISTER") { record_route(); xlog("not register and not nated so record_route"); }; # ----------------------------------------------------------------- # Call Tear Down Section # ----------------------------------------------------------------- if (method=="BYE" || method=="CANCEL") { setflag(1); #call end_media_session in case we're proxying media end_media_session();
^^^^^ So .. directly .. without checking anything more ... close mediasessions ... you are brave !!! ;-)
}; # ----------------------------------------------------------------- # Loose Route Section # ----------------------------------------------------------------- if (loose_route()) { #Ensure we are dealing with a re-INVITE. Only connectedcalls have tag= #entry in the To header. So if it's loose routed and doesn't have totag #and it's an invite or reply then something's wrong xlog("loose_route"); if ((method=="INVITE" || method=="REFER") && !has_totag()) { sl_send_reply("403", "Forbidden"); xlog("403 in lr"); return; };
if (method=="INVITE") { if (!allow_trusted()) { xlog("!allow_ trusted for r-uri <$ru>"); if (!proxy_authorize("","subscriber")) { proxy_challenge("domain.com","1"); return; } else if (!check_from()) { sl_send_reply("403", "UseFrom=ID"); return; }; consume_credentials(); };
#check client is nated or that we've alreadyidentified it's nated xlog("Re-invite. rs $rs si $si rm $rm ru $ru tu $tu fu $fu fd $fd rr $rr"); if (client_nat_test("3") || search("^Route:.*;nat=yes")) { setbflag(6); xlog("Recipient is nated so setbflag 6 and use mediaproxy: r-uri <$ru>"); use_media_proxy();
^^^^^^^ So for re-invites you take into account to do mediaproxy handling ... but not for first-time INVITE's ... quite extrange ... ;-)
}; }; route(1); return; }; # ----------------------------------------------------------------- # Call Type Processing Section # ----------------------------------------------------------------- # Processes out-of-dialogue messages i.e. # 1. new dialogue # 2. message not destined for us (but we are relaying or proxying) xlog("Call Type Processing Section"); if (!is_uri_host_local()) { xlog("!is_uri_host_local"); if (is_from_local() || allow_trusted() ) { xlog("is_from_local() || allow_trusted()"); route(5); route(1); } else { sl_send_reply("403", "Forbidden"); xlog("403 in call type processing. rs $rs si $si rm$rm ru $ru tu $tu fu $fu fd $fd rr $rr"); }; return; };
sip_trace(); if (method=="ACK") { route(1); return; } else if (method=="CANCEL") { route(1);
^^^^^ Uff ... another point to having problems ... look ahead.
return; } else if (method=="INVITE") { route(3); return; } else if (method=="REGISTER") { route(2); return; } else if (method=="SUBSCRIBE") { route(7); return; };route[1] {
# ----------------------------------------------------------------- # Default Message Handler # ----------------------------------------------------------------- xlog("hit route(1). rs $rs si $si rm $rm ru $ru tu $tu fu $fu rr$rr"); #Call reply_route(1) to intercept response messages heading to the client t_on_reply("1"); #Try to relay the message to its destination if (!t_relay()) { #If it can't and it's an INVITE or ACK end the media proxying log(1,"route[1] !t_relay"); if (method=="INVITE" || method=="ACK") { end_media_session();
^^^^^^ For and ACK ?? .. sure ??? .. ACK will never arrive here, also INVITE should never arrive here, because you are sending them to route 3 from the main route block.
}; sl_reply_error(); } else { log(1,"route[1] t_relay"); };
^^^^^ So you route CANCEL to route(1) ... but you don't test if that CANCEL belongs to an stablished NATED dialog and close mediaproxy session ...
}
onreply_route[1]
#Handles message that are returned to the sender i.e. response to caller's original request { xlog("hit onreply_route(1). rs $rs si $si rm $rm ru $ru tu $tu fu $fu rr $rr");
if (isbflagset(6)) { xlog("flag(6) is set for $fu . We're currently inonreply_route(1)");
^^^^^^ So a reply to a NATED Request and you don't do anything ... quite good ...
}; if (isbflagset(7)) { xlog("flag(7) is set for $fu . We're currently inonreply_route(1)"); };
if (status=~"(180)|(183)|2[0-9][0-9]") { xlog("status matches for $fu . We're currently inonreply_route(1)"); }; if ((isbflagset(6) || isbflagset(7)) && (status=~"(180)|(183)|2[0-9][0-9]")) {
#Check the SDP payload length. Assume if we have somethingwe can call mediaproxy if (!search("^Content-Length:[ ]*0")) { log(1,"using media proxy in onreply_route(1)"); use_media_proxy(); }; };
if (client_nat_test("1")) { fix_nated_contact(); };
^^^^^ This route-block it's a complete mess ..
}
Any advice appreciated.
I advice you that your confing should be rewritten, almost from scracht ... take a look at the doc examples, because you are doing things at wild west way ..
-
CSB -
Iñaki Baz Castillo -
Raúl Alexis Betancor Santana