Cant get followme to terminate a call if no answer ( Goto (app-blackhole,hangup,1))

Follow Me is set for 0 initial ring time and then to follow for 20 seconds and then hangup. It is only following itself. I see it rings 20 seconds, the pbx claims its hanging up but then the ringing sound changes and it appears to start another call. I let this loop several times and it appears to never hangup.

I think its silly to want the phones to do this but thats what they want and I’m trying to make it work. Any ideas?

Here is what I see in putty:

-- SIP/253-00000516 is ringing
-- Nobody picked up in 20000 ms
-- SIP/253-00000516 Internal Gosub(crm-hangup,s,1) start

it goes through the motions of hanging up and then I see this but the caller hears ringing still

-- Goto (app-blackhole,hangup,1)

== Extension Changed 253[ext-local] new state Idle for Notify User 209
== Extension Changed 253[ext-local] new state Idle for Notify User 251
== Extension Changed 253[ext-local] new state Idle for Notify User 206
== Extension Changed 253[ext-local] new state Idle for Notify User 203

It rings for another 20 seconds and then checks time conditions and such again, changes the state back to ringing, rings for another 20 seconds, and then repeats the above message(s) and continues to ring. I didn’t go any further than this but i suspect it will ring forever.

What about the ensuing log lines for the FollowMe extensions setup for 253?

When I call from a cell phone (ATT) it works fine and terminates the call. My calls were originally all from another freepbx instance. I did a couple calls with the carrier watching and they could see that calls are failing on the primary inbound trunk and going through on the secondary.

What it appears is happening is every 20 seconds the PBX I’m calling from is trying again and during that 20 seconds its failing through all the outbound trunks. From the calling side I see this in the CDR

image

and from the receiving side i see this in the CDR

image

This number is on Level 3 so all calls regardless of origin should come from Level 3 to the Voip Innovations and then on to the PBX. Maybe it behaves different if the call is on net (never leaving the VI network)?

Logs, logs, logs, no logs no clairyoyance

Here is everything. The VI-Outbound trunk is actually what is getting used as a failover inbound trunk, which may have something do with this.

