Everyone is busy/congested at this time

Asterisk 13 with FreePBX 13.0.6 Clean install.

Running a Chrome Browser client and a Polycom desk phone on the same LAN as the PBX.

I have 2 extensions. 1 allocated to the Polycom and 1 in use via UCP.

I can ring the Polycom from the UCP and I get a call established with bidirectional audio.

If I ring the UCP extension from the Polycom it goes to voicemail and the logs show the following:-

[2015-10-27 15:52:20] WARNING[63831][C-00000034] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] netsock2.c: Using SIP VIDEO TOS bits 136
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] netsock2.c: Using SIP VIDEO CoS mark 6
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] netsock2.c: Using SIP RTP TOS bits 184
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] netsock2.c: Using SIP RTP CoS mark 5
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] app_stack.c: SIP/991576-0000005b Internal Gosub(func-apply-sipheaders,s,1) start
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp(“SIP/991576-0000005b”, “Applying SIP Headers to channel”) in new stack
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] pbx.c: Executing [s@func-apply-sipheaders:2] Set(“SIP/991576-0000005b”, “SIPHEADERKEYS=”) in new stack
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] pbx.c: Executing [s@func-apply-sipheaders:3] While(“SIP/991576-0000005b”, “0”) in new stack
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] app_while.c: Jumping to priority 7
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] pbx.c: Executing [s@func-apply-sipheaders:8] Return(“SIP/991576-0000005b”, “”) in new stack
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] app_stack.c: Spawn extension (from-internal, 1576, 1) exited non-zero on ‘SIP/991576-0000005b’
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] app_stack.c: SIP/991576-0000005b Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] app_dial.c: Called SIP/991576
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] app_dial.c: Connected line update to SIP/1488-0000005a prevented.
[2015-10-27 15:52:20] VERBOSE[63831][C-00000034] app_dial.c: SIP/991576-0000005b is ringing
[2015-10-27 15:52:23] VERBOSE[63831][C-00000034] app_dial.c: Everyone is busy/congested at this time (2:0/0/2)

To make things more confusing… if I take out the Polycom and have a second UCP in it’s place… I get the same issue dialling UCP to UCP so it looks like there’s an issue ONLY if the call is Inbound to UCP.

UPDATE
More testing done:-

Now have 2x Polycom 321 handsets registered (exts 1488 and 1573). Calls to/from either Polycom extension to the other all works perfectly with bidirectional audio.

Calls between Polycom handset and SIP Softphones work fine in both directions with bi-directional audio.

however…
If I log one extension (ext.1573) into UCP…
If I call from UCP (1573) to the other extension (1488) everything works perfectly.
If I call from Polycom (1488) to ext.1573 both UCP and the Polycom ring but I cannot pickup from UCP???

I get the following in the log…

-- Called SIP/1573
-- Called SIP/991573
-- Connected line update to SIP/1488-000000a6 prevented.
-- Connected line update to SIP/1488-000000a6 prevented.
-- SIP/991573-000000a8 is ringing
-- SIP/1573-000000a7 is ringing
-- Nobody picked up in 15000 ms

I picked up on UCP at this point but the Polycom continued to ring until VM cut in.

Any ideas?

Thanks in advance.

Mike

Hi,

You have problems with the update procedures (Connected line update to SIP/1488-000000a6 prevented) . What is configured on your rpid settings of the extensions?

Thank you,

Daniel Friedman
Trixton LTD.

Hi

Send RPID is set to no.
Extensions 1488/1573 work fine. It’s the 991488 and 991573 WebRTC extensions that won’t receive incoming calls. They can make outgoing with no problem but incoming goes to VM.

Not sure if WebRTC calls even use RPID?

Cheers

Hi,

Try to replace the RPID to PAI instead of no.
Send the logs again. It is better you will send the sip log as well (sip set debug peer 991573).

Thank you,

Daniel Friedman
Trixton LTD.

This is the output…

