Caller ID not showing numbers

modcar · June 19, 2016, 1:20am

Hello;

In CIDLookup, I set source type ‘internal’ which displays the name of the caller, if they are in the Asterisk Phonebook - which is great

My issue is, if someone calls, whos not in the phonebook, our phones don’t display the callerid at all - they just say ‘incoming call’.

If I set the lookup source to ‘none’ in inbound routes, the phones display the number of the caller as expected

Is there a way around this? I’d really like it to show the name if they are in the phonebook, or just the number if they aren’t

astbox · June 19, 2016, 7:13am

What version of FreePBX do you use? Make an inbound call and post the log from the call to see what is happening.
Normally if freepbx cannot find a name, it serves the number like a normal call. Is this happening for all calls or for a specific number?

modcar · June 19, 2016, 9:42pm

Hello;

FreePBX 13.0.131 (recently updated to v13, only setup phonebook and callerid lookup a few minutes before v13 upgrade)
Current Asterisk Version: 11.21.0

Hope I got all the log needed:

[2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] Set("SIP/VFX-Dynamite-0000005b", "GROUP()=OUT_3") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Goto("SIP/VFX-Dynamite-0000005b", "from-trunk,012345678,1") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (from-trunk,012345678,1)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] Set("SIP/VFX-Dynamite-0000005b", "__DIRECTION=INBOUND") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Gosub("SIP/VFX-Dynamite-0000005b", "sub-record-check,s,1(in,012345678,dontcare)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-0000005b", "0?initialized") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-0000005b", "__REC_STATUS=INITIALIZED") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] Set("SIP/VFX-Dynamite-0000005b", "NOW=1466371399") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:4] Set("SIP/VFX-Dynamite-0000005b", "__DAY=20") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-0000005b", "__MONTH=06") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:6] Set("SIP/VFX-Dynamite-0000005b", "__YEAR=2016") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] Set("SIP/VFX-Dynamite-0000005b", "__TIMESTR=20160620-092319") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:8] Set("SIP/VFX-Dynamite-0000005b", "__FROMEXTEN=unknown") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:9] Set("SIP/VFX-Dynamite-0000005b", "__MON_FMT=wav") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:10] NoOp("SIP/VFX-Dynamite-0000005b", "Recordings initialized") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:11] ExecIf("SIP/VFX-Dynamite-0000005b", "0?Set(ARG3=dontcare)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-0000005b", "REC_POLICY_MODE_SAVE=") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] ExecIf("SIP/VFX-Dynamite-0000005b", "0?Set(REC_STATUS=NO)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] GotoIf("SIP/VFX-Dynamite-0000005b", "2?checkaction") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (sub-record-check,s,17)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:17] GotoIf("SIP/VFX-Dynamite-0000005b", "1?sub-record-check,in,1") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (sub-record-check,in,1)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-0000005b", "Inbound Recording Check to 012345678") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-0000005b", "FROMEXTEN=unknown") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] ExecIf("SIP/VFX-Dynamite-0000005b", "9?Set(FROMEXTEN=098765432)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:4] Gosub("SIP/VFX-Dynamite-0000005b", "recordcheck,1(dontcare,in,012345678)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-0000005b", "Starting recording check against dontcare") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Goto("SIP/VFX-Dynamite-0000005b", "dontcare") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] Return("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] Return("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] Gosub("SIP/VFX-Dynamite-0000005b", "app-blacklist-check,s,1()") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-0000005b", "0?blacklisted") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-0000005b", "CALLED_BLACKLIST=1") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] Return("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:4] Set("SIP/VFX-Dynamite-0000005b", "__FROM_DID=012345678") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-0000005b", "CDR(did)=012345678") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:6] ExecIf("SIP/VFX-Dynamite-0000005b", "1 ?Set(CALLERID(name)=098765432)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] Set("SIP/VFX-Dynamite-0000005b", "__MOHCLASS=") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:8] Set("SIP/VFX-Dynamite-0000005b", "__REVERSAL_REJECT=FALSE") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/VFX-Dynamite-0000005b", "1?post-reverse-charge") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (from-trunk,012345678,11)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:11] NoOp("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-0000005b", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] Set("SIP/VFX-Dynamite-0000005b", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-0000005b", "CALLERID(name-pres)=allowed_not_screened") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:15] Set("SIP/VFX-Dynamite-0000005b", "CALLERID(num-pres)=allowed_not_screened") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:16] Gosub("SIP/VFX-Dynamite-0000005b", "cidlookup,cidlookup_4,1()") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/VFX-Dynamite-0000005b", "1?Set(CALLERID(name)=Fraser - Mobile)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Return("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:17] NoOp("SIP/VFX-Dynamite-0000005b", "CallerID Entry Point") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:18] Goto("SIP/VFX-Dynamite-0000005b", "ext-group,902,1") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (ext-group,902,1)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-0000005b", "0?cid") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] PlayTones("SIP/VFX-Dynamite-0000005b", "ring") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] Progress("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:4] Macro("SIP/VFX-Dynamite-0000005b", "user-callerid,") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] Set("SIP/VFX-Dynamite-0000005b", "TOUCH_MONITOR=1466371399.91") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-0000005b", "AMPUSER=098765432") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/VFX-Dynamite-0000005b", "0?report") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:4] ExecIf("SIP/VFX-Dynamite-0000005b", "1?Set(REALCALLERIDNUM=098765432)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-0000005b", "AMPUSER=") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:6] GotoIf("SIP/VFX-Dynamite-0000005b", "0?limit") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] Set("SIP/VFX-Dynamite-0000005b", "AMPUSERCIDNAME=") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:8] GotoIf("SIP/VFX-Dynamite-0000005b", "1?report") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (macro-user-callerid,s,15)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-0000005b", "0?continue") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:16] ExecIf("SIP/VFX-Dynamite-0000005b", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:17] Set("SIP/VFX-Dynamite-0000005b", "__TTL=64") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:18] GotoIf("SIP/VFX-Dynamite-0000005b", "1?continue") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (macro-user-callerid,s,29)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:29] Set("SIP/VFX-Dynamite-0000005b", "CALLERID(number)=098765432") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:30] Set("SIP/VFX-Dynamite-0000005b", "CALLERID(name)=Fraser - Mobile") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:31] Set("SIP/VFX-Dynamite-0000005b", "CDR(cnum)=098765432") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:32] Set("SIP/VFX-Dynamite-0000005b", "CDR(cnam)=Fraser - Mobile") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:33] Set("SIP/VFX-Dynamite-0000005b", "CHANNEL(language)=en") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] Macro("SIP/VFX-Dynamite-0000005b", "blkvm-setifempty,") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-0000005b", "1?init") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (macro-blkvm-setifempty,s,4)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:4] Set("SIP/VFX-Dynamite-0000005b", "__BLKVM_CHANNEL=SIP/VFX-Dynamite-0000005b") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-0000005b", "SHARED(BLKVM,SIP/VFX-Dynamite-0000005b)=TRUE") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:6] Set("SIP/VFX-Dynamite-0000005b", "GOSUB_RETVAL=TRUE") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] MacroExit("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:6] GotoIf("SIP/VFX-Dynamite-0000005b", "1?skipov") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (ext-group,902,9)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:9] Set("SIP/VFX-Dynamite-0000005b", "RRNODEST=") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:10] Set("SIP/VFX-Dynamite-0000005b", "__NODEST=902") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:11] GosubIf("SIP/VFX-Dynamite-0000005b", "0?sub-rgsetcid,s,1()") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Gosub("SIP/VFX-Dynamite-0000005b", "sub-record-check,s,1(rg,902,dontcare)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-0000005b", "9?initialized") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (sub-record-check,s,10)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:10] NoOp("SIP/VFX-Dynamite-0000005b", "Recordings initialized") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:11] ExecIf("SIP/VFX-Dynamite-0000005b", "0?Set(ARG3=dontcare)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-0000005b", "REC_POLICY_MODE_SAVE=") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] ExecIf("SIP/VFX-Dynamite-0000005b", "0?Set(REC_STATUS=NO)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] GotoIf("SIP/VFX-Dynamite-0000005b", "2?checkaction") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (sub-record-check,s,17)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:17] GotoIf("SIP/VFX-Dynamite-0000005b", "0?sub-record-check,rg,1") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:18] NoOp("SIP/VFX-Dynamite-0000005b", "Generic rg Recording Check - 098765432 902") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:19] Gosub("SIP/VFX-Dynamite-0000005b", "recordcheck,1(dontcare,rg,902)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-0000005b", "Starting recording check against dontcare") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Goto("SIP/VFX-Dynamite-0000005b", "dontcare") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] Return("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:20] Return("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] Set("SIP/VFX-Dynamite-0000005b", "RingGroupMethod=ringall") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] Macro("SIP/VFX-Dynamite-0000005b", "dial,30,Ttr,610-613-600-614") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-0000005b", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
    [2016-06-20
     09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing 
    [[email protected]:2] ExecIf("SIP/VFX-Dynamite-0000005b", 
    "0?Set(ALERT_INFO=)") in new stack
    [2016-06-20
     09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing 
    [[email protected]:3] ExecIf("SIP/VFX-Dynamite-0000005b", 
    "0?Set(ALERT_INFO=)") in new stack
    [2016-06-20
     09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing 
    [[email protected]:4] ExecIf("SIP/VFX-Dynamite-0000005b", 
    "0?Set(ALERT_INFO=)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] ExecIf("SIP/VFX-Dynamite-0000005b", "0?Set(CHANNEL(musicclass)=)") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:6] AGI("SIP/VFX-Dynamite-0000005b", "dialparties.agi") in new stack
    [2016-06-20 09:23:19] VERBOSE[10493][C-0000001a] res_agi.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:  dialparties.agi: Starting New Dialparties.agi
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:  dialparties.agi: Caller ID name is 'Fraser - Mobile' number is '098765432'
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:  dialparties.agi: Methodology of ring is  'ringall'
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Added extension 610 to extension map
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Added extension 613 to extension map
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Added extension 600 to extension map
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Added extension 614 to extension map
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 610 cf is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 613 cf is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 600 cf is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 614 cf is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 610 do not disturb is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 613 do not disturb is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 600 do not disturb is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Extension 614 do not disturb is disabled
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: dbset CALLTRACE/610 to 098765432
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: dbset CALLTRACE/613 to 098765432
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: dbset CALLTRACE/600 to 098765432
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: dbset CALLTRACE/614 to 098765432
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- dialparties.agi: Filtered ARG3: 610-613-600-614
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] res_agi.c:     -- <SIP/VFX-Dynamite-0000005b>AGI Script dialparties.agi completed, returning 0
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:9] NoOp("SIP/VFX-Dynamite-0000005b", "Returned from dialparties with groups to dial") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:10] Set("SIP/VFX-Dynamite-0000005b", "LOOPCNT=4") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:11] Set("SIP/VFX-Dynamite-0000005b", "ITER=1") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-0000005b", "EXTTOCALL=610") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-0000005b", "Working with 610") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-0000005b", "ITER=2") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-0000005b", "1?ndloopbegin") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (macro-dial,s,12)
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-0000005b", "EXTTOCALL=613") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-0000005b", "Working with 613") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-0000005b", "ITER=3") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-0000005b", "1?ndloopbegin") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (macro-dial,s,12)
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-0000005b", "EXTTOCALL=600") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-0000005b", "Working with 600") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-0000005b", "ITER=4") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-0000005b", "1?ndloopbegin") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (macro-dial,s,12)
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-0000005b", "EXTTOCALL=614") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-0000005b", "Working with 614") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-0000005b", "ITER=5") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-0000005b", "0?ndloopbegin") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:16] Macro("SIP/VFX-Dynamite-0000005b", "dial-ringall-predial-hook,") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] MacroExit("SIP/VFX-Dynamite-0000005b", "") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:17] Dial("SIP/VFX-Dynamite-0000005b", "SIP/610&SIP/613&SIP/600&SIP/614,30,trM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP TOS bits 184
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP CoS mark 5
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP TOS bits 184
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP CoS mark 5
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP TOS bits 184
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP CoS mark 5
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP TOS bits 184
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] netsock2.c:   == Using SIP RTP CoS mark 5
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/610-0000005c Internal Gosub(func-apply-sipheaders,s,1) start
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/610-0000005c", "Applying SIP Headers to channel") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/610-0000005c", "SIPHEADERKEYS=") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] While("SIP/610-0000005c", "0") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_while.c:     -- Jumping to priority 6
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] Return("SIP/610-0000005c", "") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:   == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/610-0000005c'
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/610-0000005c Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/613-0000005d Internal Gosub(func-apply-sipheaders,s,1) start
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/613-0000005d", "Applying SIP Headers to channel") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/613-0000005d", "SIPHEADERKEYS=") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] While("SIP/613-0000005d", "0") in new stack
    [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_while.c:     -- Jumping to priority 6

modcar · June 19, 2016, 9:42pm

[2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] Return("SIP/613-0000005d", "") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:   == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/613-0000005d'
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/613-0000005d Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/600-0000005e Internal Gosub(func-apply-sipheaders,s,1) start
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/600-0000005e", "Applying SIP Headers to channel") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/600-0000005e", "SIPHEADERKEYS=") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] While("SIP/600-0000005e", "0") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_while.c:     -- Jumping to priority 6
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] Return("SIP/600-0000005e", "") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:   == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/600-0000005e'
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/600-0000005e Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/614-0000005f Internal Gosub(func-apply-sipheaders,s,1) start
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/614-0000005f", "Applying SIP Headers to channel") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] Set("SIP/614-0000005f", "SIPHEADERKEYS=") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:3] While("SIP/614-0000005f", "0") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_while.c:     -- Jumping to priority 6
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:7] Return("SIP/614-0000005f", "") in new stack
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:   == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/614-0000005f'
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_stack.c:     -- SIP/614-0000005f Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_dial.c:     -- Called SIP/610
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_dial.c:     -- Called SIP/613
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_dial.c:     -- Called SIP/600
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_dial.c:     -- Called SIP/614
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a]
         app_dial.c:     -- SIP/614-0000005f connected line has changed. Saving 
        it until answer for SIP/VFX-Dynamite-0000005b
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a]
         app_dial.c:     -- SIP/600-0000005e connected line has changed. Saving 
        it until answer for SIP/VFX-Dynamite-0000005b
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a]
         app_dial.c:     -- SIP/613-0000005d connected line has changed. Saving 
        it until answer for SIP/VFX-Dynamite-0000005b
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a]
         app_dial.c:     -- SIP/610-0000005c connected line has changed. Saving 
        it until answer for SIP/VFX-Dynamite-0000005b
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_dial.c:     -- SIP/610-0000005c is ringing
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_dial.c:     -- SIP/613-0000005d is ringing
        [2016-06-20 09:23:20] VERBOSE[10493][C-0000001a] app_dial.c:     -- SIP/614-0000005f is ringing
        [2016-06-20 09:23:21] VERBOSE[10493][C-0000001a] app_dial.c:     -- SIP/600-0000005e is ringing
        [2016-06-20 09:23:21] VERBOSE[10493][C-0000001a] app_dial.c:     -- SIP/600-0000005e is ringing
        [2016-06-20 09:23:23] VERBOSE[2284][C-0000001a] chan_sip.c:     -- Got SIP response 486 "Busy Here" back from 190.23.2.101:60411
        [2016-06-20 09:23:23] VERBOSE[10493][C-0000001a] app_dial.c:     -- SIP/600-0000005e is busy
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a]
         app_macro.c:   == Spawn extension (macro-dial, s, 17) exited non-zero 
        on 'SIP/VFX-Dynamite-0000005b' in macro 'dial'
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:   == Spawn extension (ext-group, 902, 14) exited non-zero on 'SIP/VFX-Dynamite-0000005b'
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] Macro("SIP/VFX-Dynamite-0000005b", "hangupcall,") in new stack
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/VFX-Dynamite-0000005b", "0?Set(CDR(recordingfile)=.wav)") in new stack
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:2] GotoIf("SIP/VFX-Dynamite-0000005b", "1?theend") in new stack
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:     -- Goto (macro-hangupcall,s,4)
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:4] ExecIf("SIP/VFX-Dynamite-0000005b", "0?Set(CDR(recordingfile)=)") in new stack
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:     -- Executing [[email protected]:5] Hangup("SIP/VFX-Dynamite-0000005b", "") in new stack
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a]
         app_macro.c:   == Spawn extension (macro-hangupcall, s, 5) exited 
        non-zero on 'SIP/VFX-Dynamite-0000005b' in macro 'hangupcall'
        [2016-06-20 09:23:28] VERBOSE[10493][C-0000001a] pbx.c:   == Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/VFX-Dynamite-0000005b'

