[Serusers] One failure_route problem remaining

Guys, First, thanks again to those who have offered advice. I have re-started building from the ONsip.org rtpproxy example config and have everything working properly except one thing. In the interest of being thorough, I kept a log of what I changed and why: - Tested REGISTER, works OK. - Calls between UAs initially failed when proxy_authorize in route[3] was called. Disabled proxy_authorize checks. Works OK. (Need to revisit this one for security. Can anyone point out the problem?) - Implemented failure_route for voicemail on timeout. Timeout calls from UAs work fine to VM via Asterisk. - Implemented 7 digit dial perl script and added second lookup. No problems. Added NPANXX route lookup script in route[3]. No problems. - Implemented "Your call cannot be completed as dialed" via Asterisk server by replacing sl_send_reply 404 in route[3] with route(7). No problems. - Initially was unable to dial voicemail access number from UA. It would connect to Asterisk server but not have audio. Call would drop. Fixed by adding this to route[1]: # NAT Fix if (method=="INVITE" && nat_uac_test("19")) { force_rport(); fix_nated_contact(); force_rtp_proxy(); }; - Voicemail access is now OK. - UA timeout calls to voicemail now fail. Debug on Asterisk looks like the contact is being fixed twice. Added flag(9) to make sure NAT fix only happens once. UA timeout calls now go to voicemail properly. - I notice a lot of "Warning: sl_send_reply: I won't send a reply for ACK!!" but don't know if this is significant or not. From what I've read it sounds like ACKs are getting an sl_reply rather than being t_relayed but I didn't really modify anything related ... ? Now, the biggest problem seems to be calls coming from the inbound SIP gateway aren't being handled properly on timeout. (Calls from the inbound SIP gateway work fine to UAs.) This very well may be the fault of the other equipment, but it's nothing we can debug directly so I want to make sure there's nothing else wrong. Keep in mind, the inbound SIP gateway CAN communicate with the Asterisk server by dialing a DID that is directed to voicemail. I thought it might be some kind of routing problem between those boxes, but this would seem to disprove that. I'm going to include the abbreviated ngrep dump from the SER machine and then the ser.cfg file. Thanks again for the help thus far and in advance for any assistance on this. -Corey Here is an IP legend: xxx.xxx.xxx.7 - Inbound SIP Gateway xxx.xxx.xxx.36 - SER Server xxx.xxx.xxx.80 - Asterisk Server 216.xxx.ua.207 - NATed UA public IP ** NGREP DUMP FROM SER SERVER # U xxx.xxx.xxx.7:5060 -> xxx.xxx.xxx.36:5060 INVITE sip:5414362504@xxx.xxx.xxx.36:5060 SIP/2.0..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-Xvn755Ml3U1j41B # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 100 trying -- your call is important to us..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-Xvn755Ml3U1j41 # U xxx.xxx.xxx.36:5060 -> 216.xxx.ua.207:7565 INVITE sip:5414362504@216.xxx.ua.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=Xvn755Ml3U1j41B-IPTrunk-67-17-23at # U 216.xxx.ua.207:7565 -> xxx.xxx.xxx.36:5060 SIP/2.0 100 Trying..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.0,SIP/2.0/UDP xxx.xxx.xxx.7:5060;rport=5060 # U 216.xxx.ua.207:7565 -> xxx.xxx.xxx.36:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.0,SIP/2.0/UDP xxx.xxx.xxx.7:5060;rport=506 # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;rport=5060;branch=z9hG4bK-00101-Xvn755Ml3U1j41B-0..From: sip:61087 # # *** Call is diverted to Asterisk server here. # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.80:5060 INVITE sip:5414362504@xxx.xxx.xxx.80:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=Xvn755Ml3U1j41B-IPTrunk-67-17-23a # U xxx.xxx.xxx.36:5060 -> 216.xxx.ua.207:7565 CANCEL sip:5414362504@216.xxx.ua.207:5060 SIP/2.0..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.0..From: sip: # U xxx.xxx.xxx.80:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 100 Trying..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.1..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;bran # U 216.xxx.ua.207:7565 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.0..From: sip:6108712381@xxx.xxx.xxx.7:5060;tag= # U 216.xxx.ua.207:7565 -> xxx.xxx.xxx.36:5060 SIP/2.0 487 Request Cancelled..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.0,SIP/2.0/UDP xxx.xxx.xxx.7:5060 # U xxx.xxx.xxx.36:5060 -> 216.xxx.ua.207:7565 ACK sip:5414362504@216.xxx.ua.207:5060 SIP/2.0..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.0..From: sip:610 # U xxx.xxx.xxx.36:5060 -> 216.xxx.ua.207:5060 .... # U xxx.xxx.xxx.36:5060 -> 216.xxx.ua.207:7565 .... # U xxx.xxx.xxx.80:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.1..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-Xvn755Ml3U1j41B-0..Record-Route: <sip:209.216.160. # U xxx.xxx.xxx.80:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.1..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-Xvn755Ml3U1j41B-0..Record-Route: <sip:209.216.160. # # Several OKs seem to be going through here... U xxx.xxx.xxx.80:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.1..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-Xvn755Ml3U1j41B-0..Record-Route: <sip:209.216.160. # U xxx.xxx.xxx.80:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe432.bd7822d3.1..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-Xvn755Ml3U1j41B-0..Record-Route: <sip:209.216.160. # # Call is dropped by now. ** Asterisk console sip debug <-- SIP read from xxx.xxx.xxx.36:5060: INVITE sip:5414362504@xxx.xxx.xxx.80:5060 SIP/2.0 Record-Route: <sip:xxx.xxx.xxx.36;ftag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7;lr=on> Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKef17.c97ef7d2.1 Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;rport=5060;branch=z9hG4bK-00101-AJn351hl3U1H58O-0 Max-Forwards: 5 From: sip:6108712381@xxx.xxx.xxx.7:5060;tag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7 To: sip:5414362504@xxx.xxx.xxx.36:5060 Call-ID: AJn351hl3U1H58O(a)xxx.xxx.xxx.7 CSeq: 101 INVITE Remote-Party-Id: <sip:6108712381@xxx.xxx.xxx.7:5060>;party=calling;privacy=off;id-type=subscriber Expires: 180 Allow: INVITE,CANCEL,BYE,ACK Contact: sip:xxx.xxx.xxx.7:5060 User-Agent: Tekelec-7000/r4.0 Content-Type: application/sdp Content-Length: 149 P-hint: OFFLINE VOICEMAIL v=0 o=- 1 1 IN IP4 xxx.xxx.xxx.7 s= c=IN IP4 xxx.xxx.xxx.36 t=0 0 m=audio 35842 RTP/AVP 0 a=ptime:20 a=rtpmap:0 PCMU/8000 a=nortpproxy:yes --- (17 headers 9 lines)--- Using INVITE request as basis request - AJn351hl3U1H58O(a)xxx.xxx.xxx.7 Sending to xxx.xxx.xxx.36 : 5060 (non-NAT) Found no matching peer or user for 'xxx.xxx.xxx.36:5060' Found RTP audio format 0 Peer audio RTP is at port xxx.xxx.xxx.36:35842 Found description format PCMU Capabilities: us - 0x40e (gsm|ulaw|alaw|ilbc), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Looking for 5414362504 in sip list_route: hop: <sip:xxx.xxx.xxx.36;ftag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7;lr=on> list_route: hop: <sip:xxx.xxx.xxx.7:5060> Transmitting (no NAT) to xxx.xxx.xxx.36:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKef17.c97ef7d2.1 Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-AJn351hl3U1H58O-0 From: sip:6108712381@xxx.xxx.xxx.7:5060;tag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7 To: sip:5414362504@xxx.xxx.xxx.36:5060 all-ID: AJn351hl3U1H58O(a)xxx.xxx.xxx.7 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Contact: <sip:5414362504@xxx.xxx.xxx.80> Content-Length: 0 --- -- Executing Wait("SIP/5060-b7d05f68", "1") in new stack -- Executing VoiceMail("SIP/5060-b7d05f68", "5414362504@sip") in new stack We're at xxx.xxx.xxx.80 port 14018 Answering with preferred capability 0x4 (ulaw) Answering with preferred capability 0x2 (gsm) Answering with preferred capability 0x8 (alaw) Answering with preferred capability 0x400 (ilbc) Reliably Transmitting (no NAT) to xxx.xxx.xxx.36:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKef17.c97ef7d2.1 Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-AJn351hl3U1H58O-0 Record-Route: <sip:xxx.xxx.xxx.36;ftag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7;lr=on> From: sip:6108712381@xxx.xxx.xxx.7:5060;tag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7 To: sip:5414362504@xxx.xxx.xxx.36:5060;tag=as4c6bfaee Call-ID: AJn351hl3U1H58O(a)xxx.xxx.xxx.7 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Contact: <sip:5414362504@xxx.xxx.xxx.80> Content-Type: application/sdp Content-Length: 237 v=0 o=root 29275 29275 IN IP4 xxx.xxx.xxx.80 s=session c=IN IP4 xxx.xxx.xxx.80 t=0 0 m=audio 14018 RTP/AVP 0 3 8 97 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:97 iLBC/8000 a=silenceSupp:off - - - - --- -- Playing 'vm-intro' (language 'en') Retransmitting #1 (no NAT) to xxx.xxx.xxx.36:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKef17.c97ef7d2.1 Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-AJn351hl3U1H58O-0 Record-Route: <sip:xxx.xxx.xxx.36;ftag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7;lr=on> From: sip:6108712381@xxx.xxx.xxx.7:5060;tag=AJn351hl3U1H58O-IPTrunk-70-17-23atxxx.xxx.xxx.7 To: sip:5414362504@xxx.xxx.xxx.36:5060;tag=as4c6bfaee Call-ID: AJn351hl3U1H58O(a)xxx.xxx.xxx.7 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Contact: <sip:5414362504@xxx.xxx.xxx.80> Content-Type: application/sdp Content-Length: 237 v=0 o=root 29275 29275 IN IP4 xxx.xxx.xxx.80 s=session c=IN IP4 xxx.xxx.xxx.80 t=0 0 m=audio 14018 RTP/AVP 0 3 8 97 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:97 iLBC/8000 a=silenceSupp:off - - - - --- ** ser.cfg # whatever.net - SER Configuration File # debug=3 fork=yes log_stderror=yes listen=xxx.xxx.xxx.36 port=5060 children=4 alias=whatever.net alias=hostname.whatever.net dns=no rev_dns=no fifo="/tmp/ser_fifo" fifo_db_url="mysql://ser:serpass@localhost/ser" # Modules loadmodule "/usr/local/lib/ser/modules/mysql.so" loadmodule "/usr/local/lib/ser/modules/sl.so" loadmodule "/usr/local/lib/ser/modules/tm.so" loadmodule "/usr/local/lib/ser/modules/rr.so" loadmodule "/usr/local/lib/ser/modules/maxfwd.so" loadmodule "/usr/local/lib/ser/modules/usrloc.so" loadmodule "/usr/local/lib/ser/modules/registrar.so" loadmodule "/usr/local/lib/ser/modules/auth.so" loadmodule "/usr/local/lib/ser/modules/auth_db.so" loadmodule "/usr/local/lib/ser/modules/nathelper.so" loadmodule "/usr/local/lib/ser/modules/textops.so" loadmodule "/usr/local/lib/ser/modules/uri_db.so" loadmodule "/usr/local/lib/ser/modules/uri.so" loadmodule "/usr/local/lib/ser/modules/xlog.so" loadmodule "/usr/local/lib/ser/modules/options.so" loadmodule "/usr/local/lib/ser/modules/exec.so" modparam("auth_db|uri_db|usrloc|permissions", "db_url", "mysql://ser:serpass@localhost/ser") modparam("auth_db", "calculate_ha1", 1) modparam("auth_db", "password_column", "password") modparam("nathelper", "natping_interval", 30) modparam("nathelper", "ping_nated_only", 1) modparam("nathelper", "rtpproxy_sock", "unix:/var/run/rtpproxy.sock") modparam("usrloc", "db_mode", 2) modparam("registrar", "nat_flag", 6) modparam("rr", "enable_full_lr", 1) modparam("tm", "fr_inv_timer", 20) modparam("tm", "fr_timer", 20) # # Route Section # route { # Basic Checks if (!mf_process_maxfwd_header("10")) { sl_send_reply("483", "Too Many Hops"); break; }; if (msg:len > max_len) { sl_send_reply("513", "Message Overflow"); break; }; ## # Record Route Section ## if (method!="REGISTER") { record_route(); }; if (method=="BYE" || method=="CANCEL") { unforce_rtp_proxy(); } ## # Loose Route Section ## if (loose_route()) { if (has_totag() && (method=="INVITE" || method=="ACK")) { if (nat_uac_test("19")) { setflag(6); force_rport(); fix_nated_contact(); }; force_rtp_proxy("l"); }; route(1); break; }; ## # Message Processing Section ## if (uri!=myself) { route(1); break; }; if (uri==myself) { if (method=="CANCEL") { route(3); break; } else if (method=="INVITE") { route(3); break; } else if (method=="REGISTER") { route(2); break; } else if (method=="NOTIFY") { sl_send_reply("200", "Shut up."); break; } else if (method=="OPTIONS" && (! uri=~"sip:.*[@]+.*")) { options_reply(); break; }; lookup("aliases"); if (uri!=myself) { route(1); break; }; if (!lookup("location") && method!="ACK") { sl_send_reply("404", "User Not Found"); break; }; }; route(1); } route[1] { # ----------------------------------------------------------------- # Default Message Handler # ----------------------------------------------------------------- # NAT Fix if (method=="INVITE" && nat_uac_test("19") && !isflagset(9)) { xlog("L_ERR", "Fixing NAT on INVITE for %ct.\n"); force_rport(); fix_nated_contact(); force_rtp_proxy(); setflag(9); }; t_on_reply("1"); if (!t_relay()) { if (method=="INVITE" && isflagset(6)) { unforce_rtp_proxy(); }; sl_reply_error(); }; } route[2] { # ----------------------------------------------------------------- # REGISTER Message Handler # ---------------------------------------------------------------- if (!search("^Contact:\ +\*") && nat_uac_test("19")) { setflag(6); fix_nated_register(); force_rport(); }; sl_send_reply("100", "Trying"); if (!www_authorize("whatever.net","subscriber")) { www_challenge("whatever.net","0"); break; }; if (!check_to()) { sl_send_reply("401", "Unauthorized"); break; }; consume_credentials(); if (!save("location")) { sl_reply_error(); }; } route[3] { # ----------------------------------------------------------------- # CANCEL and INVITE Message Handler # ----------------------------------------------------------------- if (nat_uac_test("19")) { setflag(6); } lookup("aliases"); if (uri!=myself) { route(1); break; }; if (!lookup("location")) { if (uri=~"^sip:911@") { # Pass 911 calls first route(5); break; }; if (uri=~"^sip:[0-9]{7}@") { # EXPAND 7-DIGIT CALL exec_dset("/root/7digit.pl"); }; # Try location lookup again if (!lookup("location")) { if (uri=~"^sip:[0-9]{10}@") { # DB Lookup of NPANXX route exec_dset("/root/npa_nxx.pl"); route(1); break; }; if (uri=~"^sip:[0-9]{11}@") { # DB Lookup of NPANXX route strip(1); exec_dset("/root/npa_nxx.pl"); route(1); break; }; if (uri=~"^sip:555@") { # Voicemail Access route(6); break; }; if (uri=~"^sip:556@") { # Voicemail Access route(6); break; }; # Call error message route(7); # sl_send_reply("404", "User Not Found"); break; }; }; # if (!proxy_authorize("whatever.net","subscriber")) { # proxy_challenge("whatever.net","0"); # break; # } else if (!check_from()) { # sl_send_reply("403", "Use From=ID"); # break; # }; # consume_credentials(); if (isflagset(6) && !isflagset(9)) { force_rport(); fix_nated_contact(); force_rtp_proxy(); setflag(9); }; t_on_reply("1"); t_on_failure("1"); if (!t_relay()) { if(isflagset(6)) { unforce_rtp_proxy(); }; sl_reply_error(); }; } route[5] { ### # Local PSTN Gateway ### rewritehost("xxx.xxx.xxx.7"); route(1); } route[6] { ### # Calls to VM ### rewritehost("xxx.xxx.xxx.80"); route(1); } route[7] { ### # Call Failure ### rewriteuri("sip:7110000001@xxx.xxx.xxx.80"); route(1); } failure_route[1] { ### # Voicemail ### xlog("L_ERR", " Failure Route 1 hit.\n"); if (t_check_status("487")) { xlog("L_ERR", " Failure Route 1 - 487 detected, breaking.\n"); break; }; rewritehost("xxx.xxx.xxx.80"); append_hf("P-hint: OFFLINE VOICEMAIL\r\n"); append_branch(); route(1); } onreply_route[1] { if (isflagset(6) && status=~"(180)|(183)|2[0-9][0-9]") { if (!search("^Content-Length:\ +0")) { force_rtp_proxy(); }; }; if (nat_uac_test("1")) { fix_nated_contact(); }; } ********************************************* This message has been scanned for viruses and dangerous content, and is believed to be clean.