HT-AZ-FPBX-01*CLI> sip set debug peer 991573
SIP Debugging Enabled for IP: 10.1.0.1
[2015-10-29 13:11:53] WARNING[24628][C-00000070]: app_dial.c:2411 dial_exec_full: Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)
Audio is at 13158
Video is at 192.168.50.6:12308
Adding codec ulaw to SDP
Adding codec alaw to SDP
Adding codec gsm to SDP
Adding codec g726 to SDP
Adding codec g722 to SDP
Adding video codec h264 to SDP
Adding video codec mpeg4 to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 10.1.0.1:10696:
INVITE sip:[email protected];transport=ws SIP/2.0
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK7470aed0
Max-Forwards: 70
From: “Mark Johns” sip:[email protected]:5061;tag=as2931964c
To: sip:[email protected];transport=ws
Contact: sip:[email protected]:5061;transport=WS
Call-ID: [email protected]:5061
CSeq: 102 INVITE
User-Agent: FPBX-13.0.6(13.6.0)
Date: Thu, 29 Oct 2015 13:11:53 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 1607

v=0
o=root 863708706 863708706 IN IP4 192.168.50.6
s=Asterisk PBX 13.6.0
c=IN IP4 192.168.50.6
b=CT:384
t=0 0
m=audio 13158 RTP/SAVPF 0 8 3 111 9 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:111 G726-32/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=ice-ufrag:447d9a1d4c375b48671268f56139c954
a=ice-pwd:58de4b405abd2937179a2a992899dc1e
a=candidate:Hc0a83206 1 UDP 2130706431 192.168.50.6 13158 typ host
a=candidate:S28761a0f 1 UDP 1694498815 40.118.26.15 13158 typ srflx raddr 192.168.50.6 rport 13158
a=candidate:Hc0a83206 2 UDP 2130706430 192.168.50.6 13159 typ host
a=candidate:S28761a0f 2 UDP 1694498814 40.118.26.15 13159 typ srflx raddr 192.168.50.6 rport 13159
a=connection:new
a=setup:actpass
a=fingerprint:SHA-256 D8:68:EE:10:C0:1A:E5:97:A7:E1:4F:E9:40:90:0D:48:FD:53:8F:94:75:C3:9B:B0:3B:7D:5D:D2:E5:4C:C8:BC
a=sendrecv
m=video 12308 RTP/SAVPF 99 104
a=ice-ufrag:6bc8697654bc8bb45e9690376a7af41a
a=ice-pwd:59d26eee0d531ce6101580801f2ecd09
a=candidate:Hc0a83206 1 UDP 2130706431 192.168.50.6 12308 typ host
a=candidate:S28761a0f 1 UDP 1694498815 40.118.26.15 12308 typ srflx raddr 192.168.50.6 rport 12308
a=candidate:Hc0a83206 2 UDP 2130706430 192.168.50.6 12309 typ host
a=candidate:S28761a0f 2 UDP 1694498814 40.118.26.15 12309 typ srflx raddr 192.168.50.6 rport 12309
a=connection:new
a=setup:actpass
a=fingerprint:SHA-256 D8:68:EE:10:C0:1A:E5:97:A7:E1:4F:E9:40:90:0D:48:FD:53:8F:94:75:C3:9B:B0:3B:7D:5D:D2:E5:4C:C8:BC
a=rtpmap:99 H264/90000
a=rtpmap:104 MP4V-ES/90000
a=sendrecv


<— SIP read from WS:10.1.0.1:10696 —>
SIP/2.0 100 Trying
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK7470aed0
To: sip:[email protected];transport=ws
From: “Mark Johns” sip:[email protected]:5061;tag=as2931964c
Call-ID: [email protected]:5061
CSeq: 102 INVITE
Supported: timer,ice,outbound
Content-Length: 0

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

<— SIP read from WS:10.1.0.1:10696 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK7470aed0
To: sip:[email protected];transport=ws;tag=jkg1ilfktf
From: “Mark Johns” sip:[email protected]:5061;tag=as2931964c
Call-ID: [email protected]:5061
CSeq: 102 INVITE
Contact: sip:[email protected];transport=ws
Supported: timer,ice,outbound
Content-Length: 0

