1 Sep
2005
1 Sep
'05
8:20 p.m.
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(a)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(a)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(a)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(a)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(a)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(a)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(a)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.
2 Sep
2 Sep
8:21 a.m.
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(a)csma.biz>
To: <serusers(a)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:
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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
8:27 p.m.
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.
6831
days inactive
6832
days old
2 comments
2 participants
participants (2)
-
Corey S. McFadden -
Greger V. Teigre