Ring groups issue

ErikU · February 3, 2017, 7:29pm

I am running the latest SNG distro, and I did update all modules last night: 14.0.1Beta13

Today, I found that none of my ring groups perform as they had been. When a trunk is routed to a ring group, none of the extensions ring and the call is routed directly to the Destination is No Answer, which is currently an IVR. If I change the destination if no answer to a single extension, it will ring to that single extension. I have tried the following:

Deleting and rebuilding the ring group.
Building a new ring group with a single extension, and routing the trunk to that group
Rebooting
Rebooting extensions

In every other way extensions seem to behave normally.

At this point, I’m going to need some assistance. I do find it odd that I updated all modules last night, though I have been updating modules regularly.

Here is the asterisk snippet:

 == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [2068298170@from-trunk:1] Set("SIP/Lightpress-00000002", "__DIRECTION=INBOUND") in new stack
    -- Executing [2068298170@from-trunk:2] Gosub("SIP/Lightpress-00000002", "sub-record-check,s,1(in,2068298170,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("SIP/Lightpress-00000002", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("SIP/Lightpress-00000002", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("SIP/Lightpress-00000002", "NOW=1486149604") in new stack
    -- Executing [s@sub-record-check:4] Set("SIP/Lightpress-00000002", "__DAY=03") in new stack
    -- Executing [s@sub-record-check:5] Set("SIP/Lightpress-00000002", "__MONTH=02") in new stack
    -- Executing [s@sub-record-check:6] Set("SIP/Lightpress-00000002", "__YEAR=2017") in new stack
    -- Executing [s@sub-record-check:7] Set("SIP/Lightpress-00000002", "__TIMESTR=20170203-112004") in new stack
    -- Executing [s@sub-record-check:8] Set("SIP/Lightpress-00000002", "__FROMEXTEN=unknown") in new stack
    -- Executing [s@sub-record-check:9] Set("SIP/Lightpress-00000002", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:10] NoOp("SIP/Lightpress-00000002", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("SIP/Lightpress-00000002", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("SIP/Lightpress-00000002", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("SIP/Lightpress-00000002", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("SIP/Lightpress-00000002", "2?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("SIP/Lightpress-00000002", "1?sub-record-check,in,1") in new stack
    -- Goto (sub-record-check,in,1)
    -- Executing [in@sub-record-check:1] NoOp("SIP/Lightpress-00000002", "Inbound Recording Check to 2068298170") in new stack
    -- Executing [in@sub-record-check:2] Set("SIP/Lightpress-00000002", "FROMEXTEN=unknown") in new stack
    -- Executing [in@sub-record-check:3] ExecIf("SIP/Lightpress-00000002", "10?Set(FROMEXTEN=2062956765)") in new stack
    -- Executing [in@sub-record-check:4] Gosub("SIP/Lightpress-00000002", "recordcheck,1(dontcare,in,2068298170)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/Lightpress-00000002", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("SIP/Lightpress-00000002", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("SIP/Lightpress-00000002", "") in new stack
    -- Executing [in@sub-record-check:5] Return("SIP/Lightpress-00000002", "") in new stack
    -- Executing [2068298170@from-trunk:3] Gosub("SIP/Lightpress-00000002", "app-blacklist-check,s,1()") in new stack
    -- Executing [s@app-blacklist-check:1] GotoIf("SIP/Lightpress-00000002", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:2] Set("SIP/Lightpress-00000002", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:3] Return("SIP/Lightpress-00000002", "") in new stack
    -- Executing [2068298170@from-trunk:4] Set("SIP/Lightpress-00000002", "__FROM_DID=2068298170") in new stack
    -- Executing [2068298170@from-trunk:5] Set("SIP/Lightpress-00000002", "CDR(did)=2068298170") in new stack
    -- Executing [2068298170@from-trunk:6] ExecIf("SIP/Lightpress-00000002", "0 ?Set(CALLERID(name)=2062956765)") in new stack
    -- Executing [2068298170@from-trunk:7] Set("SIP/Lightpress-00000002", "__MOHCLASS=") in new stack
    -- Executing [2068298170@from-trunk:8] Set("SIP/Lightpress-00000002", "__REVERSAL_REJECT=FALSE") in new stack
    -- Executing [2068298170@from-trunk:9] GotoIf("SIP/Lightpress-00000002", "1?post-reverse-charge") in new stack
    -- Goto (from-trunk,2068298170,11)
    -- Executing [2068298170@from-trunk:11] NoOp("SIP/Lightpress-00000002", "") in new stack
    -- Executing [2068298170@from-trunk:12] Set("SIP/Lightpress-00000002", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
    -- Executing [2068298170@from-trunk:13] Set("SIP/Lightpress-00000002", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
    -- Executing [2068298170@from-trunk:14] Set("SIP/Lightpress-00000002", "CALLERID(name-pres)=allowed_not_screened") in new stack
    -- Executing [2068298170@from-trunk:15] Set("SIP/Lightpress-00000002", "CALLERID(num-pres)=allowed_not_screened") in new stack
    -- Executing [2068298170@from-trunk:16] Set("SIP/Lightpress-00000002", "__ALERT_INFO=custom6") in new stack
    -- Executing [2068298170@from-trunk:17] Set("SIP/Lightpress-00000002", "CIDSFSCHEME=QUxMfEFMTA==") in new stack
    -- Executing [2068298170@from-trunk:18] AGI("SIP/Lightpress-00000002", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack
    -- Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Executing Scheme..
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Scheme Asked is: ALL
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: The DID is: 2068298170
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: The CNUM is: 2062956765
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: The CNAME is: 2062956765
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi:
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Starting scheme Default
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Converting result to UTF-8
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Setting caller id to:  Erik Utter
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Determined to be: 'Erik Utter'
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: Attempting to set lookupcid
    -- <SIP/Lightpress-00000002>AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi completed, returning 0
    -- Executing [2068298170@from-trunk:19] Set("SIP/Lightpress-00000002", "CALLERID(name)=Erik Utter") in new stack
    -- Executing [2068298170@from-trunk:20] NoOp("SIP/Lightpress-00000002", "CallerID Entry Point") in new stack
    -- Executing [2068298170@from-trunk:21] Macro("SIP/Lightpress-00000002", "prepend-cid,Main: ") in new stack
    -- Executing [s@macro-prepend-cid:1] GotoIf("SIP/Lightpress-00000002", "1?REPCID") in new stack
    -- Goto (macro-prepend-cid,s,5)
    -- Executing [s@macro-prepend-cid:5] Set("SIP/Lightpress-00000002", "_RGPREFIX=Main: ") in new stack
    -- Executing [s@macro-prepend-cid:6] Set("SIP/Lightpress-00000002", "CALLERID(name)=Main: Erik Utter") in new stack
    -- Executing [2068298170@from-trunk:22] Goto("SIP/Lightpress-00000002", "ext-group,615,1") in new stack
    -- Goto (ext-group,615,1)
    -- Executing [615@ext-group:1] GotoIf("SIP/Lightpress-00000002", "0?cid") in new stack
    -- Executing [615@ext-group:2] PlayTones("SIP/Lightpress-00000002", "ring") in new stack
    -- Executing [615@ext-group:3] Progress("SIP/Lightpress-00000002", "") in new stack
    -- Executing [615@ext-group:4] Macro("SIP/Lightpress-00000002", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/Lightpress-00000002", "TOUCH_MONITOR=1486149604.2") in new stack
    -- Executing [s@macro-user-callerid:2] Set("SIP/Lightpress-00000002", "AMPUSER=2062956765") in new stack
    -- Executing [s@macro-user-callerid:3] GotoIf("SIP/Lightpress-00000002", "0?report") in new stack
    -- Executing [s@macro-user-callerid:4] ExecIf("SIP/Lightpress-00000002", "1?Set(__REALCALLERIDNUM=2062956765)") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/Lightpress-00000002", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/Lightpress-00000002", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:7] Set("SIP/Lightpress-00000002", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:8] GotoIf("SIP/Lightpress-00000002", "1?report") in new stack
    -- Goto (macro-user-callerid,s,15)
    -- Executing [s@macro-user-callerid:15] GotoIf("SIP/Lightpress-00000002", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:16] ExecIf("SIP/Lightpress-00000002", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    -- Executing [s@macro-user-callerid:17] Set("SIP/Lightpress-00000002", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:18] GotoIf("SIP/Lightpress-00000002", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,29)
    -- Executing [s@macro-user-callerid:29] Set("SIP/Lightpress-00000002", "CALLERID(number)=2062956765") in new stack
    -- Executing [s@macro-user-callerid:30] Set("SIP/Lightpress-00000002", "CALLERID(name)=Main: Erik Utter") in new stack
    -- Executing [s@macro-user-callerid:31] GotoIf("SIP/Lightpress-00000002", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:32] Set("SIP/Lightpress-00000002", "CDR(cnam)=Main: Erik Utter") in new stack
    -- Executing [s@macro-user-callerid:33] Set("SIP/Lightpress-00000002", "CDR(cnum)=2062956765") in new stack
    -- Executing [s@macro-user-callerid:34] Set("SIP/Lightpress-00000002", "CHANNEL(language)=en") in new stack
    -- Executing [615@ext-group:5] Macro("SIP/Lightpress-00000002", "blkvm-setifempty,") in new stack
    -- Executing [s@macro-blkvm-setifempty:1] GotoIf("SIP/Lightpress-00000002", "1?init") in new stack
    -- Goto (macro-blkvm-setifempty,s,4)
    -- Executing [s@macro-blkvm-setifempty:4] Set("SIP/Lightpress-00000002", "__BLKVM_CHANNEL=SIP/Lightpress-00000002") in new stack
    -- Executing [s@macro-blkvm-setifempty:5] Set("SIP/Lightpress-00000002", "SHARED(BLKVM,SIP/Lightpress-00000002)=TRUE") in new stack
    -- Executing [s@macro-blkvm-setifempty:6] Set("SIP/Lightpress-00000002", "GOSUB_RETVAL=TRUE") in new stack
    -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/Lightpress-00000002", "") in new stack
    -- Executing [615@ext-group:6] GotoIf("SIP/Lightpress-00000002", "1?skipov") in new stack
    -- Goto (ext-group,615,9)
    -- Executing [615@ext-group:9] Set("SIP/Lightpress-00000002", "RRNODEST=") in new stack
    -- Executing [615@ext-group:10] Set("SIP/Lightpress-00000002", "__NODEST=615") in new stack
    -- Executing [615@ext-group:11] GosubIf("SIP/Lightpress-00000002", "0?sub-rgsetcid,s,1()") in new stack
    -- Executing [615@ext-group:12] Gosub("SIP/Lightpress-00000002", "sub-record-check,s,1(rg,615,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("SIP/Lightpress-00000002", "10?initialized") in new stack
    -- Goto (sub-record-check,s,10)
    -- Executing [s@sub-record-check:10] NoOp("SIP/Lightpress-00000002", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("SIP/Lightpress-00000002", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("SIP/Lightpress-00000002", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("SIP/Lightpress-00000002", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("SIP/Lightpress-00000002", "2?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("SIP/Lightpress-00000002", "0?sub-record-check,rg,1") in new stack
    -- Executing [s@sub-record-check:18] NoOp("SIP/Lightpress-00000002", "Generic rg Recording Check - 2062956765 615") in new stack
    -- Executing [s@sub-record-check:19] Gosub("SIP/Lightpress-00000002", "recordcheck,1(dontcare,rg,615)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/Lightpress-00000002", "Starting recording check against dontcare") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("SIP/Lightpress-00000002", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [recordcheck@sub-record-check:3] Return("SIP/Lightpress-00000002", "") in new stack
    -- Executing [s@sub-record-check:20] Return("SIP/Lightpress-00000002", "") in new stack
    -- Executing [615@ext-group:13] Set("SIP/Lightpress-00000002", "RingGroupMethod=ringall") in new stack
    -- Executing [615@ext-group:14] Macro("SIP/Lightpress-00000002", "dial,20,Ttr,110-111-112-120") in new stack
    -- Executing [s@macro-dial:1] NoOp("SIP/Lightpress-00000002", "Blind Transfer: , Attended Transfer: , User: , Alert Info: custom6") in new stack
    -- Executing [s@macro-dial:2] ExecIf("SIP/Lightpress-00000002", "0?Set(ALERT_INFO=internal)") in new stack
    -- Executing [s@macro-dial:3] ExecIf("SIP/Lightpress-00000002", "0?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial:4] ExecIf("SIP/Lightpress-00000002", "0?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial:5] ExecIf("SIP/Lightpress-00000002", "0?Set(CHANNEL(musicclass)=)") in new stack
    -- Executing [s@macro-dial:6] AGI("SIP/Lightpress-00000002", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
 dialparties.agi: Starting New Dialparties.agi
    -- <SIP/Lightpress-00000002>AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] NoOp("SIP/Lightpress-00000002", "Returned from dialparties with no extensions to call and DIALSTATUS: ") in new stack
    -- Executing [s@macro-dial:8] MacroExit("SIP/Lightpress-00000002", "") in new stack
    -- Executing [615@ext-group:15] Gosub("SIP/Lightpress-00000002", "sub-record-cancel,s,1()") in new stack
    -- Executing [s@sub-record-cancel:1] Return("SIP/Lightpress-00000002", "") in new stack
    -- Executing [615@ext-group:16] Set("SIP/Lightpress-00000002", "RingGroupMethod=") in new stack
    -- Executing [615@ext-group:17] GotoIf("SIP/Lightpress-00000002", "0?nodest") in new stack
    -- Executing [615@ext-group:18] Set("SIP/Lightpress-00000002", "__NODEST=") in new stack
    -- Executing [615@ext-group:19] Macro("SIP/Lightpress-00000002", "blkvm-clr,") in new stack
    -- Executing [s@macro-blkvm-clr:1] Set("SIP/Lightpress-00000002", "SHARED(BLKVM,SIP/Lightpress-00000002)=") in new stack
    -- Executing [s@macro-blkvm-clr:2] Set("SIP/Lightpress-00000002", "GOSUB_RETVAL=") in new stack
    -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/Lightpress-00000002", "") in new stack
    -- Executing [615@ext-group:20] Goto("SIP/Lightpress-00000002", "ivr-3,s,1") in new stack
    -- Goto (ivr-3,s,1)
    -- Executing [s@ivr-3:1] Set("SIP/Lightpress-00000002", "TIMEOUT_LOOPCOUNT=0") in new stack
    -- Executing [s@ivr-3:2] Set("SIP/Lightpress-00000002", "INVALID_LOOPCOUNT=0") in new stack
    -- Executing [s@ivr-3:3] Set("SIP/Lightpress-00000002", "_IVR_CONTEXT_ivr-3=") in new stack
    -- Executing [s@ivr-3:4] Set("SIP/Lightpress-00000002", "_IVR_CONTEXT=ivr-3") in new stack
    -- Executing [s@ivr-3:5] Set("SIP/Lightpress-00000002", "__IVR_RETVM=") in new stack
    -- Executing [s@ivr-3:6] GotoIf("SIP/Lightpress-00000002", "0?skip") in new stack
    -- Executing [s@ivr-3:7] Answer("SIP/Lightpress-00000002", "") in new stack
    -- Executing [s@ivr-3:8] Wait("SIP/Lightpress-00000002", "1") in new stack
    -- Executing [s@ivr-3:9] Set("SIP/Lightpress-00000002", "IVR_MSG=custom/utternew") in new stack
    -- Executing [s@ivr-3:10] Set("SIP/Lightpress-00000002", "TIMEOUT(digit)=3") in new stack
    -- Digit timeout set to 3.000
    -- Executing [s@ivr-3:11] ExecIf("SIP/Lightpress-00000002", "1?Background(custom/utternew)") in new stack
    -- <SIP/Lightpress-00000002> Playing 'custom/utternew.slin' (language 'en')

I’m also noting the following error come up, if it helps:

[2017-02-03 11:20:16] ERROR[2998]: pjproject:0 <?>:     sip_transport. Error processing 516 bytes packet from UDP 10.0.1.33:5060 : PJSIP syntax error exception when parsing 'Request Line' header on line 1 col 12:
SUBSCRIBE  SIP/2.0
Via: SIP/2.0/UDP 10.0.1.33;branch=z9hG4bK7889073e5EA03803
From: "109" <sip:[email protected]>;tag=92548F72-F8958767
To:
CSeq: 1 SUBSCRIBE
Call-ID: [email protected]
Contact: <sip:[email protected]>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
Event: dialog
User-Agent: PolycomSoundPointIP-SPIP_650-UA/4.1.1.0731
Accept-Language: en
Accept: application/dialog-info+xml
Max-Forwards: 70
Expires: 120
Content-Length: 0

lgaetz · February 3, 2017, 7:44pm

I think these are the relevant lines:

-- Executing [s@macro-dial:6] AGI("SIP/Lightpress-00000002", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
 dialparties.agi: Starting New Dialparties.agi
-- <SIP/Lightpress-00000002>AGI Script dialparties.agi completed, returning 0
-- Executing [s@macro-dial:7] NoOp("SIP/Lightpress-00000002", "Returned from dialparties with no extensions to call and DIALSTATUS: ") in new stack

Looks like dialparties.agi is broken in 14

ErikU · February 3, 2017, 8:19pm

Any tips on repairing or replacing that?

cynjut · February 3, 2017, 8:33pm

Obvious, stupid, rhetorical question.

Why are you running 14-BETA on a production system?

To my uneducated eye, I think you could probably replace the dialparties.agi with one from an older system. The one from a FreePBX 13 installation might work. I could be wrong, of course, so proceed with caution if you decide to try this.

I don’t know if yours is ZENDed or not, but you may be able to troubleshoot the script yourself by looking through the code and (perhaps) turning on some debugging. Just a suggestion.

ErikU · February 3, 2017, 8:48pm

Unfortunately the distro would not install on my new hardware. I went around and around on that and finally decided to risk the new beta, understanding that things like this could happen. Fortunately, it’s in my own office so it’s just my own co-workers to deal with.

Any other thoughts from the brain trust on how to repair?

tm1000 · February 3, 2017, 9:12pm

At this time no. This is what comes with beta software unfortunately.

tm1000 · February 3, 2017, 9:59pm

core v14.0.1beta7

ErikU · February 3, 2017, 11:10pm

I’ll give that a shot.

ErikU · February 4, 2017, 12:13am

That fixed it.

THANK YOU!