Grandstream DP715 busy

Bought a new Grandstream DP715 cordless IP phone. I’ve got the phone registered with FreePBX (Asterisk 11.13.0), no problems there. I’m able to dial out from the DP715 to any extension on the network, but any incoming calls automatically get a busy signal. A copy of the sip debug and the call proceeding through the server:

<— SIP read from UDP:192.168.1.200:5060 —>
INVITE sip:[email protected]:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK5f1fd3a1A58D07B2
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone
CSeq: 1 INVITE
Call-ID: [email protected]
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.3.0069
Accept-Language: en-ca,en;q=0.9
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 296

v=0
o=- 1444788912 1444788912 IN IP4 192.168.1.200
s=Polycom IP Phone
c=IN IP4 192.168.1.200
t=0 0
a=sendrecv
m=audio 2268 RTP/AVP 9 0 8 18 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:127 telephone-event/8000
<------------->
— (15 headers 13 lines) —
Sending to 192.168.1.200:5060 (NAT)
Sending to 192.168.1.200:5060 (NAT)
Using INVITE request as basis request - [email protected]
Found peer ‘3210’ for ‘3210’ from 192.168.1.200:5060

<— Reliably Transmitting (NAT) to 192.168.1.200:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK5f1fd3a1A58D07B2;received=192.168.1.200;rport=5060
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone;tag=as0bdb3468
Call-ID: [email protected]
CSeq: 1 INVITE
Server: FPBX-2.11.0(11.13.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="0785230e"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘[email protected]’ in 6400 ms (Method: INVITE)

<— SIP read from UDP:192.168.1.200:5060 —>
ACK sip:[email protected]:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK5f1fd3a1A58D07B2
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone;tag=as0bdb3468
CSeq: 1 ACK
Call-ID: [email protected]
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.3.0069
Accept-Language: en-ca,en;q=0.9
Max-Forwards: 70
Content-Length: 0

<------------->
— (12 headers 0 lines) —

<— SIP read from UDP:192.168.1.200:5060 —>
INVITE sip:[email protected]:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK229e0cc68B6BFF7F
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone
CSeq: 2 INVITE
Call-ID: [email protected]
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.3.0069
Accept-Language: en-ca,en;q=0.9
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Authorization: Digest username=“3210”, realm=“asterisk”, nonce=“0785230e”, uri=“sip:[email protected]:5060;user=phone”, response=“5ba626f5e074ea647ae9f8a7c526f7b8”, algorithm=MD5
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 296

v=0
o=- 1444788912 1444788912 IN IP4 192.168.1.200
s=Polycom IP Phone
c=IN IP4 192.168.1.200
t=0 0
a=sendrecv
m=audio 2268 RTP/AVP 9 0 8 18 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:127 telephone-event/8000
<------------->
— (16 headers 13 lines) —
Sending to 192.168.1.200:5060 (NAT)
Using INVITE request as basis request - [email protected]
Found peer ‘3210’ for ‘3210’ from 192.168.1.200:5060
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 9
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 18
Found RTP audio format 127
Found audio description format G722 for ID 9
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 127
Capabilities: us - (gsm|ulaw|alaw), peer - audio=(ulaw|alaw|g729|g722)/video=(nothing)/text=(nothing), combined - (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.200:2268
Looking for 3225 in from-internal (domain 192.168.1.3)
list_route: hop: sip:[email protected]

<— Transmitting (NAT) to 192.168.1.200:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK229e0cc68B6BFF7F;received=192.168.1.200;rport=5060
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone
Call-ID: [email protected]
CSeq: 2 INVITE
Server: FPBX-2.11.0(11.13.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Executing [[email protected]:1] Set(“SIP/3210-0000000b”, “__RINGTIMER=15”) in new stack
– Executing [[email protected]:2] Macro(“SIP/3210-0000000b”, “exten-vm,novm,3225,0,0,0”) in new stack
– Executing [[email protected]:1] Macro(“SIP/3210-0000000b”, “user-callerid,”) in new stack
– Executing [[email protected]:1] Set(“SIP/3210-0000000b”, “TOUCH_MONITOR=1444788927.11”) in new stack
– Executing [[email protected]:2] Set(“SIP/3210-0000000b”, “AMPUSER=3210”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/3210-0000000b”, “0?report”) in new stack
– Executing [[email protected]:4] ExecIf(“SIP/3210-0000000b”, “1?Set(REALCALLERIDNUM=3210)”) in new stack
– Executing [[email protected]:5] Set(“SIP/3210-0000000b”, “AMPUSER=3210”) in new stack
– Executing [[email protected]:6] GotoIf(“SIP/3210-0000000b”, “0?limit”) in new stack
– Executing [[email protected]:7] Set(“SIP/3210-0000000b”, “AMPUSERCIDNAME=Warren - Office”) in new stack
– Executing [[email protected]:8] GotoIf(“SIP/3210-0000000b”, “0?report”) in new stack
– Executing [[email protected]:9] Set(“SIP/3210-0000000b”, “AMPUSERCID=3210”) in new stack
– Executing [[email protected]:10] Set(“SIP/3210-0000000b”, “__DIAL_OPTIONS=Ttr”) in new stack
– Executing [[email protected]:11] Set(“SIP/3210-0000000b”, “CALLERID(all)=“Warren - Office” <3210>”) in new stack
– Executing [[email protected]:12] GotoIf(“SIP/3210-0000000b”, “0?limit”) in new stack
– Executing [[email protected]:13] ExecIf(“SIP/3210-0000000b”, “0?Set(GROUP(concurrency_limit)=3210)”) in new stack
– Executing [[email protected]:14] GosubIf(“SIP/3210-0000000b”, “7?sub-ccss,s,1(macro-exten-vm,3225)”) in new stack
– Executing [[email protected]:1] ExecIf(“SIP/3210-0000000b”, “0?Return()”) in new stack
– Executing [[email protected]:2] Set(“SIP/3210-0000000b”, “CCSS_SETUP=TRUE”) in new stack
– Executing [[email protected]:3] GosubIf(“SIP/3210-0000000b”, “0?monitor_config,1(macro-exten-vm,3225):monitor_default,1(macro-exten-vm,3225)”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/3210-0000000b”, “1?is_exten”) in new stack
– Goto (sub-ccss,monitor_default,4)
– Executing [[email protected]:4] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack
– Executing [[email protected]:5] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack
– Executing [[email protected]:6] Return(“SIP/3210-0000000b”, “TRUE”) in new stack
– Executing [[email protected]:4] GosubIf(“SIP/3210-0000000b”, “7?agent_config,1():agent_default,1()”) in new stack
– Executing [[email protected]:1] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack
– Executing [[email protected]:2] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack
– Executing [[email protected]:3] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack
– Executing [[email protected]:4] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack
– Executing [[email protected]:5] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2015-10-13 22:15:27] WARNING[16783][C-00000009]: ccss.c:1000 ast_set_cc_callback_macro: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
– Executing [[email protected]:6] ExecIf(“SIP/3210-0000000b”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack
– Executing [[email protected]:7] ExecIf(“SIP/3210-0000000b”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
– Executing [[email protected]:8] ExecIf(“SIP/3210-0000000b”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/[email protected])”) in new stack
– Executing [[email protected]:9] Set(“SIP/3210-0000000b”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2015-10-13 22:15:27] WARNING[16783][C-00000009]: ccss.c:1000 ast_set_cc_callback_macro: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
– Executing [[email protected]:10] Return(“SIP/3210-0000000b”, “”) in new stack
– Executing [[email protected]:5] Set(“SIP/3210-0000000b”, “DB(AMPUSER/3210/ccss/last_number)=3225”) in new stack
– Executing [[email protected]:6] Return(“SIP/3210-0000000b”, “”) in new stack
– Executing [[email protected]:15] ExecIf(“SIP/3210-0000000b”, “0?Set(CHANNEL(language)=)”) in new stack
– Executing [[email protected]:16] GotoIf(“SIP/3210-0000000b”, “0?continue”) in new stack
– Executing [[email protected]:17] ExecIf(“SIP/3210-0000000b”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
– Executing [[email protected]:18] Set(“SIP/3210-0000000b”, “__TTL=64”) in new stack
– Executing [[email protected]:19] GotoIf(“SIP/3210-0000000b”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,30)
– Executing [[email protected]:30] Set(“SIP/3210-0000000b”, “CALLERID(number)=3210”) in new stack
– Executing [[email protected]:31] Set(“SIP/3210-0000000b”, “CALLERID(name)=Warren - Office”) in new stack
– Executing [[email protected]:32] Set(“SIP/3210-0000000b”, “CDR(cnum)=3210”) in new stack
– Executing [[email protected]:33] Set(“SIP/3210-0000000b”, “CDR(cnam)=Warren - Office”) in new stack
– Executing [[email protected]:34] Set(“SIP/3210-0000000b”, “CHANNEL(language)=en”) in new stack
– Executing [[email protected]:2] Set(“SIP/3210-0000000b”, “RingGroupMethod=none”) in new stack
– Executing [[email protected]:3] Set(“SIP/3210-0000000b”, “__EXTTOCALL=3225”) in new stack
– Executing [[email protected]:4] Set(“SIP/3210-0000000b”, “__PICKUPMARK=3225”) in new stack
– Executing [[email protected]:5] Set(“SIP/3210-0000000b”, “RT=”) in new stack
– Executing [[email protected]:6] ExecIf(“SIP/3210-0000000b”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
– Executing [[email protected]:7] ExecIf(“SIP/3210-0000000b”, “0?MacroExit()”) in new stack
– Executing [[email protected]:8] Gosub(“SIP/3210-0000000b”, “sub-record-check,s,1(exten,3225,)”) in new stack
– Executing [[email protected]:1] Set(“SIP/3210-0000000b”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [[email protected]:2] GotoIf(“SIP/3210-0000000b”, “1?check”) in new stack
– Goto (sub-record-check,s,7)
– Executing [[email protected]:7] Set(“SIP/3210-0000000b”, “__MON_FMT=wav”) in new stack
– Executing [[email protected]:8] GotoIf(“SIP/3210-0000000b”, “1?next”) in new stack
– Goto (sub-record-check,s,11)
– Executing [[email protected]:11] ExecIf(“SIP/3210-0000000b”, “0?Return()”) in new stack
– Executing [[email protected]:12] ExecIf(“SIP/3210-0000000b”, “0?Set(__REC_POLICY_MODE=)”) in new stack
– Executing [[email protected]:13] GotoIf(“SIP/3210-0000000b”, “0?exten,1”) in new stack
– Executing [[email protected]:14] Set(“SIP/3210-0000000b”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [[email protected]:15] Set(“SIP/3210-0000000b”, “NOW=1444788927”) in new stack
– Executing [[email protected]:16] Set(“SIP/3210-0000000b”, “__DAY=13”) in new stack
– Executing [[email protected]:17] Set(“SIP/3210-0000000b”, “__MONTH=10”) in new stack
– Executing [[email protected]:18] Set(“SIP/3210-0000000b”, “__YEAR=2015”) in new stack
– Executing [[email protected]:19] Set(“SIP/3210-0000000b”, “__TIMESTR=20151013-221527”) in new stack
– Executing [[email protected]:20] Set(“SIP/3210-0000000b”, “__FROMEXTEN=3210”) in new stack
– Executing [[email protected]:21] Set(“SIP/3210-0000000b”, “__CALLFILENAME=exten-3225-3210-20151013-221527-1444788927.11”) in new stack
– Executing [[email protected]:22] Goto(“SIP/3210-0000000b”, “exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [[email protected]:1] GotoIf(“SIP/3210-0000000b”, “0?callee”) in new stack
– Executing [[email protected]:2] Set(“SIP/3210-0000000b”, “__REC_POLICY_MODE=dontcare”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/3210-0000000b”, “1?caller”) in new stack
– Goto (sub-record-check,exten,10)
– Executing [[email protected]:10] Set(“SIP/3210-0000000b”, “__REC_POLICY_MODE=dontcare”) in new stack
– Executing [[email protected]:11] GosubIf(“SIP/3210-0000000b”, “0?record,1(exten,3225,3210)”) in new stack
– Executing [[email protected]:12] Return(“SIP/3210-0000000b”, “”) in new stack
– Executing [[email protected]:9] GotoIf(“SIP/3210-0000000b”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,15)
– Executing [[email protected]:15] GosubIf(“SIP/3210-0000000b”, “0?clrheader,1()”) in new stack
– Executing [[email protected]:16] Macro(“SIP/3210-0000000b”, “dial-one,Ttr,3225”) in new stack
– Executing [[email protected]:1] Set(“SIP/3210-0000000b”, “DEXTEN=3225”) in new stack
– Executing [[email protected]:2] Set(“SIP/3210-0000000b”, “DIALSTATUS_CW=”) in new stack
– Executing [[email protected]:3] GosubIf(“SIP/3210-0000000b”, “0?screen,1()”) in new stack
– Executing [[email protected]:4] GosubIf(“SIP/3210-0000000b”, “0?cf,1()”) in new stack
– Executing [[email protected]:5] GotoIf(“SIP/3210-0000000b”, “0?skip1”) in new stack
– Executing [[email protected]:6] Set(“SIP/3210-0000000b”, “DEXTEN=”) in new stack
– Executing [[email protected]:7] Set(“SIP/3210-0000000b”, “DIALSTATUS=BUSY”) in new stack
– Executing [[email protected]:8] GotoIf(“SIP/3210-0000000b”, “1?nodial”) in new stack
– Goto (macro-dial-one,s,48)
– Executing [[email protected]:48] ExecIf(“SIP/3210-0000000b”, “0?Set(DIALSTATUS=NOANSWER)”) in new stack
– Executing [[email protected]:49] NoOp(“SIP/3210-0000000b”, “Returned from dial-one with nothing to call and DIALSTATUS: BUSY”) in new stack
– Executing [[email protected]:50] MacroExit(“SIP/3210-0000000b”, “”) in new stack
– Executing [[email protected]:17] Set(“SIP/3210-0000000b”, “SV_DIALSTATUS=BUSY”) in new stack
– Executing [[email protected]:18] GosubIf(“SIP/3210-0000000b”, “0?docfu,1()”) in new stack
– Executing [[email protected]:19] GosubIf(“SIP/3210-0000000b”, “0?docfb,1()”) in new stack
– Executing [[email protected]:20] Set(“SIP/3210-0000000b”, “DIALSTATUS=BUSY”) in new stack
– Executing [[email protected]:21] ExecIf(“SIP/3210-0000000b”, “0?MacroExit()”) in new stack
– Executing [[email protected]:22] GotoIf(“SIP/3210-0000000b”, “1?s-BUSY,1”) in new stack
– Goto (macro-exten-vm,s-BUSY,1)
– Executing [[email protected]:1] GotoIf(“SIP/3210-0000000b”, “0?exit,1”) in new stack
– Executing [[email protected]:2] PlayTones(“SIP/3210-0000000b”, “busy”) in new stack
Audio is at 17794
Adding codec 100003 (ulaw) to SDP
Adding codec 100004 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Transmitting (NAT) to 192.168.1.200:5060 —>
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK229e0cc68B6BFF7F;received=192.168.1.200;rport=5060
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone;tag=as4e5b9a10
Call-ID: [email protected]
CSeq: 2 INVITE
Server: FPBX-2.11.0(11.13.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Content-Length: 256

v=0
o=root 595011679 595011679 IN IP4 192.168.1.3
s=Asterisk PBX 11.13.0
c=IN IP4 192.168.1.3
t=0 0
m=audio 17794 RTP/AVP 0 8 127
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-16
a=ptime:20
a=sendrecv

<------------>
– Executing [[email protected]:3] Busy(“SIP/3210-0000000b”, “20”) in new stack

<— Reliably Transmitting (NAT) to 192.168.1.200:5060 —>
SIP/2.0 486 Busy Here
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK229e0cc68B6BFF7F;received=192.168.1.200;rport=5060
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone;tag=as4e5b9a10
Call-ID: [email protected]
CSeq: 2 INVITE
Server: FPBX-2.11.0(11.13.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces
Content-Length: 0

<------------>
== Spawn extension (macro-exten-vm, s-BUSY, 3) exited non-zero on ‘SIP/3210-0000000b’ in macro ‘exten-vm’
== Spawn extension (from-internal, 3225, 2) exited non-zero on ‘SIP/3210-0000000b’
– Executing [[email protected]:1] Hangup(“SIP/3210-0000000b”, “”) in new stack
== Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/3210-0000000b’

<— SIP read from UDP:192.168.1.200:5060 —>
ACK sip:[email protected]:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK229e0cc68B6BFF7F
From: “Warren Zinger” sip:[email protected];tag=A2B56497-57619558
To: sip:[email protected];user=phone;tag=as4e5b9a10
CSeq: 2 ACK
Call-ID: 6db[email protected]
Contact: sip:[email protected]
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_650-UA/3.3.3.0069
Accept-Language: en-ca,en;q=0.9
Max-Forwards: 70
Content-Length: 0

<------------->
— (12 headers 0 lines) —
Really destroying SIP dialog ‘[email protected]’ Method: ACK
Really destroying SIP dialog ‘[email protected]’ Method: REGISTER
WNDSON14DS0*CLI>

Really scratching my head here. Any suggestions, gurus? What am I missing/not seeing? There’s no reason why the phone should be giving me a 486 Busy Here message, there’s no calls on the darn thing… sip show channels shows 0 active SIP dialogs…

Could it be a problem with CODECs? I see you are using g729 which I have heard needs a license to be used.

I am very new to this… please take my suggestion with a grain of salt.