Not sure if its worth noting, but the trunk name the call came in on should have been labelled ‘VFX-Ray’. Looking through CDR reports, no matter which trunk the call comes in on, its labelled as Dynamite

astbox · June 20, 2016, 6:10am

In this case the cid is set to Fraser - Mobile so I think you should remove your phone from asterisk phonebook to see what is happening if there isn’t there. Related to the two trunks, are they both registered to the same host?

modcar · June 20, 2016, 11:42pm

Yes, both trunks are with the same host.

I removed my mobile number ‘098765432’ from the address book, and called again:

[2016-06-21 11:38:14] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] Set("SIP/VFX-Dynamite-000000ce", "GROUP()=OUT_3") in new stack
[2016-06-21 11:38:14] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Goto("SIP/VFX-Dynamite-000000ce", "from-trunk,012345678,1") in new stack
[2016-06-21 11:38:14] VERBOSE[11425][C-00000047] pbx.c: -- Goto (from-trunk,012345678,1)
[2016-06-21 11:38:14] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] Set("SIP/VFX-Dynamite-000000ce", "__DIRECTION=INBOUND") in new stack
[2016-06-21 11:38:14] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Gosub("SIP/VFX-Dynamite-000000ce", "sub-record-check,s,1(in,012345678,dontcare)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-000000ce", "0?initialized") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-000000ce", "__REC_STATUS=INITIALIZED") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] Set("SIP/VFX-Dynamite-000000ce", "NOW=1466465895") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] Set("SIP/VFX-Dynamite-000000ce", "__DAY=21") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-000000ce", "__MONTH=06") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:6] Set("SIP/VFX-Dynamite-000000ce", "__YEAR=2016") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] Set("SIP/VFX-Dynamite-000000ce", "__TIMESTR=20160621-113815") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:8] Set("SIP/VFX-Dynamite-000000ce", "__FROMEXTEN=unknown") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:9] Set("SIP/VFX-Dynamite-000000ce", "__MON_FMT=wav") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:10] NoOp("SIP/VFX-Dynamite-000000ce", "Recordings initialized") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:11] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(ARG3=dontcare)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-000000ce", "REC_POLICY_MODE_SAVE=") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(REC_STATUS=NO)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] GotoIf("SIP/VFX-Dynamite-000000ce", "2?checkaction") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (sub-record-check,s,17)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:17] GotoIf("SIP/VFX-Dynamite-000000ce", "1?sub-record-check,in,1") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (sub-record-check,in,1)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-000000ce", "Inbound Recording Check to 012345678") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-000000ce", "FROMEXTEN=unknown") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/VFX-Dynamite-000000ce", "9?Set(FROMEXTEN=098765432)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] Gosub("SIP/VFX-Dynamite-000000ce", "recordcheck,1(dontcare,in,012345678)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-000000ce", "Starting recording check against dontcare") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Goto("SIP/VFX-Dynamite-000000ce", "dontcare") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (sub-record-check,recordcheck,3)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] Return("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] Return("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] Gosub("SIP/VFX-Dynamite-000000ce", "app-blacklist-check,s,1()") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-000000ce", "0?blacklisted") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-000000ce", "CALLED_BLACKLIST=1") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] Return("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] Set("SIP/VFX-Dynamite-000000ce", "__FROM_DID=012345678") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-000000ce", "CDR(did)=012345678") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:6] ExecIf("SIP/VFX-Dynamite-000000ce", "1 ?Set(CALLERID(name)=098765432)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] Set("SIP/VFX-Dynamite-000000ce", "__MOHCLASS=") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:8] Set("SIP/VFX-Dynamite-000000ce", "__REVERSAL_REJECT=FALSE") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/VFX-Dynamite-000000ce", "1?post-reverse-charge") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (from-trunk,012345678,11)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:11] NoOp("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-000000ce", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] Set("SIP/VFX-Dynamite-000000ce", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-000000ce", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:15] Set("SIP/VFX-Dynamite-000000ce", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:16] Gosub("SIP/VFX-Dynamite-000000ce", "cidlookup,cidlookup_4,1()") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(CALLERID(name)=)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Return("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:17] NoOp("SIP/VFX-Dynamite-000000ce", "CallerID Entry Point") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:18] Goto("SIP/VFX-Dynamite-000000ce", "ext-group,902,1") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (ext-group,902,1)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-000000ce", "0?cid") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] PlayTones("SIP/VFX-Dynamite-000000ce", "ring") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] Progress("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] Macro("SIP/VFX-Dynamite-000000ce", "user-callerid,") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] Set("SIP/VFX-Dynamite-000000ce", "TOUCH_MONITOR=1466465894.210") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/VFX-Dynamite-000000ce", "AMPUSER=098765432") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/VFX-Dynamite-000000ce", "0?report") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/VFX-Dynamite-000000ce", "1?Set(REALCALLERIDNUM=098765432)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-000000ce", "AMPUSER=") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/VFX-Dynamite-000000ce", "0?limit") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] Set("SIP/VFX-Dynamite-000000ce", "AMPUSERCIDNAME=") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/VFX-Dynamite-000000ce", "1?report") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (macro-user-callerid,s,15)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-000000ce", "0?continue") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:16] ExecIf("SIP/VFX-Dynamite-000000ce", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:17] Set("SIP/VFX-Dynamite-000000ce", "__TTL=64") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/VFX-Dynamite-000000ce", "1?continue") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (macro-user-callerid,s,29)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:29] Set("SIP/VFX-Dynamite-000000ce", "CALLERID(number)=098765432") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:30] Set("SIP/VFX-Dynamite-000000ce", "CALLERID(name)=098765432") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:31] Set("SIP/VFX-Dynamite-000000ce", "CDR(cnum)=098765432") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:32] Set("SIP/VFX-Dynamite-000000ce", "CDR(cnam)=098765432") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:33] Set("SIP/VFX-Dynamite-000000ce", "CHANNEL(language)=en") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] Macro("SIP/VFX-Dynamite-000000ce", "blkvm-setifempty,") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-000000ce", "1?init") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (macro-blkvm-setifempty,s,4)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] Set("SIP/VFX-Dynamite-000000ce", "__BLKVM_CHANNEL=SIP/VFX-Dynamite-000000ce") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] Set("SIP/VFX-Dynamite-000000ce", "SHARED(BLKVM,SIP/VFX-Dynamite-000000ce)=TRUE") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:6] Set("SIP/VFX-Dynamite-000000ce", "GOSUB_RETVAL=TRUE") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] MacroExit("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/VFX-Dynamite-000000ce", "1?skipov") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (ext-group,902,9)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:9] Set("SIP/VFX-Dynamite-000000ce", "RRNODEST=") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:10] Set("SIP/VFX-Dynamite-000000ce", "__NODEST=902") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:11] GosubIf("SIP/VFX-Dynamite-000000ce", "0?sub-rgsetcid,s,1()") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Gosub("SIP/VFX-Dynamite-000000ce", "sub-record-check,s,1(rg,902,dontcare)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/VFX-Dynamite-000000ce", "9?initialized") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (sub-record-check,s,10)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:10] NoOp("SIP/VFX-Dynamite-000000ce", "Recordings initialized") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:11] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(ARG3=dontcare)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-000000ce", "REC_POLICY_MODE_SAVE=") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(REC_STATUS=NO)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] GotoIf("SIP/VFX-Dynamite-000000ce", "2?checkaction") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (sub-record-check,s,17)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:17] GotoIf("SIP/VFX-Dynamite-000000ce", "0?sub-record-check,rg,1") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:18] NoOp("SIP/VFX-Dynamite-000000ce", "Generic rg Recording Check - 098765432 902") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:19] Gosub("SIP/VFX-Dynamite-000000ce", "recordcheck,1(dontcare,rg,902)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-000000ce", "Starting recording check against dontcare") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Goto("SIP/VFX-Dynamite-000000ce", "dontcare") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Goto (sub-record-check,recordcheck,3)
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] Return("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:20] Return("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] Set("SIP/VFX-Dynamite-000000ce", "RingGroupMethod=ringall") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] Macro("SIP/VFX-Dynamite-000000ce", "dial,30,Ttr,610-613-600-614") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/VFX-Dynamite-000000ce", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(ALERT_INFO=)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(ALERT_INFO=)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(ALERT_INFO=)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(CHANNEL(musicclass)=)") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:6] AGI("SIP/VFX-Dynamite-000000ce", "dialparties.agi") in new stack
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: dialparties.agi: Caller ID name is '098765432' number is '098765432'
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: dialparties.agi: Methodology of ring is 'ringall'
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Added extension 610 to extension map
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Added extension 613 to extension map
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Added extension 600 to extension map
[2016-06-21 11:38:15] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Added extension 614 to extension map
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 610 cf is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 613 cf is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 600 cf is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 614 cf is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 610 do not disturb is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 613 do not disturb is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 600 do not disturb is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Extension 614 do not disturb is disabled
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: dbset CALLTRACE/610 to 098765432
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: dbset CALLTRACE/613 to 098765432
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: dbset CALLTRACE/600 to 098765432
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: dbset CALLTRACE/614 to 098765432
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- dialparties.agi: Filtered ARG3: 610-613-600-614
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] res_agi.c: -- <SIP/VFX-Dynamite-000000ce>AGI Script dialparties.agi completed, returning 0
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:9] NoOp("SIP/VFX-Dynamite-000000ce", "Returned from dialparties with groups to dial") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:10] Set("SIP/VFX-Dynamite-000000ce", "LOOPCNT=4") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:11] Set("SIP/VFX-Dynamite-000000ce", "ITER=1") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-000000ce", "EXTTOCALL=610") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-000000ce", "Working with 610") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-000000ce", "ITER=2") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-000000ce", "1?ndloopbegin") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Goto (macro-dial,s,12)
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-000000ce", "EXTTOCALL=613") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-000000ce", "Working with 613") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-000000ce", "ITER=3") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-000000ce", "1?ndloopbegin") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Goto (macro-dial,s,12)
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-000000ce", "EXTTOCALL=600") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-000000ce", "Working with 600") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-000000ce", "ITER=4") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-000000ce", "1?ndloopbegin") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Goto (macro-dial,s,12)
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:12] Set("SIP/VFX-Dynamite-000000ce", "EXTTOCALL=614") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:13] NoOp("SIP/VFX-Dynamite-000000ce", "Working with 614") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:14] Set("SIP/VFX-Dynamite-000000ce", "ITER=5") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:15] GotoIf("SIP/VFX-Dynamite-000000ce", "0?ndloopbegin") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:16] Macro("SIP/VFX-Dynamite-000000ce", "dial-ringall-predial-hook,") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] MacroExit("SIP/VFX-Dynamite-000000ce", "") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:17] Dial("SIP/VFX-Dynamite-000000ce", "SIP/610&SIP/613&SIP/600&SIP/614,30,trM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP TOS bits 184
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP CoS mark 5
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP TOS bits 184
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP CoS mark 5
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP TOS bits 184
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP CoS mark 5
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP TOS bits 184
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] netsock2.c: == Using SIP RTP CoS mark 5
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/610-000000cf Internal Gosub(func-apply-sipheaders,s,1) start
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/610-000000cf", "Applying SIP Headers to channel") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/610-000000cf", "SIPHEADERKEYS=") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] While("SIP/610-000000cf", "0") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_while.c: -- Jumping to priority 6
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] Return("SIP/610-000000cf", "") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/610-000000cf'
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/610-000000cf Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/613-000000d0 Internal Gosub(func-apply-sipheaders,s,1) start
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/613-000000d0", "Applying SIP Headers to channel") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/613-000000d0", "SIPHEADERKEYS=") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] While("SIP/613-000000d0", "0") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_while.c: -- Jumping to priority 6
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] Return("SIP/613-000000d0", "") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/613-000000d0'
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/613-000000d0 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/600-000000d1 Internal Gosub(func-apply-sipheaders,s,1) start
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/600-000000d1", "Applying SIP Headers to channel") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/600-000000d1", "SIPHEADERKEYS=") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] While("SIP/600-000000d1", "0") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_while.c: -- Jumping to priority 6
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] Return("SIP/600-000000d1", "") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/600-000000d1'
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/600-000000d1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/614-000000d2 Internal Gosub(func-apply-sipheaders,s,1) start
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/614-000000d2", "Applying SIP Headers to channel") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] Set("SIP/614-000000d2", "SIPHEADERKEYS=") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:3] While("SIP/614-000000d2", "0") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_while.c: -- Jumping to priority 6
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:7] Return("SIP/614-000000d2", "") in new stack
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: == Spawn extension (from-internal, 902, 1) exited non-zero on 'SIP/614-000000d2'
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_stack.c: -- SIP/614-000000d2 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- Called SIP/610
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- Called SIP/613
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- Called SIP/600
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- Called SIP/614
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/614-000000d2 connected line has changed. Saving it until answer for SIP/VFX-Dynamite-000000ce
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/600-000000d1 connected line has changed. Saving it until answer for SIP/VFX-Dynamite-000000ce
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/613-000000d0 connected line has changed. Saving it until answer for SIP/VFX-Dynamite-000000ce
[2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/610-000000cf connected line has changed. Saving it until answer for SIP/VFX-Dynamite-000000ce

modcar · June 20, 2016, 11:42pm

   [2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/610-000000cf is ringing
    [2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/613-000000d0 is ringing
    [2016-06-21 11:38:16] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/614-000000d2 is ringing
    [2016-06-21 11:38:17] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/600-000000d1 is ringing
    [2016-06-21 11:38:20] VERBOSE[2284][C-00000047] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 122.56.211.165:50381
    [2016-06-21 11:38:20] VERBOSE[11425][C-00000047] app_dial.c: -- SIP/600-000000d1 is busy
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] app_macro.c: == Spawn extension (macro-dial, s, 17) exited non-zero on 'SIP/VFX-Dynamite-000000ce' in macro 'dial'
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: == Spawn extension (ext-group, 902, 14) exited non-zero on 'SIP/VFX-Dynamite-000000ce'
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] Macro("SIP/VFX-Dynamite-000000ce", "hangupcall,") in new stack
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(CDR(recordingfile)=.wav)") in new stack
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/VFX-Dynamite-000000ce", "1?theend") in new stack
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: -- Goto (macro-hangupcall,s,4)
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/VFX-Dynamite-000000ce", "0?Set(CDR(recordingfile)=)") in new stack
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: -- Executing [[email protected]:5] Hangup("SIP/VFX-Dynamite-000000ce", "") in new stack
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on 'SIP/VFX-Dynamite-000000ce' in macro 'hangupcall'
    [2016-06-21 11:38:24] VERBOSE[11425][C-00000047] pbx.c: == Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/VFX-Dynamite-000000ce'

modcar · June 21, 2016, 1:16am

Ok, I just decided to do some testing calling internal lines. I have 3x ata adaptors Cisco/Linksys SPA2102, 2 of them have 1 extension connected, and the other has 2 extensoins on it.

The 2 ata adaptors that have only 1 extension signed in, caller id doesn’t work with those. The ata with 2 extensions signed in, it works. All 3 ata adaptors are configured using the same xml file, and i’m 99.9% sure the caller id was working pre v13 upgrade.

Caller id is working find to my mobile (using CSIPSimple on Android)

astbox · June 21, 2016, 5:06pm

Related to the problem that always comes from the same trunk, it is because you are have two sip trunks to the same provider and you authenticate with you ip and port not username and secret. Open a new thread and post there what you have in your sip trunk options if you want to fix that also.

modcar · July 3, 2016, 1:51am

Thanks astbox - will take a look at that later