I decided to bite the bullet and upgrade to the latest. Rather than run through all the scripts and risk problems, I created a second server and installed from scratch.
Previously, the *806004 would cause extension 6004 to ring once and pickup on speaker.
Now it rings once and drops the call.
I was on a very old version, so I don’t know where to start looking for how to debug this problem?
Latest distro, latest modules, commercial EPM. Polycom 335 phones.
Thanks,
Check your endpoint template and ensure ‘auto answer’ is enabled.
If the template is fine then look in the logs. I had an issue recently where something in the router was causing some phones to not auto answer. It was doing the same thing you describe, where it would ring once and then hang up, even though the phone sending the page thought it was talking to the other phones. We were replacing the routers anyway, which fixed the issue. These were Polycom 335s and 550s.
Thanks. I’ll look at the logs. I did move the server external (freepbxhosting) and now I have several phones behind a NAT (no helpers). So perhaps this is related. I’ll update my internal server to the same versions and see if I can get paging to work again.
I’m still not quite sure where to look in the template. The config file (in /tftpboot) changed pretty significantly from the very old version I was using.
The asterisk log is showing
full-20160409:[2016-04-08 17:36:18] VERBOSE[26873][C-00000063] pbx.c: Executing [*806003@ext-intercom:15] Set("PJSIP/6000-0000000f", "_ALERTINFO=Ring Answer") in new stack
But I’m not finding “Ring Answer” in the /tftpboot config files for that phone from EPM. The closest I find is Auto Answer
<voIpProt.SIP.alertInfo
voIpProt.SIP.alertInfo.1.class="ringAutoAnswer"
voIpProt.SIP.alertInfo.1.value="Auto Answer"
voIpProt.SIP.alertInfo.2.class="default"
voIpProt.SIP.alertInfo.2.value=""
>
I’m seeing this line in the externsions_additional.conf file, but per the /var/log/asterisk/full log, it’s sending Ring Answer.
exten => s,n,ExecIf($["${USERAGENT:0:7}" = "Polycom"]?Set(ALERTINFO=info=Auto Answer))
I also moved to PJSIP at the same time, perhaps I’ll also try to switch back to chan_sip and see if that changes anything.
Oops - I do see some manipulation of Alert Info, possibly to Auto Answer. I’ll look at this more tomorrow.
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:21] GotoIf("PJSIP/6000-00000002", "0?macro") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:22] Set("PJSIP/6000-00000002", "USERAGENT=") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:23] ExecIf("PJSIP/6000-00000002", "0?Set(USERAGENT=)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:24] ExecIf("PJSIP/6000-00000002", "0?Set(CALLINFO=<sip:broadworks.net>;answer-after=0)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:25] ExecIf("PJSIP/6000-00000002", "0?Set(ALERTINFO=Intercom)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:26] ExecIf("PJSIP/6000-00000002", "0?Set(ALERTINFO=info=Auto Answer)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:27] ExecIf("PJSIP/6000-00000002", "0?Set(ALERTINFO=ring-answer)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@macro-autoanswer:28] ExecIf("PJSIP/6000-00000002", "1?Set(__SIP_URI_OPTIONS=intercom=true)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:22] Set("PJSIP/6000-00000002", "_DOPTIONS=A(beep)b(autoanswer^s^1(Ring Answer,<uri>;answer-after=0))") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:23] ChanIsAvail("PJSIP/6000-00000002", "PJSIP/6003,s") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:24] ExecIf("PJSIP/6000-00000002", "0?Set(AVAILORIGCHAN=PJSIP/6003)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:25] GotoIf("PJSIP/6000-00000002", "1?continue") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Goto (ext-intercom,*806003,30)
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:30] NoOp("PJSIP/6000-00000002", "Continuing with page") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:31] GotoIf("PJSIP/6000-00000002", "0?godial") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:32] Set("PJSIP/6000-00000002", "CONNECTEDLINE(name,i)=Natalie") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:33] Set("PJSIP/6000-00000002", "CONNECTEDLINE(num)=6003") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [*806003@ext-intercom:34] Dial("PJSIP/6000-00000002", "PJSIP/6003/sip:[email protected]:1043,5,IA(beep)b(autoanswer^s^1(Ring Answer,<uri>;answer-after=0))") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] app_stack.c: PJSIP/6003-00000004 Internal Gosub(autoanswer,s,1(Ring Answer,<uri>;answer-after=0)) start
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@autoanswer:1] GosubIf("PJSIP/6003-00000004", "1?addheader,1(Alert-Info,Ring Answer)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [addheader@autoanswer:1] SIPAddHeader("PJSIP/6003-00000004", "Alert-Info: Ring Answer") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [addheader@autoanswer:2] Set("PJSIP/6003-00000004", "PJSIP_HEADER(add,Alert-Info)=Ring Answer") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [addheader@autoanswer:3] Return("PJSIP/6003-00000004", "") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@autoanswer:2] GosubIf("PJSIP/6003-00000004", "1?addheader,1(Call-Info,<uri>;answer-after=0)") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [addheader@autoanswer:1] SIPAddHeader("PJSIP/6003-00000004", "Call-Info: <uri>;answer-after=0") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [addheader@autoanswer:2] Set("PJSIP/6003-00000004", "PJSIP_HEADER(add,Call-Info)=<uri>;answer-after=0") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [addheader@autoanswer:3] Return("PJSIP/6003-00000004", "") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] pbx.c: Executing [s@autoanswer:3] Return("PJSIP/6003-00000004", "") in new stack
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] app_stack.c: Spawn extension (from-internal, *806003, 1) exited non-zero on 'PJSIP/6003-00000004'
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] app_stack.c: PJSIP/6003-00000004 Internal Gosub(autoanswer,s,1(Ring Answer,<uri>;answer-after=0)) complete GOSUB_RETVAL=
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] app_dial.c: Called PJSIP/6003/sip:[email protected]:1043
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] app_dial.c: Connected line update to PJSIP/6000-00000002 prevented.
[2016-04-08 16:31:27] VERBOSE[18104][C-00000037] app_dial.c: PJSIP/6003-00000004 is ringing
[2016-04-08 16:31:32] VERBOSE[18104][C-00000037] app_dial.c: Nobody picked up in 5000 mspjsip set logger host is showing Ring Answer in the SIP headers.
INVITE sip:[email protected]:1044 SIP/2.0^M
Via: SIP/2.0/UDP xxx.xxx.xx.xxx:5061;rport;branch=z9hG4bKPjSB5kghgiERDdzTmduwzYN8EZDhbDy5PX^M
From: "6051" <sip:[email protected]>;tag=ykl9aNPv25eEoEClVte8jYmSwIQoIDL3^M
To: <sip:[email protected]>^M
Contact: <sip:[email protected]:5061>^M
Call-ID: 5GOoOxI6TlWMoH75rCUkB4mCz9E-clW4^M
CSeq: 29411 INVITE^M
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REGISTER, REFER^M
Supported: 100rel, timer, replaces, norefersub^M
Session-Expires: 1800^M
Min-SE: 90^M
Alert-Info: Ring Answer^M
Call-Info: <uri>;answer-after=0^M
P-Asserted-Identity: "6051" <sip:[email protected]>^M
Max-Forwards: 70^M
User-Agent: FPBX-13.0.105(13.7.2)^M
Content-Type: application/sdp^M
Content-Length: 315^M
^M
v=0^M
o=- 50840059 50840059 IN IP4 162.221.91.171^M
s=Asterisk^M
c=IN IP4 xxx.xxx.xx.xxx^M
t=0 0^M
m=audio 15556 RTP/AVP 0 8 3 111 101^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:8 PCMA/8000^M
a=rtpmap:3 GSM/8000^M
a=rtpmap:111 G726-32/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-16^M
a=ptime:20^M
a=maxptime:150^M
a=sendrecv^MChanged the endpoint I was paging to CHAN_SIP and paging works.
Changed the endpoint back to CHAN_PJSIP, broken.
Edited extensions_additional.conf and replaced both instances of “Ring Answer” with “Auto Answer”, did asterisk reload from the command line, and paging works.
Given the PJSIP headers were showing “Ring Answer”, it appears that the problem is in the PJSIP interaction with the code that updates Ring Answer for Polycom phones.
Any experts out there?
Ever find that you just can’t put down a book?
The problem is the lack of SIPPEER in PJSIP.
exten => s,n,Set(USERAGENT=${SIPPEER(${CUT(DIAL,/,2)},useragent)})
is returning nothing and isn’t defined in CHAN_PJSIP. Google finds lots of references to SIPPEER / PJSIP but I don’t see a clear solution with my lack of dial plan experience.
Yeah, pjsip is just not there yet. Use chan_sip extensions.
Paging isn’t make/break for me. I think I’ll keep with PJSIP for a while longer. My phones seam more stable with it, but that’s tough to tell for sure. Sometimes my network is more solid than other days.
I filed a ticket so hopefully it eventually gets addressed in PJSIP or the dial plan.
Just wanted to thank the freepbx guys for fixing this! I installed the fix they provided a long while ago, but just switched back to PJSIP and confirmed it worked 
Thanks!