We're working through an annoying problem with voicemail and the fr_inv_timer and after banging our heads against it for a while figured we'd reach out for a little help. It's probably something obvious, but here's the scenario:
1. SIP DID rings SER 2. SER Routes to registered UA (UA behind NAT) 3. UA Rings 4. fr_inv_timer is hit and failure_route[1] is invoked 5. failure_route[1] rewrites host to send call to Asterisk for VM 6. Asterisk gets the call and starts processing but the calling party never gets the OK, gets no audio, and dies with a fast busy.
When the UA is NOT registered or registered without going through NAT there isn't a problem. Asterisk OK's and works fine.
This is probably some moronic NAT issue but we're not sure how to proceed. I'm going to follow with a 'sip debug' message from Asterisk, some ngrep from the SER machine (with commentary), and finally the SER cnf itself.
If anyone can help we would be incredibly grateful! (Seriously!)
Thanks, -Corey
** IP Legend xxx.xxx.xxx.7 - SIP Originating Source xxx.xxx.xxx.36 - SER xxx.xxx.xxx.80 - Asterisk VM Server 216.NAT.CLI.207 - NAT UA Public IP 192.168.249.83 - Private IP of UA
5410000000 - DID & UA ID 6100000000 - Outside Caller ID
** Versions SER: 0.9.4-rc3 rtpproxy: 20040107 Extension 20050322
** Asterisk SIP Debug shows this on the second retry:
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=z9hG4bK9e09.116856a3.2 Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-5Jn7520l3PhAH6h-0 Record-Route: sip:xxx.xxx.xxx.36;ftag=5Jn7520l3PhAH6h-IPTrunk-81-17-23atxxx.xxx.xxx.7;lr=on From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=5Jn7520l3PhAH6h-IPTrunk-81-17-23atxxx.xxx.xxx.7 To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as625cebc0 Call-ID: 5Jn7520l3PhAH6h@xxx.xxx.xxx.7 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Contact: sip:5410000000@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 11476 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 - - - -
After re-transmitting one more time it will finally fail.
*** NGREP OUTPUT (from SER box)
# U xxx.xxx.xxx.7:5060 -> xxx.xxx.xxx.36:5060 INVITE sip:5410000000@xxx.xxx.xxx.36:5060 SIP/2.0..Via: SIP/2.0/UDP ... # 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 ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@192.168.249.83:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23a ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at xxx.xxx.xxx.7;lr=on>..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 100 Trying..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at xxx.xxx.xxx.7;lr=on>..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 ....
# U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 CANCEL sip:5410000000@192.168.249.83:5060 SIP/2.0..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe2fe.1754f177.0..From: sip ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 487 Request Cancelled..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 ACK sip:5410000000@192.168.249.83:5060 SIP/2.0..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at xxx.xxx.xxx.7;lr=on>..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 100 Trying..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # (ASTERISK SERVER ENTERS THE PICTURE HERE) U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.80:5060 INVITE sip:5410000000@xxx.xxx.xxx.80 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at209. 216.177.7;lr=on>..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;rport= 5060;branch=z9hG4bK-00101-kYn356Vl3PhGzel-0..Max-Forwards: 5..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-I PTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 I NVITE..Remote-Party-Id: sip:6100000000@xxx.xxx.xxx.7:5060;party=calling;privacy=off;id-type=subscriber..Expires: 180..All ow: INVITE,CANCEL,BYE,ACK..Contact: sip:xxx.xxx.xxx.7:5060..User-Agent: Tekelec-7000/r4.0..Content-Type: application/sdp..C ontent-Length: 169....v=0..o=- 1 1 IN IP4 xxx.xxx.xxx.7..s= ..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35314 RTP/AVP 0..a=pt ime:20..a=rtpmap:0 PCMU/8000..a=direction:active..a=nortpproxy:yes..
# U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 CANCEL sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Via: SIP/2.0/UDP ... # (ASTERISK SERVER RESPONDS) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;bran ch=z9hG4bK-00101-kYn356Vl3PhGzel-0..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23at209.216.1 77.7..To: sip:5410000000@xxx.xxx.xxx.36:5060..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asteris k PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Length: 0 ....
# U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 487 Request Cancelled..Via: SIP/2.0/UDP ... # (SER ACKs the UAs' 487) U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 ACK sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Via: SIP/2.0/UDP ... # (ASTERISK SENDS THE OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 255....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35316 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 - - - -..a=nortpproxy:yes.. # (ASTERISK SENDS ANOTHER OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 255....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35316 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 - - - -..a=nortpproxy:yes.. # (ASTERISK SENDS YET ANOTHER OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 255....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35316 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 - - - -..a=nortpproxy:yes.. # (ASTERISK SENDS ANOTHER OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 237....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.80..t=0 0..m=audio 11184 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 - - - -..
# ASTERISK KEEPS TRYING TO SEND OK 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 237....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.80..t=0 0..m=audio 11184 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 - - - -..
** At this point the call is in fast-busy and Asterisk shows a failure.
**** SER CFG # ser.cfg ############################################################
debug=3 fork=yes log_stderror=yes
listen=xxx.xxx.xxx.36 port=5060 children=4 alias=whatever.net alias=whatever.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/acc.so" loadmodule "/usr/local/lib/ser/modules/rr.so" loadmodule "/usr/local/lib/ser/modules/exec.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/permissions.so"
### # Module Paramaters ###
modparam("auth_db|uri_db|usrloc", "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")
# VM Timeout modparam("tm", "fr_inv_timer", 20)
modparam("usrloc", "db_mode", 2) modparam("permissions", "db_mode", 0) modparam("permissions", "trusted_table", "trusted") modparam("registrar", "nat_flag", 6) modparam("rr", "enable_full_lr", 1) modparam("exec", "setvars", 1)
modparam("acc", "log_level", 1) modparam("acc", "log_flag", 1) modparam("acc", "db_url", "mysql://ser:serpass@localhost/ser") modparam("acc", "db_flag", 1)
### # Routing 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; }; if (method!="REGISTER") { record_route(); };
if (method=="BYE" || method=="CANCEL") { unforce_rtp_proxy(); }
# Loose Routing if (loose_route()) { route(1); break; };
# Call Processing 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; };
lookup("aliases"); if (uri!=myself) { route(1); break; };
if (!lookup("location")) { sl_send_reply("404", "User Not Found"); break; }; };
route(1); }
route[1] {
### # Default Call Handling ###
# NAT Fix if (isflagset(6) && !isflagset(9)) { fix_nated_sdp("1"); force_rport(); fix_nated_contact(); force_rtp_proxy(); setflag(9); };
# On call timeout to voicemail t_on_failure("1"); t_on_reply("1");
# Log setflag(1);
if (!t_relay()) { if (method=="INVITE" && isflagset(6)) { unforce_rtp_proxy(); }; sl_reply_error(); }; }
route[2] {
### # REGISTER method ###
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] {
### # INVITE & CANCEL # URI matching is here. ###
t_on_failure("1");
if (nat_uac_test("19")) { log(1," INVITE: NAT Detected. Setting flag 6.\n"); setflag(6); }
if (method=="INVITE" && src_ip==xxx.xxx.xxx.7) { !allow_trusted()) {
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(); };
lookup("aliases"); # if (uri!=myself) { # force_rtp_proxy(); # 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:1[0-9]{10}@") { # DB Lookup of NPANXX route exec_dset("/root/npa_nxx.pl"); route(1); break; }; # Call error message route(7);
break; }; };
# if (isflagset(6)) { # force_rport(); # fix_nated_contact(); # force_rtp_proxy(); # };
t_on_reply("1");
if (!t_relay()) { if(isflagset(6)) { unforce_rtp_proxy(); } sl_reply_error(); }; }
route[4] {
### # Primary LD Gateway ###
rewritehost("xxxxxxxxxxxxxxxx"); route(1); }
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 ###
log(1,"Failure Route Hit\n"); rewritehost("xxx.xxx.xxx.80"); 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") && !isflagset(9)) { fix_nated_contact(); }; }
-- Corey S. McFadden (c@csma.biz) McFadden Associates - Technology Consultants phone 215-825-2121 x510 - web.csma.biz
********************************************* This message has been scanned for viruses and dangerous content, and is believed to be clean.
Hi Corey, A few comments: - It seems that after the timeout, a new INVITE is generated to the UA, right before the forwarding to Asterisk. Is this just noise or part of the actual call you documented? - The record routing and path of the messages look fine AFAICS, but you don't mention one crucial point: Does the caller receive the OK or not? You assume it is a NAT problem, but are you sure? Maybe the caller discards the message for some reason? - You haven't shown the initial INVITE from .7. Does it originate on port 5060? Some GWs will be asynchronous and expect reply on the high UDP port used for the INVITE. Your NAT detection may then detect the GW as NATed and rewrite, which may cause a problem. - I remember a problem where Asterisk was involved where ;lr=on caused a problem. I cannot remember if it is relevant, but you may want to search in the archives - A log from the caller would tell you if the OK is received or dropped
g-)
----- Original Message ----- From: "Corey S. McFadden" csm-lists@csma.biz To: serusers@lists.iptel.org Sent: Thursday, September 01, 2005 08:20 PM Subject: [Serusers] NAT Related Voicemail Timeout Problem (HELP!)
We're working through an annoying problem with voicemail and the fr_inv_timer and after banging our heads against it for a while figured we'd reach out for a little help. It's probably something obvious, but here's the scenario:
- SIP DID rings SER
- SER Routes to registered UA (UA behind NAT)
- UA Rings
- fr_inv_timer is hit and failure_route[1] is invoked
- failure_route[1] rewrites host to send call to Asterisk for VM
- Asterisk gets the call and starts processing but the calling party
never gets the OK, gets no audio, and dies with a fast busy.
When the UA is NOT registered or registered without going through NAT there isn't a problem. Asterisk OK's and works fine.
This is probably some moronic NAT issue but we're not sure how to proceed. I'm going to follow with a 'sip debug' message from Asterisk, some ngrep from the SER machine (with commentary), and finally the SER cnf itself.
If anyone can help we would be incredibly grateful! (Seriously!)
Thanks, -Corey
** IP Legend xxx.xxx.xxx.7 - SIP Originating Source xxx.xxx.xxx.36 - SER xxx.xxx.xxx.80 - Asterisk VM Server 216.NAT.CLI.207 - NAT UA Public IP 192.168.249.83 - Private IP of UA
5410000000 - DID & UA ID 6100000000 - Outside Caller ID
** Versions SER: 0.9.4-rc3 rtpproxy: 20040107 Extension 20050322
** Asterisk SIP Debug shows this on the second retry:
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=z9hG4bK9e09.116856a3.2 Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z9hG4bK-00101-5Jn7520l3PhAH6h-0 Record-Route: sip:xxx.xxx.xxx.36;ftag=5Jn7520l3PhAH6h-IPTrunk-81-17-23atxxx.xxx.xxx.7;lr=on From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=5Jn7520l3PhAH6h-IPTrunk-81-17-23atxxx.xxx.xxx.7 To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as625cebc0 Call-ID: 5Jn7520l3PhAH6h@xxx.xxx.xxx.7 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Contact: sip:5410000000@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 11476 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 - - - -
After re-transmitting one more time it will finally fail.
*** NGREP OUTPUT (from SER box)
# U xxx.xxx.xxx.7:5060 -> xxx.xxx.xxx.36:5060 INVITE sip:5410000000@xxx.xxx.xxx.36:5060 SIP/2.0..Via: SIP/2.0/UDP ... # 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 ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@192.168.249.83:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23a ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at xxx.xxx.xxx.7;lr=on>..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 100 Trying..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at xxx.xxx.xxx.7;lr=on>..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 ....
# U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 CANCEL sip:5410000000@192.168.249.83:5060 SIP/2.0..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe2fe.1754f177.0..From: sip ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 487 Request Cancelled..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 ACK sip:5410000000@192.168.249.83:5060 SIP/2.0..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 INVITE sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at xxx.xxx.xxx.7;lr=on>..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 100 Trying..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.7:5060 SIP/2.0 180 Ringing..Via: SIP/2.0/UDP ... # (ASTERISK SERVER ENTERS THE PICTURE HERE) U xxx.xxx.xxx.36:5060 -> xxx.xxx.xxx.80:5060 INVITE sip:5410000000@xxx.xxx.xxx.80 SIP/2.0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23at209. 216.177.7;lr=on>..Via: SIP/2.0/UDP xxx.xxx.xxx.36;branch=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;rport= 5060;branch=z9hG4bK-00101-kYn356Vl3PhGzel-0..Max-Forwards: 5..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-I PTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 I NVITE..Remote-Party-Id: sip:6100000000@xxx.xxx.xxx.7:5060;party=calling;privacy=off;id-type=subscriber..Expires: 180..All ow: INVITE,CANCEL,BYE,ACK..Contact: sip:xxx.xxx.xxx.7:5060..User-Agent: Tekelec-7000/r4.0..Content-Type: application/sdp..C ontent-Length: 169....v=0..o=- 1 1 IN IP4 xxx.xxx.xxx.7..s= ..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35314 RTP/AVP 0..a=pt ime:20..a=rtpmap:0 PCMU/8000..a=direction:active..a=nortpproxy:yes..
# U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 CANCEL sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Via: SIP/2.0/UDP ... # (ASTERISK SERVER RESPONDS) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;bran ch=z9hG4bK-00101-kYn356Vl3PhGzel-0..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23at209.216.1 77.7..To: sip:5410000000@xxx.xxx.xxx.36:5060..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asteris k PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Length: 0 ....
# U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 200 OK..Via: SIP/2.0/UDP ... # U 216.NAT.CLI.207:5060 -> xxx.xxx.xxx.36:5060 SIP/2.0 487 Request Cancelled..Via: SIP/2.0/UDP ... # (SER ACKs the UAs' 487) U xxx.xxx.xxx.36:5060 -> 216.NAT.CLI.207:5060 ACK sip:5410000000@216.NAT.CLI.207:5060 SIP/2.0..Via: SIP/2.0/UDP ... # (ASTERISK SENDS THE OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 255....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35316 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 - - - -..a=nortpproxy:yes.. # (ASTERISK SENDS ANOTHER OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 255....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35316 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 - - - -..a=nortpproxy:yes.. # (ASTERISK SENDS YET ANOTHER OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 255....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.36..t=0 0..m=audio 35316 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 - - - -..a=nortpproxy:yes.. # (ASTERISK SENDS ANOTHER OK) 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 237....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.80..t=0 0..m=audio 11184 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 - - - -..
# ASTERISK KEEPS TRYING TO SEND OK 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=z9hG4bKe2fe.1754f177.2..Via: SIP/2.0/UDP xxx.xxx.xxx.7:5060;branch=z 9hG4bK-00101-kYn356Vl3PhGzel-0..Record-Route: <sip:xxx.xxx.xxx.36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=o n>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@209.216 .160.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@xxx.xxx.xxx.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INV ITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: sip:5410000000@xxx.xxx.xxx.80..Content-Type: application/sdp..Con tent-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 11184 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:of f - - - -..
# 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-kYn356Vl3PhGzel-0..Record-Route: <sip:209.216.160. 36;ftag=kYn356Vl3PhGzel-IPTrunk-83-17-23atxxx.xxx.xxx.7;lr=on>..From: sip:6100000000@xxx.xxx.xxx.7:5060;tag=kYn356Vl3PhGzel -IPTrunk-83-17-23atxxx.xxx.xxx.7..To: sip:5410000000@xxx.xxx.xxx.36:5060;tag=as6ca38bc6..Call-ID: kYn356Vl3PhGzel@209.216.1 77.7..CSeq: 101 INVITE..User-Agent: Asterisk PBX..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY..Contact: <sip:54 14362504@xxx.xxx.xxx.80>..Content-Type: application/sdp..Content-Length: 237....v=0..o=root 29275 29275 IN IP4 209.216.160. 80..s=session..c=IN IP4 xxx.xxx.xxx.80..t=0 0..m=audio 11184 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 - - - -..
** At this point the call is in fast-busy and Asterisk shows a failure.
**** SER CFG # ser.cfg ############################################################
debug=3 fork=yes log_stderror=yes
listen=xxx.xxx.xxx.36 port=5060 children=4 alias=whatever.net alias=whatever.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/acc.so" loadmodule "/usr/local/lib/ser/modules/rr.so" loadmodule "/usr/local/lib/ser/modules/exec.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/permissions.so"
### # Module Paramaters ###
modparam("auth_db|uri_db|usrloc", "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")
# VM Timeout modparam("tm", "fr_inv_timer", 20)
modparam("usrloc", "db_mode", 2) modparam("permissions", "db_mode", 0) modparam("permissions", "trusted_table", "trusted") modparam("registrar", "nat_flag", 6) modparam("rr", "enable_full_lr", 1) modparam("exec", "setvars", 1)
modparam("acc", "log_level", 1) modparam("acc", "log_flag", 1) modparam("acc", "db_url", "mysql://ser:serpass@localhost/ser") modparam("acc", "db_flag", 1)
### # Routing 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; }; if (method!="REGISTER") { record_route(); }; if (method=="BYE" || method=="CANCEL") { unforce_rtp_proxy(); } # Loose Routing if (loose_route()) { route(1); break; }; # Call Processing 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; }; lookup("aliases"); if (uri!=myself) { route(1); break; }; if (!lookup("location")) { sl_send_reply("404", "User Not Found"); break; }; }; route(1);}
route[1] {
### # Default Call Handling ### # NAT Fix if (isflagset(6) && !isflagset(9)) { fix_nated_sdp("1"); force_rport(); fix_nated_contact(); force_rtp_proxy(); setflag(9); }; # On call timeout to voicemail t_on_failure("1"); t_on_reply("1"); # Log setflag(1); if (!t_relay()) { if (method=="INVITE" && isflagset(6)) { unforce_rtp_proxy(); }; sl_reply_error(); };}
route[2] {
### # REGISTER method ### 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] {
### # INVITE & CANCEL # URI matching is here. ### t_on_failure("1"); if (nat_uac_test("19")) { log(1," INVITE: NAT Detected. Setting flag 6.\n"); setflag(6); } if (method=="INVITE" && src_ip==xxx.xxx.xxx.7) { !allow_trusted()) { 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(); }; lookup("aliases");# if (uri!=myself) { # force_rtp_proxy(); # 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:1[0-9]{10}@") { # DB Lookup of NPANXX route exec_dset("/root/npa_nxx.pl"); route(1); break; }; # Call error message route(7); break; }; };# if (isflagset(6)) { # force_rport(); # fix_nated_contact(); # force_rtp_proxy(); # };
t_on_reply("1"); if (!t_relay()) { if(isflagset(6)) { unforce_rtp_proxy(); } sl_reply_error(); };}
route[4] {
### # Primary LD Gateway ### rewritehost("xxxxxxxxxxxxxxxx"); route(1);}
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 ### log(1,"Failure Route Hit\n"); rewritehost("xxx.xxx.xxx.80"); 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") && !isflagset(9)) { fix_nated_contact(); };}
-- Corey S. McFadden (c@csma.biz) McFadden Associates - Technology Consultants phone 215-825-2121 x510 - web.csma.biz
This message has been scanned for viruses and dangerous content, and is believed to be clean.
Serusers mailing list serusers@lists.iptel.org http://lists.iptel.org/mailman/listinfo/serusers
Greger,
Thanks for the response. To answer your questions, the original INVITE is coming from 5060. After the timeout the second INVITE is a mystery. I'm looking into the ;lr=on question but it definitely looks like the OK isn't getting to the GW.
I thought there might be an independent timeout on the GW messing with things but we turned down the fr_inv_timer to 4 and that had no effect. As soon as the failure route hit Asterisk the call drops for the caller.
I'm inclined to think it might have something to do with the rtpproxy because we've discovered another situation: two phones behind the same NAT registering to SER can't call each other. They can ring each other but the calls never actually connect.
Here is some SER debug: 5(75891) contact_parser(): Empty body 5(75891) parse_contact(): Error while parsing 5(75891) get_contact_uri: Error while parsing Contact body 2(75888) contact_parser(): Empty body 2(75888) parse_contact(): Error while parsing 2(75888) get_contact_uri: Error while parsing Contact body 2(75888) ERROR: add_uac: maximum number of branches exceeded 2(75888) ERROR: t_forward_nonack: failure to add branches 2(75888) ERROR: w_t_relay (failure mode): forwarding failed 2(75888) ERROR: sl_reply_error used: I'm terribly sorry, server error occurred (1/SL)
If anyone can provide any more insight as to what we might be doing wrong here we would certainly appreciate it.
Thanks again, -Corey
On Fri, 2 Sep 2005, Greger V. Teigre wrote:
Hi Corey, A few comments:
- It seems that after the timeout, a new INVITE is generated to the UA,
right before the forwarding to Asterisk. Is this just noise or part of the actual call you documented?
- The record routing and path of the messages look fine AFAICS, but you
don't mention one crucial point: Does the caller receive the OK or not? You assume it is a NAT problem, but are you sure? Maybe the caller discards the message for some reason?
- You haven't shown the initial INVITE from .7. Does it originate on port
5060? Some GWs will be asynchronous and expect reply on the high UDP port used for the INVITE. Your NAT detection may then detect the GW as NATed and rewrite, which may cause a problem.
- I remember a problem where Asterisk was involved where ;lr=on caused a
problem. I cannot remember if it is relevant, but you may want to search in the archives
- A log from the caller would tell you if the OK is received or dropped
g-)
<snip>
********************************************* This message has been scanned for viruses and dangerous content, and is believed to be clean.
-
Corey S. McFadden -
Greger V. Teigre