<------------->
— (9 headers 0 lines) —
sip_route_dump: route/path hop: sip:[email protected];transport=ws

<— SIP read from WS:10.1.0.1:10696 —>
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK7470aed0
To: sip:[email protected];transport=ws;tag=jkg1ilfktf
From: “Mark Johns” sip:[email protected]:5061;tag=as2931964c
Call-ID: [email protected]:5061
CSeq: 102 INVITE
Supported: timer,ice,outbound
Content-Length: 0

<------------->
— (8 headers 0 lines) —
Transmitting (no NAT) to 10.1.0.1:10696:
ACK sip:[email protected];transport=ws SIP/2.0
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK7470aed0
Max-Forwards: 70
From: “Mark Johns” sip:[email protected]:5061;tag=as2931964c
To: sip:[email protected];transport=ws;tag=jkg1ilfktf
Contact: sip:[email protected]:5061;transport=WS
Call-ID: [email protected]:5061
CSeq: 102 ACK
User-Agent: FPBX-13.0.6(13.6.0)
Content-Length: 0


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

<— SIP read from WS:10.1.0.1:10696 —>
REGISTER sip:telephony.htempest.co.uk SIP/2.0
Via: SIP/2.0/WS ln5mil4673qa.invalid;branch=z9hG4bK7484914
Max-Forwards: 69
To: sip:[email protected]
From: sip:[email protected];tag=cgavaccdkt
Call-ID: se0sc7105ku0vvlvgcr2g5
CSeq: 2647 REGISTER
Contact: sip:[email protected];transport=ws;+sip.ice;reg-id=1;+sip.instance=“urn:uuid:2a2ef2a0-99b3-4e47-b4a4-b242afa91cc5”;expires=600
Expires: 600
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS
Supported: path,gruu,outbound
User-Agent: JsSIP 0.6.30
Content-Length: 0

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

<— SIP read from WS:10.1.0.1:10696 —>
REGISTER sip:telephony.htempest.co.uk SIP/2.0
Via: SIP/2.0/WS ln5mil4673qa.invalid;branch=z9hG4bK6303346
Max-Forwards: 69
To: sip:[email protected]
From: sip:[email protected];tag=cgavaccdkt
Call-ID: se0sc7105ku0vvlvgcr2g5
CSeq: 2648 REGISTER
Authorization: Digest algorithm=MD5, username=“991573”, realm=“asterisk”, nonce=“265ee5cf”, uri=“sip:telephony.htempest.co.uk”, response=“679c46098094bba28db4635f0e90910f”
Contact: sip:[email protected];transport=ws;+sip.ice;reg-id=1;+sip.instance=“urn:uuid:2a2ef2a0-99b3-4e47-b4a4-b242afa91cc5”;expires=600
Expires: 600
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS
Supported: path,gruu,outbound
User-Agent: JsSIP 0.6.30
Content-Length: 0

<------------->
— (14 headers 0 lines) —
Reliably Transmitting (no NAT) to 10.1.0.1:10696:
OPTIONS sip:[email protected];transport=ws SIP/2.0
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK7815a0ec
Max-Forwards: 70
From: “Unknown” sip:[email protected]:5061;tag=as79bf20ee
To: sip:[email protected];transport=ws
Contact: sip:[email protected]:5061;transport=WS
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
User-Agent: FPBX-13.0.6(13.6.0)
Date: Thu, 29 Oct 2015 13:12:03 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


Scheduling destruction of SIP dialog ‘[email protected]:5061’ in 6400 ms (Method: NOTIFY)
Reliably Transmitting (no NAT) to 10.1.0.1:10696:
NOTIFY sip:[email protected];transport=ws SIP/2.0
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK0f18badd
Max-Forwards: 70
From: “Unknown” sip:[email protected]:5061;tag=as713b26ed
To: sip:[email protected];transport=ws
Contact: sip:[email protected]:5061;transport=WS
Call-ID: [email protected]:5061
CSeq: 102 NOTIFY
User-Agent: FPBX-13.0.6(13.6.0)
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 105

