We’re using Broadvoice and everything worked fine for about two days. Then we updated the firmware on our router and came across the following problem. All inbound calls work fine but outbound will work fine for one call and then when we try to call right after that, it rings busy. If we shutdown asterisk and wait about 3 minutes and restart it we can then make a call. Then if we try to make another immediately after that it rings busy again.
Here’s the sip debug of a call. 100 is the extnesion I’m calling from. 6306407999 is the number being called and 6307491020 is the Broadvoice number being used for the call:
Found RTP audio format 97
Found RTP audio format 98
Found RTP audio format 101
Peer audio RTP is at port 192.168.1.100:16478
Found description format PCMU for ID 0
Found description format G726-32 for ID 2
Found description format G723 for ID 4
Found description format PCMA for ID 8
Found description format G729a for ID 18
Found description format G726-40 for ID 96
Found description format G726-24 for ID 97
Found description format G726-16 for ID 98
Found description format telephone-event for ID 101
Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0xd0d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 192.168.1.100:16478
Looking for 6306407999 in test (domain 192.168.1.5)
list_route: hop: <sip:100@192.168.1.100:5060>
asterisk*CLI>
<--- Transmitting (no NAT) to 192.168.1.100:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.100:5060;branch=z9hG4bK-e2961a22;received=192.168.1.100
From: "100" <sip:100@192.168.1.5>;tag=30e13aeffdb9d12eo0
To: "6306407999" <sip:6306407999@192.168.1.5>
Call-ID: 5d72bac3-fcd8336a@192.168.1.100
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:6306407999@192.168.1.5>
Content-Length: 0
<------------>
-- Executing [6306407999@test:1] Set("SIP/100-081d51a8", "CALLERID(num)=6305630151") in new stack
-- Executing [6306407999@test:2] Dial("SIP/100-081d51a8", "SIP/6306407999@broadvoice-out|30") in new stack
Audio is at 192.168.1.5 port 17288
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x2 (gsm) to SDP
Adding codec 0x8 (alaw) to SDP
Reliably Transmitting (NAT) to 147.135.12.221:5060:
INVITE sip:6306407999@sip.broadvoice.com SIP/2.0
Via: SIP/2.0/UDP 192.168.1.5:5060;branch=z9hG4bK6acf3c9b;rport
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>
Contact: <sip:6307491020@192.168.1.5>
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sat, 23 Jun 2007 20:25:21 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Type: application/sdp
Content-Length: 229
v=0
o=root 17613 17613 IN IP4 192.168.1.5
s=session
c=IN IP4 192.168.1.5
t=0 0
m=audio 17288 RTP/AVP 0 3 8
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
---
-- Called 6306407999@broadvoice-out
asterisk*CLI>
<--- SIP read from 147.135.12.221:5060 --->
SIP/2.0 100 Trying
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 102 INVITE
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>
Via: SIP/2.0/UDP 64.81.146.244:5060;branch=z9hG4bK6acf3c9b
Content-Length: 0
<------------->
--- (7 headers 0 lines) ---
asterisk*CLI>
<--- SIP read from 147.135.12.221:5060 --->
SIP/2.0 401 Unauthorized
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 102 INVITE
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>;tag=rtuv
Via: SIP/2.0/UDP 64.81.146.244:5060;branch=z9hG4bK6acf3c9b
WWW-Authenticate: DIGEST realm="BroadWorks",qop="auth",algorithm=MD5,nonce="BroadWorksXf3ajkl8cTiccer1BW"
Content-Length: 0
<------------->
--- (8 headers 0 lines) ---
Transmitting (NAT) to 147.135.12.221:5060:
ACK sip:6306407999@sip.broadvoice.com SIP/2.0
Via: SIP/2.0/UDP 192.168.1.5:5060;branch=z9hG4bK6acf3c9b;rport
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>;tag=rtuv
Contact: <sip:6307491020@192.168.1.5>
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0
---
Audio is at 192.168.1.5 port 17288
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x2 (gsm) to SDP
Adding codec 0x8 (alaw) to SDP
Reliably Transmitting (NAT) to 147.135.12.221:5060:
INVITE sip:6306407999@sip.broadvoice.com SIP/2.0
Via: SIP/2.0/UDP 192.168.1.5:5060;branch=z9hG4bK4b3d2ed0;rport
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>
Contact: <sip:6307491020@192.168.1.5>
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 103 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Authorization: Digest username="6307491020", realm="BroadWorks", algorithm=MD5, uri="sip:6306407999@sip.broadvoice.com", nonce="BroadWorksXf3ajkl8cTiccer1BW", response="2b9b1af399e5d1bf749ba2263e1840a7", opaque="", qop=auth, cnonce="575c12e4", nc=00000001
Date: Sat, 23 Jun 2007 20:25:21 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Type: application/sdp
Content-Length: 229
v=0
o=root 17613 17614 IN IP4 192.168.1.5
s=session
c=IN IP4 192.168.1.5
t=0 0
m=audio 17288 RTP/AVP 0 3 8
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
---
asterisk*CLI>
<--- SIP read from 147.135.12.221:5060 --->
SIP/2.0 100 Trying
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 103 INVITE
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>
Via: SIP/2.0/UDP 192.168.1.5:5060;branch=z9hG4bK4b3d2ed0;received=64.81.146.244;rport=5060
Content-Length: 0
<------------->
--- (7 headers 0 lines) ---
asterisk*CLI>
<--- SIP read from 147.135.12.221:5060 --->
SIP/2.0 403 Forbidden
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 103 INVITE
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>;tag=89ab
Via: SIP/2.0/UDP 192.168.1.5:5060;branch=z9hG4bK4b3d2ed0;received=64.81.146.244;rport=5060
Authorization: Digest username="6307491020", realm="BroadWorks", algorithm=MD5, uri="sip:6306407999@sip.broadvoice.com", nonce="BroadWorksXf3ajkl8cTiccer1BW", response="2b9b1af399e5d1bf749ba2263e1840a7", opaque="", qop=auth, cnonce="575c12e4", nc=00000001
User-Agent: Asterisk PBX
Content-Length: 178
Content-Type: application/sdp
v=0
o=3232235781 17613 17614 IN IP4 192.168.1.5
s=-
c=IN IP4 192.168.1.5
t=0 0
m=audio 17288 RTP/AVP 0 3 8
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
<------------->
--- (10 headers 9 lines) ---
Transmitting (NAT) to 147.135.12.221:5060:
ACK sip:6306407999@sip.broadvoice.com SIP/2.0
Via: SIP/2.0/UDP 192.168.1.5:5060;branch=z9hG4bK4b3d2ed0;rport
From: "100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65
To: <sip:6306407999@sip.broadvoice.com>;tag=89ab
Contact: <sip:6307491020@192.168.1.5>
Call-ID: 5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com
CSeq: 103 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0
---
[Jun 23 15:25:21] WARNING[17644]: chan_sip.c:11918 handle_response_invite: Received response: "Forbidden" from '"100" <sip:6307491020@sip.broadvoice.com>;tag=as26b89b65'
-- SIP/broadvoice-out-081d9658 is circuit-busy
== Everyone is busy/congested at this time (1:0/1/0)
== Auto fallthrough, channel 'SIP/100-081d51a8' status is 'CONGESTION'
<--- Transmitting (no NAT) to 192.168.1.100:5060 --->
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 192.168.1.100:5060;branch=z9hG4bK-e2961a22;received=192.168.1.100
From: "100" <sip:100@192.168.1.5>;tag=30e13aeffdb9d12eo0
To: "6306407999" <sip:6306407999@192.168.1.5>;tag=as41d00d69
Call-ID: 5d72bac3-fcd8336a@192.168.1.100
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:6306407999@192.168.1.5>
Content-Length: 0
X-Asterisk-HangupCause: Call Rejected
X-Asterisk-HangupCauseCode: 21
<------------>
asterisk*CLI>
<--- SIP read from 192.168.1.100:5060 --->
ACK sip:6306407999@192.168.1.5 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.100:5060;branch=z9hG4bK-e2961a22
From: "100" <sip:100@192.168.1.5>;tag=30e13aeffdb9d12eo0
To: "6306407999" <sip:6306407999@192.168.1.5>;tag=as41d00d69
Call-ID: 5d72bac3-fcd8336a@192.168.1.100
CSeq: 102 ACK
Max-Forwards: 70
Proxy-Authorization: Digest username="100",realm="asterisk",nonce="4c28d118",uri="sip:6306407999@192.168.1.5",algorithm=MD5,response="84161930bebd37270cbb05c934c63d4a"
Contact: "100" <sip:100@192.168.1.100:5060>;+sip.instance="<00000000-0000-0000-0000-000E08DD66F4>"
User-Agent: Linksys/SPA962-5.1.7
Content-Length: 0
Allow-Events: dialog
<------------->
--- (12 headers 0 lines) ---
Really destroying SIP dialog '5dd854287966445b4c3467fe31cca3ca@sip.broadvoice.com' Method: INVITE
Really destroying SIP dialog '5d72bac3-fcd8336a@192.168.1.100' Method: ACK