-- Executing [[email protected]:1] Goto("SIP/VI-Outbound_64.136.174.30-00000515", "from-pstn,XXXXXXX,1") in new stack
-- Goto (from-pstn,XXXXXXX,1)
-- Executing [[email protected]:1] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__DIRECTION=INBOUND") in new stack
-- Executing [[email protected]:2] Gosub("SIP/VI-Outbound_64.136.174.30-00000515", "app-blacklist-check,s,1()") in new stack
-- Executing [[email protected]:1] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?blacklisted") in new stack
-- Executing [[email protected]:2] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CALLED_BLACKLIST=1") in new stack
-- Executing [[email protected]:3] Return("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:3] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__FROM_DID=XXXXXXX") in new stack
-- Executing [[email protected]:4] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CDR(did)=XXXXXXX") in new stack
-- Executing [[email protected]:5] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0 ?Set(CALLERID(name)=YYYYYYYYYY)") in new stack
-- Executing [[email protected]:6] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__MOHCLASS=") in new stack
-- Executing [[email protected]:7] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__REVERSAL_REJECT=FALSE") in new stack
-- Executing [[email protected]:8] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?post-reverse-charge") in new stack
-- Goto (from-pstn,XXXXXXX,10)
-- Executing [[email protected]:10] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:11] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
-- Executing [[email protected]:12] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
-- Executing [[email protected]:13] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CALLERID(name-pres)=allowed_not_screened") in new stack
-- Executing [[email protected]:14] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CALLERID(num-pres)=allowed_not_screened") in new stack
-- Executing [[email protected]:15] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "CallerID Entry Point") in new stack
-- Executing [[email protected]:16] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__CRM_DIRECTION=INBOUND") in new stack
-- Executing [[email protected]:17] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__CRM_SOURCE=YYYYYYYYYY") in new stack
-- Executing [[email protected]:18] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__CRM_LINKEDID=1516315391.1456") in new stack
-- Executing [[email protected]:19] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
-- Executing [[email protected]:20] Goto("SIP/VI-Outbound_64.136.174.30-00000515", "from-did-direct,253,1") in new stack
-- Goto (from-did-direct,253,1)
-- Executing [[email protected]:1] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?ext-local,253,1:followme-check,253,1") in new stack
-- Goto (followme-check,253,1)
-- Executing [[email protected]:1] Gosub("SIP/VI-Outbound_64.136.174.30-00000515", "followme-sub,253,1()") in new stack
-- Executing [[email protected]:1] Macro("SIP/VI-Outbound_64.136.174.30-00000515", "user-callerid,") in new stack
-- Executing [[email protected]:1] Set("SIP/VI-Outbound_64.136.174.30-00000515", "TOUCH_MONITOR=1516315391.1456") in new stack
-- Executing [[email protected]:2] Set("SIP/VI-Outbound_64.136.174.30-00000515", "AMPUSER=YYYYYYYYYY") in new stack
-- Executing [[email protected]:3] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?report") in new stack
-- Executing [[email protected]:4] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?Set(REALCALLERIDNUM=YYYYYYYYYY)") in new stack
-- Executing [[email protected]:5] Set("SIP/VI-Outbound_64.136.174.30-00000515", "AMPUSER=") in new stack
-- Executing [[email protected]:6] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?limit") in new stack
-- Executing [[email protected]:7] Set("SIP/VI-Outbound_64.136.174.30-00000515", "AMPUSERCIDNAME=") in new stack
-- Executing [[email protected]:8] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?report") in new stack
-- Goto (macro-user-callerid,s,15)
-- Executing [[email protected]:15] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Macro Depth is 1") in new stack
-- Executing [[email protected]:16] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?report2:macroerror") in new stack
-- Goto (macro-user-callerid,s,18)
-- Executing [[email protected]:18] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?continue") in new stack
-- Executing [[email protected]:19] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__TTL=64") in new stack
-- Executing [[email protected]:20] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?continue") in new stack
-- Goto (macro-user-callerid,s,36)
-- Executing [[email protected]:36] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CALLERID(number)=YYYYYYYYYY") in new stack
-- Executing [[email protected]:37] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CALLERID(name)=YYYYYYYYYY") in new stack
-- Executing [[email protected]:38] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?cnum") in new stack
-- Executing [[email protected]:39] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CDR(cnam)=YYYYYYYYYY") in new stack
-- Executing [[email protected]:40] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CDR(cnum)=YYYYYYYYYY") in new stack
-- Executing [[email protected]:41] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CHANNEL(language)=en") in new stack
-- Executing [[email protected]:2] Set("SIP/VI-Outbound_64.136.174.30-00000515", "DIAL_OPTIONS=TtrI") in new stack
-- Executing [[email protected]:3] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CONNECTEDLINE(num,i)=253") in new stack
-- Executing [[email protected]:4] Gosub("SIP/VI-Outbound_64.136.174.30-00000515", "sub-presencestate-display,s,1(253)") in new stack
-- Executing [[email protected]:1] Goto("SIP/VI-Outbound_64.136.174.30-00000515", "state-not_set,1") in new stack
-- Goto (sub-presencestate-display,state-not_set,1)
-- Executing [[email protected]:1] Set("SIP/VI-Outbound_64.136.174.30-00000515", "PRESENCESTATE_DISPLAY=") in new stack
-- Executing [[email protected]:2] Return("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:5] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CONNECTEDLINE(name)=Large Conf Room") in new stack
-- Executing [[email protected]:6] Set("SIP/VI-Outbound_64.136.174.30-00000515", "FM_DIALSTATUS=NOT_INUSE") in new stack
-- Executing [[email protected]:7] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__EXTTOCALL=253") in new stack
-- Executing [[email protected]:8] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__PICKUPMARK=253") in new stack
-- Executing [[email protected]:9] Macro("SIP/VI-Outbound_64.136.174.30-00000515", "blkvm-setifempty,") in new stack
-- Executing [[email protected]:1] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?init") in new stack
-- Goto (macro-blkvm-setifempty,s,4)
-- Executing [[email protected]:4] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__BLKVM_CHANNEL=SIP/VI-Outbound_64.136.174.30-00000515") in new stack
-- Executing [[email protected]:5] Set("SIP/VI-Outbound_64.136.174.30-00000515", "SHARED(BLKVM,SIP/VI-Outbound_64.136.174.30-00000515)=TRUE") in new stack
-- Executing [[email protected]:6] Set("SIP/VI-Outbound_64.136.174.30-00000515", "GOSUB_RETVAL=TRUE") in new stack
-- Executing [[email protected]:7] MacroExit("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:10] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?skipov") in new stack
-- Goto (followme-sub,253,13)
-- Executing [[email protected]:13] Set("SIP/VI-Outbound_64.136.174.30-00000515", "RRNODEST=") in new stack
-- Executing [[email protected]:14] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__NODEST=253") in new stack
-- Executing [[email protected]:15] GosubIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?sub-fmsetcid,s,1()") in new stack
-- Executing [[email protected]:16] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?skipprepend") in new stack
-- Goto (followme-sub,253,18)
-- Executing [[email protected]:18] Set("SIP/VI-Outbound_64.136.174.30-00000515", "RecordMethod=Group") in new stack
-- Executing [[email protected]:19] Gosub("SIP/VI-Outbound_64.136.174.30-00000515", "sub-record-check,s,1(exten,253,)") in new stack
-- Executing [[email protected]:1] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?initialized") in new stack
-- Executing [[email protected]:2] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__REC_STATUS=INITIALIZED") in new stack
-- Executing [[email protected]:3] Set("SIP/VI-Outbound_64.136.174.30-00000515", "NOW=1516315391") in new stack
-- Executing [[email protected]:4] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__DAY=18") in new stack
-- Executing [[email protected]:5] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__MONTH=01") in new stack
-- Executing [[email protected]:6] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__YEAR=2018") in new stack
-- Executing [[email protected]:7] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__TIMESTR=20180118-144311") in new stack
-- Executing [[email protected]d-check:8] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__FROMEXTEN=YYYYYYYYYY") in new stack
-- Executing [[email protected]:9] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__MON_FMT=wav") in new stack
-- Executing [[email protected]:10] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Recordings initialized") in new stack
-- Executing [[email protected]:11] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?Set(ARG3=dontcare)") in new stack
-- Executing [[email protected]:12] Set("SIP/VI-Outbound_64.136.174.30-00000515", "REC_POLICY_MODE_SAVE=") in new stack
-- Executing [[email protected]:13] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(REC_STATUS=NO)") in new stack
-- Executing [[email protected]:14] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "5?checkaction") in new stack
-- Goto (sub-record-check,s,17)
-- Executing [[email protected]:17] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?sub-record-check,exten,1") in new stack
-- Goto (sub-record-check,exten,1)
-- Executing [[email protected]:1] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Exten Recording Check between YYYYYYYYYY and 253") in new stack
-- Executing [[email protected]:2] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CALLTYPE=external") in new stack
-- Executing [[email protected]:3] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(CALLTYPE=)") in new stack
-- Executing [[email protected]:4] Set("SIP/VI-Outbound_64.136.174.30-00000515", "CALLEE=dontcare") in new stack
-- Executing [[email protected]:5] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(CALLEE=dontcare)") in new stack
-- Executing [[email protected]:6] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?callee") in new stack
-- Goto (sub-record-check,exten,11)
-- Executing [[email protected]:11] Gosub("SIP/VI-Outbound_64.136.174.30-00000515", "recordcheck,1(dontcare,external,253)") in new stack
-- Executing [[email protected]:1] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Starting recording check against dontcare") in new stack
-- Executing [[email protected]:2] Goto("SIP/VI-Outbound_64.136.174.30-00000515", "dontcare") in new stack
-- Goto (sub-record-check,recordcheck,3)
-- Executing [[email protected]:3] Return("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:12] Return("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:20] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?skipdring") in new stack
-- Goto (followme-sub,253,23)
-- Executing [[email protected]:23] Set("SIP/VI-Outbound_64.136.174.30-00000515", "STRATEGY=ringall") in new stack
-- Executing [[email protected]:24] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__RVOL=") in new stack
-- Executing [[email protected]:25] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?skipsimple") in new stack
-- Executing [[email protected]:26] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1 ?skipsimple") in new stack
-- Goto (followme-sub,253,28)
-- Executing [[email protected]:28] Set("SIP/VI-Outbound_64.136.174.30-00000515", "RingGroupMethod=ringall") in new stack
-- Executing [[email protected]:29] Set("SIP/VI-Outbound_64.136.174.30-00000515", "_FMGRP=253") in new stack
-- Executing [[email protected]:30] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?DIALGRP") in new stack
-- Goto (followme-sub,253,34)
-- Executing [[email protected]:34] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "1?Set(DOPTS=TtrI):Set(DOPTS=m(Ring)TtI)") in new stack
-- Executing [[email protected]:35] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?doconfirm") in new stack
-- Executing [[email protected]:36] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?ringallv21") in new stack
-- Executing [[email protected]:37] Macro("SIP/VI-Outbound_64.136.174.30-00000515", "dial,20,TtrI,253") in new stack
-- Executing [[email protected]:1] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
-- Executing [[email protected]:2] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__CRM_SOURCE=YYYYYYYYYY") in new stack
-- Executing [[email protected]:3] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(ALERT_INFO=)") in new stack
-- Executing [[email protected]:4] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(ALERT_INFO=)") in new stack
-- Executing [[email protected]:5] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(ALERT_INFO=)") in new stack
-- Executing [[email protected]:6] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(CHANNEL(musicclass)=)") in new stack
-- Executing [[email protected]:7] AGI("SIP/VI-Outbound_64.136.174.30-00000515", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
-- dialparties.agi: Starting New Dialparties.agi
-- dialparties.agi: Caller ID name is 'YYYYYYYYYY' number is 'YYYYYYYYYY'
-- dialparties.agi: CW Ignore is:
-- dialparties.agi: CF Ignore is:
-- dialparties.agi: CW IN_USE/BUSY is: 1
-- dialparties.agi: USE_CONFIRMATION:  'FALSE'
-- dialparties.agi: RINGGROUP_INDEX:   ''
-- dialparties.agi: Methodology of ring is  'ringall'
-- dialparties.agi: Added extension 253 to extension map
-- dialparties.agi: Extension 253 has call screening off
-- dialparties.agi: Extension 253 cf is disabled
-- dialparties.agi: Extension 253 do not disturb is disabled
-- dialparties.agi: extnum 253 has:  cw: 1; hascfb: 0 [] hascfu: 0 []
-- dialparties.agi: dbset CALLTRACE/253 to YYYYYYYYYY
-- dialparties.agi: Filtered ARG3: 253
-- dialparties.agi: NODEST: 253 adding M(auto-blkvm) to dialopts: TtrIM(auto-blkvm)
-- dialparties.agi: NODEST: 253 blkvm enabled macro already in dialopts: TtrIM(auto-blkvm)
-- <SIP/VI-Outbound_64.136.174.30-00000515>AGI Script dialparties.agi completed, returning 0
-- Executing [[email protected]:10] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Returned from dialparties with groups to dial") in new stack
-- Executing [[email protected]:11] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "ringall array  ") in new stack
-- Executing [[email protected]:12] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__FMGL_DIAL=") in new stack
-- Executing [[email protected]:13] Set("SIP/VI-Outbound_64.136.174.30-00000515", "LOOPCNT=1") in new stack
-- Executing [[email protected]:14] Set("SIP/VI-Outbound_64.136.174.30-00000515", "ITER=1") in new stack
-- Executing [[email protected]:15] Set("SIP/VI-Outbound_64.136.174.30-00000515", "EXTTOCALL=253") in new stack
-- Executing [[email protected]:16] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Working with 253") in new stack
-- Executing [[email protected]:17] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
-- Executing [[email protected]:18] ExecIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
-- Executing [[email protected]:19] Set("SIP/VI-Outbound_64.136.174.30-00000515", "ITER=2") in new stack
-- Executing [[email protected]:20] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?ndloopbegin") in new stack
-- Executing [[email protected]:21] Macro("SIP/VI-Outbound_64.136.174.30-00000515", "dial-ringall-predial-hook,") in new stack
-- Executing [[email protected]:1] MacroExit("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:22] Dial("SIP/VI-Outbound_64.136.174.30-00000515", "SIP/253,20,trIM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
-- Using SIP RTP TOS bits 184
-- Using SIP RTP CoS mark 5
-- SIP/253-00000516 Internal Gosub(func-apply-sipheaders,s,1) start
-- Executing [[email protected]:1] ExecIf("SIP/253-00000516", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
-- Executing [[email protected]:2] NoOp("SIP/253-00000516", "Applying SIP Headers to channel") in new stack
-- Executing [[email protected]:3] Set("SIP/253-00000516", "SIPHEADERKEYS=") in new stack
-- Executing [[email protected]:4] While("SIP/253-00000516", "0") in new stack
-- Jumping to priority 7
-- Executing [[email protected]:8] Return("SIP/253-00000516", "") in new stack
-- Spawn extension (from-internal, 253, 1) exited non-zero on 'SIP/253-00000516'
-- SIP/253-00000516 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
-- Extension Changed 253[ext-local] new state Ringing for Notify User 209
-- Extension Changed 253[ext-local] new state Ringing for Notify User 251
-- Extension Changed 253[ext-local] new state Ringing for Notify User 206
-- Extension Changed 253[ext-local] new state Ringing for Notify User 203
-- Called SIP/253
-- Connected line update to SIP/VI-Outbound_64.136.174.30-00000515 prevented.
-- SIP/253-00000516 is ringing
-- Nobody picked up in 20000 ms
-- SIP/253-00000516 Internal Gosub(crm-hangup,s,1) start
-- Executing [[email protected]:1] NoOp("SIP/253-00000516", "Sending Hangup to CRM") in new stack
-- Executing [[email protected]:2] NoOp("SIP/253-00000516", "HANGUP CAUSE: 16") in new stack
-- Executing [[email protected]:3] ExecIf("SIP/253-00000516", "0?Set(__CRM_VOICEMAIL=)") in new stack
-- Executing [[email protected]:4] NoOp("SIP/253-00000516", "MASTER CHANNEL: 1516315391.1457 = 1516315391.1456") in new stack
-- Executing [[email protected]:5] GotoIf("SIP/253-00000516", "1?return") in new stack
-- Goto (crm-hangup,s,8)
-- Executing [[email protected]:8] Return("SIP/253-00000516", "") in new stack
-- Spawn extension (from-internal, 253, 1) exited non-zero on 'SIP/253-00000516'
-- SIP/253-00000516 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
-- Executing [[email protected]:23] Set("SIP/VI-Outbound_64.136.174.30-00000515", "DIALSTATUS=NOANSWER") in new stack
-- Executing [[email protected]:24] GosubIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?NOANSWER,1()") in new stack
-- Executing [[email protected]:25] NoOp("SIP/VI-Outbound_64.136.174.30-00000515", "Returning since nobody answered") in new stack
-- Executing [[email protected]:26] MacroExit("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:38] Goto("SIP/VI-Outbound_64.136.174.30-00000515", "nextstep") in new stack
-- Goto (followme-sub,253,45)
-- Executing [[email protected]:45] Set("SIP/VI-Outbound_64.136.174.30-00000515", "RingGroupMethod=") in new stack
-- Executing [[email protected]:46] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?nodest") in new stack
-- Executing [[email protected]:47] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__NODEST=") in new stack
-- Executing [[email protected]:48] Set("SIP/VI-Outbound_64.136.174.30-00000515", "__PICKUPMARK=") in new stack
-- Executing [[email protected]:49] Macro("SIP/VI-Outbound_64.136.174.30-00000515", "blkvm-clr,") in new stack
-- Executing [[email protected]:1] Set("SIP/VI-Outbound_64.136.174.30-00000515", "SHARED(BLKVM,SIP/VI-Outbound_64.136.174.30-00000515)=") in new stack
-- Executing [[email protected]:2] Set("SIP/VI-Outbound_64.136.174.30-00000515", "GOSUB_RETVAL=") in new stack
-- Executing [[email protected]:3] MacroExit("SIP/VI-Outbound_64.136.174.30-00000515", "") in new stack
-- Executing [[email protected]:50] Set("SIP/VI-Outbound_64.136.174.30-00000515", "DIALSTATUS=NOANSWER") in new stack
-- Executing [[email protected]:51] GotoIf("SIP/VI-Outbound_64.136.174.30-00000515", "0?dohangup") in new stack
-- Executing [[email protected]:52] Goto("SIP/VI-Outbound_64.136.174.30-00000515", "app-blackhole,hangup,1") in new stack
-- Goto (app-blackhole,hangup,1)

I think I have an outbound trunk definition problem. I just tried this on a different PBX and when i call from a cell phone it works fine and comes in on the correct trunk but when i call out from a soft phone connected to another freepbx system it fails on the primary inbound trunk and fails to the secondary trunk. At least I have somewhere to look.

Gotta love reading the logs :slight_smile:

After dragging VI into this I think we got this going. The issue may not be unique to VI but we’ve learned the following:

  1. VI to VI calls intentionally use that secondary inbound trunk, so thats not a concern.

  2. Calls that originate using that secondary trunk will retry if they dont connect. For that reason the originating PBX will not stop trying the call and you end up with some endless loop if the other PBX never answers, even if it shows (on both PBXs) as a bunch of unique calls.

  3. If the PBX answers the call in any way before hanging up this all goes away. So I made an announcement with no greeting and had the announcement terminate the call.

I still dont know what this app-blackhole is though, other than it really is a black hole of sorts where the call never gets answered or terminated.

your VI endpoint management should have a “pop up” list of primary through quaternary servers to expect traffic from, you should have an inbound trunk for each, But if you didn’t screw up your trunks, the primary should work. 99.999%

Thats the first thing I checked, and the VI trunks are all there and configured correctly. The issue is with the behavior of on net vs off net calls. According to the guy I talked to at tech support at least all on net (VI to VI) calls will come in on that secondary inbound trunk, and what we eventually figured out is that that trunk behaves differently than the primary trunk despite them being configured exactly the same on the pbx.

This topic was automatically closed 365 days after the last reply. New replies are no longer allowed.