Messages-Waiting: no
Message-Account: sip:*[email protected]:5061;transport=WS
Voice-Message: 0/0 (0/0)


<— SIP read from WS:10.1.0.1:10696 —>
SIP/2.0 200 OK
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK7815a0ec
To: sip:[email protected];transport=ws;tag=tg5rm4qds7
From: “Unknown” sip:[email protected]:5061;tag=as79bf20ee
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS
Accept: application/sdp, application/dtmf-relay
Supported: outbound
Content-Length: 0

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

<— SIP read from WS:10.1.0.1:10696 —>
SIP/2.0 405 Method Not Allowed
Via: SIP/2.0/WS 192.168.50.6:5061;branch=z9hG4bK0f18badd
To: sip:[email protected];transport=ws;tag=pbvs0uitos
From: “Unknown” sip:[email protected]:5061;tag=as713b26ed
Call-ID: [email protected]:5061
CSeq: 102 NOTIFY
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,MESSAGE,OPTIONS
Supported: outbound
Content-Length: 0

<------------->
— (9 headers 0 lines) —
Really destroying SIP dialog ‘[email protected]:5061’ Method: OPTIONS
Really destroying SIP dialog ‘[email protected]:5061’ Method: INVITE
Really destroying SIP dialog ‘[email protected]:5061’ Method: NOTIFY
[2015-10-29 13:12:13] NOTICE[14359]: chan_sip.c:16713 check_auth: Correct auth, but based on stale nonce received from ‘“Mark.” sip:[email protected]:5061;tag=2B6443B0-112F6FD7’
HT-AZ-FPBX-01*CLI>

Hi,

You have a codec problem. It suggests that your ip phone does not support SRTP or TLS probably. Check your configuration again and make sure you are allowing TLS in the registration field.
I also think that you have a NAT problem as well.

Thank you,

Daniel Friedman
Trixton LTD.

Wouldn’t that then mean that calls from 991573 to 1488 wouldn’t work either?

At the moment…
if I dial from 991573 to 1488 I can establish a call and have bidirectional audio.
if I dial from 1488 to 991573 I get ringing on the UCP but when I answer the call 1488 is diverted to VM.

If there was a protocol or codec issue I wouldn’t have thought I’d be able to establish a call in either direction??

Thanks again for looking… I’m a bit of a noob really and extremely grateful of your help.

Hi,

You should always call to your “regular” extension so it will ring on your UCP extension if it is connected. You have a some sort of a codec problem that is usually happens if your end phones do not support TLS + SRTP.

Did you try calling from one UCP extension to another UCP extension (by not calling directly to the UCP number) ?

Thank you,

Daniel Friedman
Trixton LTD

Hi

Yeah, initially I wanted to use the system with only UCP but, if I call from UCP to UCP I get the issue of the destination ringing but, on answer, it goes straight to VM.

Because it’s UCP to UCP I get this issue from both extensions.

I added a SIP phone to diagnose the issue and found that, dialling UCP to SIP works but SIP to UCP doesn’t.

By deduction I have found that the issue is with incoming calls to UCP, irrespective of whether the source is SIP or another UCP extension.

SIP to SIP calls all work perfectly.

Hi,

I still think that it is a codec problem that concerns to TLS + SRTP. Try to make your tests with end phones who support TLS + SRTP.

Thank you,

Daniel Friedman
Trixton LTD.

I have already tried. I have Polycom 321’s, Yealink T20P’s and Zoiper and Bria softphones with TLS enabled.

Surely though… UCP will ALWAYS use SRTP so dialling from UCP to UCP will, by default, use DTLS and SRTP? If it is a TLS/STP issue it would have to be a configurable option in FreePBX that is turned off??? I just don’t know where.

Hi,

I suspect that this is a bug of the Freepbx 13. How about trying this with the Freepbx 12 and Asterisk 11 ?

Thank you,

Daniel Friedman
Trixton LTD.

I have everything working fine on Asterisk 11 with FreePBX 12.

There are some really cool additions in FreePBX 13 that I really want to use but it looks like I may have to wait until it goes stable. :frowning: It’s been a long while in the making. :smile:

Thanks