My setup is such: 192.168.0.10 (initiating and closing UA) 192.168.0.52 (proxy) 192.168.0.90-91 (gateway and receiving UA)
I set up the BYE to use the lcr routing and it seemed to behave itself the 200 OK went through to start the call. Then the agent (i'm using sipp on both sides) sent back an ACK and a BYE. However, the odd thing is that the proxy sent the ACK over to the from_uri domain, in this case 192.168.0.51, instead of sending it off to the gateway/receiver at 0.91.
I looked in the logs and found that t_relay() had decided that there was no active transaction and so i'm guessing it tried to find the best place for it.. which was the from uri i'm guessing.
That I guess is okay.. I'll have to find a way to keep the requests forwarding to the proper gateway.. any input is appreciated.
Then the proxy went and did something really strange, it sent an INVITE to the receiving UA. According to ngrep, it was not relaying any messages from the initiating UA. It just sent it.. I have no idea why its doing that.. then things kinda go downhill from there.
Anyone know why it would be doing this? Help would be appreciated. (logs and route script below)
Rick Richardson
Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG: get_hdr_field: <To> [50]; uri=[sip:15095475551212@192.168.0.51:5060] Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG: to body [sut sip:15095475551212@192.168.0.51:5060] Mar 14 14:15:11 amnesiac /sbin/openser[7554]: get_hdr_field: cseq <Cseq>: <1> <ACK> Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG: get_hdr_body : content_length=0 Mar 14 14:15:11 amnesiac /sbin/openser[7554]: found end of header Mar 14 14:15:11 amnesiac /sbin/openser[7554]: parse_headers: flags=78 Mar 14 14:15:11 amnesiac /sbin/openser[7554]: t_lookup_request: start searching: hash=38888, isACK=1 Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG: proceeding to pre-RFC3261 transaction matching Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG: t_lookup_request: no transaction found Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG:tm:t_relay: forwarding ACK statelessly Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG: mk_proxy: doing DNS lookup... Mar 14 14:15:11 amnesiac /sbin/openser[7554]: check_via_address(192.168.0.10, 192.168.0.10, 0) Mar 14 14:15:11 amnesiac /sbin/openser[7554]: Sending: ACK sip:15095475551212@192.168.0.51:5060 SIP/2.0^M Record-Route: sip:192.168.0.52;ftag=1;lr=on^M Route: ^M Via: SIP/2.0/UDP 192.168.0.52;branch=0^M Via: SIP/2.0/UDP 192.168.0.10:5060^M From: sipp sip:15095479429@1Reseller.com:5060;tag=1^M To: sut sip:15095475551212@192.168.0.51:5060;tag=1^M Call-ID: 1.29663.192.168.0.10@sipp.call.id^M Cseq: 1 ACK^M Contact: sip:sipp@1Reseller.com:5060^M Max-Forwards: 70^M Subject: Performance Test^M Content-Length: 0^M ^M . Mar 14 14:15:11 amnesiac /sbin/openser[7554]: orig. len=365, new_len=452, proto=1 Mar 14 14:15:11 amnesiac /sbin/openser[7554]: DEBUG:destroy_avp_list: destroying list (nil)
# U 2006/03/14 14:15:11.213144 192.168.0.10:5060 -> 192.168.0.52:5060 INVITE sip:15095475551212@192.168.0.51:5060 SIP/2.0..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com;tag= 1..To: sut sip:15095475551212@192.168.0.51..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 1 INVITE..Contact: sip:sipp@1Reseller.co m:5060..Max-Forwards: 70..Subject: Performance Test..Content-Type: application/sdp..Content-Length: 136....v=0..o=user1 53655765 2353687 637 IN IP4 127.0.0.1..s=-..t=0 0..c=IN IP4 127.0.0.1..m=audio 10000 RTP/AVP 0..a=rtpmap:0 PCMU/8000.. # U 2006/03/14 14:15:11.268396 192.168.0.52:5060 -> 192.168.0.10:5060 SIP/2.0 100 trying -- your call is important to us..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com;tag=1 ..To: sut sip:15095475551212@192.168.0.51..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 1 INVITE..Server: OpenSer (1.0.0 (i386/li nux))..Content-Length: 0..Warning: 392 192.168.0.52:5060 "Noisy feedback tells: pid=7554 req_src_ip=192.168.0.10 req_src_port=5060 in_u ri=sip:15095475551212@192.168.0.51:5060 out_uri=sip:15095475551212@192.168.0.91;transport=udp via_cnt==1".... # U 2006/03/14 14:15:11.274677 192.168.0.52:5060 -> 192.168.0.91:5060 INVITE sip:15095475551212@192.168.0.91;transport=udp SIP/2.0..Record-Route: sip:192.168.0.52;ftag=1;lr=on..Via: SIP/2.0/UDP 192.168.0. 52;branch=z9hG4bK8e79.dc95dbe1.0..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com;tag=1..To: sut <sip:150 95475551212@192.168.0.51>..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 1 INVITE..Contact: sip:sipp@1Reseller.com:5060..Max-Forward s: 70..Subject: Performance Test..Content-Type: application/sdp..Content-Length: 136....v=0..o=user1 53655765 2353687637 IN IP4 127.0.0. 1..s=-..t=0 0..c=IN IP4 127.0.0.1..m=audio 10000 RTP/AVP 0..a=rtpmap:0 PCMU/8000.. # U 2006/03/14 14:15:11.277668 192.168.0.89:5060 -> 192.168.0.52:5060 SIP/2.0 180 Ringing..Route: sip:sipp@1Reseller.com:5060..Via: SIP/2.0/UDP 192.168.0.52;branch=z9hG4bK8e79.dc95dbe1.0.Via: SIP/2.0/UDP 1 92.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com;tag=1..To: sut sip:15095475551212@192.168.0.51;tag=1..Call-ID: 1.29663.19 2.168.0.10@sipp.call.id..Contact: sip:192.168.0.91:5060;transport=UDP..Content-Length: 0.... # U 2006/03/14 14:15:11.277707 192.168.0.89:5060 -> 192.168.0.52:5060 SIP/2.0 200 OK..Route: sip:sipp@1Reseller.com:5060..Via: SIP/2.0/UDP 192.168.0.52;branch=z9hG4bK8e79.dc95dbe1.0.Via: SIP/2.0/UDP 192.16 8.0.10:5060..From: sipp sip:15095479429@1Reseller.com;tag=1..To: sut sip:15095475551212@192.168.0.51;tag=1..Call-ID: 1.29663.192.168 .0.10@sipp.call.id..Contact: sip:192.168.0.91:5060;transport=UDP..Content-Type: application/sdp..Content-Length: 136....v=0..o=user1 5 3655765 2353687637 IN IP4 127.0.0.1..s=-..c=IN IP4 127.0.0.1..t=0 0..m=audio 10000 RTP/AVP 0..a=rtpmap:0 PCMU/8000.. # U 2006/03/14 14:15:11.343159 192.168.0.52:5060 -> 192.168.0.10:5060 SIP/2.0 180 Ringing..Route: sip:sipp@1Reseller.com:5060..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com ;tag=1..To: sut sip:15095475551212@192.168.0.51;tag=1..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Contact: <sip:192.168.0.91:5060;tra nsport=UDP>..Content-Length: 0.... # U 2006/03/14 14:15:11.345406 192.168.0.52:5060 -> 192.168.0.10:5060 SIP/2.0 200 OK..Route: sip:sipp@1Reseller.com:5060..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com;tag= 1..To: sut sip:15095475551212@192.168.0.51;tag=1..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Contact: <sip:192.168.0.91:5060;transpor t=UDP>..Content-Type: application/sdp..Content-Length: 136....v=0..o=user1 53655765 2353687637 IN IP4 127.0.0.1..s=-..c=IN IP4 127 .0.0.1..t=0 0..m=audio 10000 RTP/AVP 0..a=rtpmap:0 PCMU/8000.. # U 2006/03/14 14:15:11.345985 192.168.0.10:5060 -> 192.168.0.52:5060 ACK sip:15095475551212@192.168.0.51:5060 SIP/2.0..Route: ..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp <sip:15095479429@1Reseller.com :5060>;tag=1..To: sut sip:15095475551212@192.168.0.51:5060;tag=1..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 1 ACK..Contact: si p:sipp@1Reseller.com:5060..Max-Forwards: 70..Subject: Performance Test..Content-Length: 0.... # U 2006/03/14 14:15:11.346006 192.168.0.10:5060 -> 192.168.0.52:5060 BYE sip:15095475551212@192.168.0.51:5060 SIP/2.0..Route: ..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp <sip:15095479429@1Reseller.com :5060>;tag=1..To: sut sip:15095475551212@192.168.0.51:5060;tag=1..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 2 BYE..Contact: si p:sipp@1Reseller.com:5060..Max-Forwards: 70..Subject: Performance Test..Content-Length: 0.... # U 2006/03/14 14:15:11.459551 192.168.0.52:5060 -> 192.168.0.51:5060 ACK sip:15095475551212@192.168.0.51:5060 SIP/2.0..Record-Route: sip:192.168.0.52;ftag=1;lr=on..Route: ..Via: SIP/2.0/UDP 192.168.0.52; branch=0..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com:5060;tag=1..To: sut <sip:15095475551212@192.168 .0.51:5060>;tag=1..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 1 ACK..Contact: sip:sipp@1Reseller.com:5060..Max-Forwards: 70..Subj ect: Performance Test..Content-Length: 0.... # U 2006/03/14 14:15:11.482459 192.168.0.52:5060 -> 192.168.0.91:5060 BYE sip:15095475551212@192.168.0.91;transport=udp SIP/2.0..Record-Route: sip:192.168.0.52;ftag=1;lr=on..Route: ..Via: SIP/2.0/UDP 192. 168.0.52;branch=z9hG4bK5e79.b6010d86.0..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com:5060;tag=1..To: s ut sip:15095475551212@192.168.0.51:5060;tag=1..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 2 BYE..Contact: sip:sipp@1Reseller.co m:5060..Max-Forwards: 70..Subject: Performance Test..Content-Length: 0.... # U 2006/03/14 14:15:11.564502 192.168.0.52:5060 -> 192.168.0.91:5060 INVITE sip:15095475551212@192.168.0.91;transport=udp SIP/2.0..Record-Route: sip:192.168.0.52;ftag=1;lr=on..Via: SIP/2.0/UDP 192.168.0. 52;branch=z9hG4bK8e79.dc95dbe1.0..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com;tag=1..To: sut <sip:150 95475551212@192.168.0.51>..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 1 INVITE..Contact: sip:sipp@1Reseller.com:5060..Max-Forward s: 70..Subject: Performance Test..Content-Type: application/sdp..Content-Length: 136....v=0..o=user1 53655765 2353687637 IN IP4 127.0.0. 1..s=-..t=0 0..c=IN IP4 127.0.0.1..m=audio 10000 RTP/AVP 0..a=rtpmap:0 PCMU/8000.. # U 2006/03/14 14:15:11.564701 192.168.0.52:5060 -> 192.168.0.91:5060 BYE sip:15095475551212@192.168.0.91;transport=udp SIP/2.0..Record-Route: sip:192.168.0.52;ftag=1;lr=on..Route: ..Via: SIP/2.0/UDP 192. 168.0.52;branch=z9hG4bK5e79.b6010d86.0..Via: SIP/2.0/UDP 192.168.0.10:5060..From: sipp sip:15095479429@1Reseller.com:5060;tag=1..To: s ut sip:15095475551212@192.168.0.51:5060;tag=1..Call-ID: 1.29663.192.168.0.10@sipp.call.id..Cseq: 2 BYE..Contact: sip:sipp@1Reseller.co m:5060..Max-Forwards: 70..Subject: Performance Test..Content-Length: 0....
########################################## debug=9 fork=yes log_stderror=no
listen=192.168.0.52 port=5060 children=4
log_stderror=no # (cmd line: -E) log_facility=LOG_LOCAL0
dns=no rev_dns=no fifo="/tmp/ser_fifo" fifo_db_url="mysql://serusr:thisisfun@192.168.0.54/ser"
loadmodule "//lib/openser/modules/mysql.so" loadmodule "//lib/openser/modules/sl.so" loadmodule "//lib/openser/modules/tm.so" loadmodule "//lib/openser/modules/rr.so" loadmodule "//lib/openser/modules/maxfwd.so" loadmodule "//lib/openser/modules/usrloc.so" loadmodule "//lib/openser/modules/auth.so" loadmodule "//lib/openser/modules/auth_db.so" loadmodule "//lib/openser/modules/registrar.so" loadmodule "//lib/openser/modules/uri.so" loadmodule "//lib/openser/modules/uri_db.so" #loadmodule "//lib/openser/modules/mediaproxy.so" loadmodule "//lib/openser/modules/textops.so" loadmodule "//lib/openser/modules/avpops.so" #loadmodule "//lib/openser/modules/domain.so" loadmodule "//lib/openser/modules/reseller.so" loadmodule "//lib/openser/modules/acc.so" loadmodule "//lib/openser/modules/lcr.so" loadmodule "//lib/openser/modules/xlog.so"
modparam("auth_db|reseller|lcr|uri_db|usrloc|acc", "db_url", "mysql://serusr:thisisfun@192.168.0.54/ser")
modparam("auth_db", "calculate_ha1", 1) modparam("auth_db", "password_column", "password")
modparam("usrloc", "db_mode", 2)
modparam("rr", "enable_full_lr", 1)
modparam("tm", "fr_inv_timer", 27) modparam("tm", "fr_inv_timer_avp", "inv_timeout")
# -- acc params # modparam("acc", "db_flag", 1) modparam("acc", "failed_transaction_flag", 1) modparam("acc", "db_missed_flag", 1) modparam("acc", "report_cancels", 1) modparam("acc", "multi_leg_enabled", 1) modparam("acc", "src_leg_avp_id", 110) modparam("acc", "dst_leg_avp_id", 110) modparam("acc", "acc_dst_leg_column", "dst_leg") modparam("acc", "acc_src_leg_column", "src_leg")
route { xlog("L_DBG", "TRACE: Message received."); # ----------------------------------------------------------------- # Record Route Section # ----------------------------------------------------------------- if (method != "REGISTER") { record_route(); };
xlog("L_DBG", "TRACE: Record routing."); # ----------------------------------------------------------------- # Loose Route Section # ----------------------------------------------------------------- if (loose_route()) {
route(1); return; }; xlog("L_DBG", "TRACE: Done with loose routing."); if (method=="CANCEL") { route(1); return; } else if (method=="INVITE") { route(3); return; } else if (method=="BYE") { route(3); return; }
route(1); }
route[1] {
# ----------------------------------------------------------------- # Default Message Handler # ----------------------------------------------------------------- xlog("L_DBG","TRACE: Entered default message handler");
if (!t_relay()) { sl_reply_error(); }; }
route[3] {
# ----------------------------------------------------------------- # INVITE Message Handler # ----------------------------------------------------------------- xlog("L_DBG","TRACE: Entered INVITE handler."); if (uri=~"^sip:1[0-9]{10}@") { strip(1); };
xlog("L_DBG","TRACE: Message not addressed to us.");
# it should check to see if the number is managed locally.. # if not, send to pstn # if (from_gw()) { xlog("L_DBG","TRACE: Message is from a gateway.") ; route(6); return; }; };
route(5);
route(1); } route[5] {
# ----------------------------------------------------------------- # PSTN Handler # ----------------------------------------------------------------- xlog("L_DBG","TRACE: Entered PSTN handler."); if (!load_gws()) { sl_send_reply("500", "Server Internal Error - Cannot load gateways"); return; }; xlog("L_DBG","TRACE: Loading gateways"); if (!next_gw()) { xlog("L_DBG","TRACE: Couldn't find a gateway."); sl_send_reply("503", "Service not available - No gateways"); return; };
t_on_failure("1"); avp_write("i:45", "inv_timeout"); } route[6] {
# ------------------------------------------------------------------ # Local Number Handler # ------------------------------------------------------------------
if (!fwd_usr_ip()){ sl_send_reply("503", "Wrong number"); } forward(uri:host, uri:port); }
failure_route[1] {
next_gw(); t_relay(); }