FAX CNG detected but no fax extension in context (ext-local)

Hi Folks,

Started to notice that faxes were failing on my pbx today. It has the paid fax configuration pro module and has worked properly for months now. Suddenly I started to receive an error when faxes come in that say “res_fax.c: FAX CNG detected but no fax extension in context (ext-local)” and “chan_dahdi.c: Fax detected, but no fax extension”.

This issue seems to be occurring for all extensions (about 60 of them). The faxes come in from a Digium PRI card with DHADI fax detection set to “incoming”. Each DID inbound route has the fax detection set to yes, dhadi, 4 second detect time, and the recipient is set to the proper “fax recipient” destination.

I tried reinstalling both the fax and faxpro modules, but it did not help. Also just upgraded the faxpro module to the edge version and that did not fix it either.

Anyone else ever encounter this issue? Any help would be much appreciated.

Asterisk version is 13.15.0
Fax Configuration Pro version is 13.0.38.6
Freepbx version is: 13.0.192.9

Thanks Folks!

Output from

asterisk -x "module show like fax"
1 Like

Thanks for the reply Lorne. The output is below. I do have a debug log of the a sample failing fax. It is huge but available if you need.

[[email protected] ~]# asterisk -x "module show like fax"
Module                         Description                              Use Count  Status      Support Level
res_fax.so                     Generic FAX Applications                 1          Running              core
res_fax_spandsp.so             Spandsp G.711 and T.38 FAX Technologies  0          Running          extended
2 modules loaded

Looks okay, going to need a call trace.

Part 1 of logs:

[2017-07-20 19:24:53] VERBOSE[3467][C-0000000f] sig_pri.c: Accepting call from '781519XXXX' to '78141XX133' on channel 0/1, span 1
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Set("DAHDI/i1/781519XXXX-d", "__DIRECTION=INBOUND") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Gosub("DAHDI/i1/781519XXXX-d", "sub-record-check,s,1(in,78141XX133,never)") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] GotoIf("DAHDI/i1/781519XXXX-d", "0?initialized") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "__REC_STATUS=INITIALIZED") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Set("DAHDI/i1/781519XXXX-d", "NOW=1500593093") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Set("DAHDI/i1/781519XXXX-d", "__DAY=20") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] Set("DAHDI/i1/781519XXXX-d", "__MONTH=07") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:6] Set("DAHDI/i1/781519XXXX-d", "__YEAR=2017") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:7] Set("DAHDI/i1/781519XXXX-d", "__TIMESTR=20170720-192453") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:8] Set("DAHDI/i1/781519XXXX-d", "__FROMEXTEN=unknown") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:9] Set("DAHDI/i1/781519XXXX-d", "__MON_FMT=wav") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:10] NoOp("DAHDI/i1/781519XXXX-d", "Recordings initialized") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:11] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(ARG3=dontcare)") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:12] Set("DAHDI/i1/781519XXXX-d", "REC_POLICY_MODE_SAVE=") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:13] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(REC_STATUS=NO)") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:14] GotoIf("DAHDI/i1/781519XXXX-d", "2?checkaction") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:17] GotoIf("DAHDI/i1/781519XXXX-d", "1?sub-record-check,in,1") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,in,1)
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/i1/781519XXXX-d", "Inbound Recording Check to 78141XX133") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "FROMEXTEN=unknown") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/i1/781519XXXX-d", "10?Set(FROMEXTEN=781519XXXX)") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Gosub("DAHDI/i1/781519XXXX-d", "recordcheck,1(never,in,78141XX133)") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/i1/781519XXXX-d", "Starting recording check against never") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Goto("DAHDI/i1/781519XXXX-d", "never") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,recordcheck,14)
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:14] Set("DAHDI/i1/781519XXXX-d", "__REC_POLICY_MODE=NEVER") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:15] Goto("DAHDI/i1/781519XXXX-d", "stoprec") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,recordcheck,25)
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:25] NoOp("DAHDI/i1/781519XXXX-d", "Stopping recording: in, 78141XX133") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:26] Set("DAHDI/i1/781519XXXX-d", "__REC_STATUS=STOPPED") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:27] System("DAHDI/i1/781519XXXX-d", "/var/lib/asterisk/bin/stoprecording.php "DAHDI/i1/781519XXXX-d"") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:28] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Gosub("DAHDI/i1/781519XXXX-d", "app-blacklist-check,s,1()") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] GotoIf("DAHDI/i1/781519XXXX-d", "0?blacklisted") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "CALLED_BLACKLIST=1") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Set("DAHDI/i1/781519XXXX-d", "__FROM_DID=78141XX133") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] Set("DAHDI/i1/781519XXXX-d", "CDR(did)=78141XX133") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:6] ExecIf("DAHDI/i1/781519XXXX-d", "0 ?Set(CALLERID(name)=781519XXXX)") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:7] Set("DAHDI/i1/781519XXXX-d", "CHANNEL(musicclass)=efi-hard-rock-muzak") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:8] Set("DAHDI/i1/781519XXXX-d", "__MOHCLASS=efi-hard-rock-muzak") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:9] Set("DAHDI/i1/781519XXXX-d", "__REVERSAL_REJECT=FALSE") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:10] GotoIf("DAHDI/i1/781519XXXX-d", "1?post-reverse-charge") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (from-digital,78141XX133,12)
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:12] NoOp("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:13] Set("DAHDI/i1/781519XXXX-d", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:14] Set("DAHDI/i1/781519XXXX-d", "__CALLINGNUMPRES_SV=allowed") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:15] Set("DAHDI/i1/781519XXXX-d", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:16] Set("DAHDI/i1/781519XXXX-d", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:17] Set("DAHDI/i1/781519XXXX-d", "CIDSFSCHEME=YmFzZV9FRkktRGVmYXVsdA==") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:19] Set("DAHDI/i1/781519XXXX-d", "CALLERID(name)=Calling Party") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:20] NoOp("DAHDI/i1/781519XXXX-d", "CallerID Entry Point") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:21] Set("DAHDI/i1/781519XXXX-d", "FAX_DEST=ext-fax^9^1") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:22] Set("DAHDI/i1/781519XXXX-d", "FAXOPT(faxdetect)=yes") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:23] Answer("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:24] Wait("DAHDI/i1/781519XXXX-d", "3") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:25] Set("DAHDI/i1/781519XXXX-d", "__CRM_DIRECTION=INBOUND") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:26] Set("DAHDI/i1/781519XXXX-d", "__CRM_SOURCE=781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:27] Set("DAHDI/i1/781519XXXX-d", "__CRM_LINKEDID=1500593093.2430") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:28] ExecIf("DAHDI/i1/781519XXXX-d", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:29] Goto("DAHDI/i1/781519XXXX-d", "app-setcid,5,1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (app-setcid,5,1)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/i1/781519XXXX-d", "(Extension 133) Changing cid to Calling Party <91781519XXXX>") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "CALLERID(name)=Calling Party") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Set("DAHDI/i1/781519XXXX-d", "CALLERID(num)=91781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Goto("DAHDI/i1/781519XXXX-d", "from-did-direct,133,1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (from-did-direct,133,1)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] GotoIf("DAHDI/i1/781519XXXX-d", "1?ext-local,133,1:followme-check,133,1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (ext-local,133,1)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Set("DAHDI/i1/781519XXXX-d", "__RINGTIMER=20") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Macro("DAHDI/i1/781519XXXX-d", "exten-vm,133,133,1,1,1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Macro("DAHDI/i1/781519XXXX-d", "user-callerid,") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Set("DAHDI/i1/781519XXXX-d", "TOUCH_MONITOR=1500593093.2430") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "AMPUSER=91781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] GotoIf("DAHDI/i1/781519XXXX-d", "0?report") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] ExecIf("DAHDI/i1/781519XXXX-d", "1?Set(REALCALLERIDNUM=91781519XXXX)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] Set("DAHDI/i1/781519XXXX-d", "AMPUSER=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:6] GotoIf("DAHDI/i1/781519XXXX-d", "0?limit") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:7] Set("DAHDI/i1/781519XXXX-d", "AMPUSERCIDNAME=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:8] GotoIf("DAHDI/i1/781519XXXX-d", "1?report") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-user-callerid,s,15)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:15] GotoIf("DAHDI/i1/781519XXXX-d", "0?continue") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:16] ExecIf("DAHDI/i1/781519XXXX-d", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:17] Set("DAHDI/i1/781519XXXX-d", "__TTL=64") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:18] GotoIf("DAHDI/i1/781519XXXX-d", "1?continue") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-user-callerid,s,29)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:29] Set("DAHDI/i1/781519XXXX-d", "CALLERID(number)=91781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:30] Set("DAHDI/i1/781519XXXX-d", "CALLERID(name)=Calling Party") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:31] GotoIf("DAHDI/i1/781519XXXX-d", "0?cnum") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:32] Set("DAHDI/i1/781519XXXX-d", "CDR(cnam)=Calling Party") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:33] Set("DAHDI/i1/781519XXXX-d", "CDR(cnum)=91781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:34] Set("DAHDI/i1/781519XXXX-d", "CHANNEL(language)=en") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:35] GosubIf("DAHDI/i1/781519XXXX-d", "0?app-check-classofservce,s,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "RingGroupMethod=none") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Set("DAHDI/i1/781519XXXX-d", "__EXTTOCALL=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Set("DAHDI/i1/781519XXXX-d", "__PICKUPMARK=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] Set("DAHDI/i1/781519XXXX-d", "RT=20") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:12] Gosub("DAHDI/i1/781519XXXX-d", "sub-record-check,s,1(exten,133,dontcare)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] GotoIf("DAHDI/i1/781519XXXX-d", "10?initialized") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,s,10)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:10] NoOp("DAHDI/i1/781519XXXX-d", "Recordings initialized") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:11] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(ARG3=dontcare)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:12] Set("DAHDI/i1/781519XXXX-d", "REC_POLICY_MODE_SAVE=NEVER") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:13] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(REC_STATUS=NO)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:14] GotoIf("DAHDI/i1/781519XXXX-d", "5?checkaction") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:17] GotoIf("DAHDI/i1/781519XXXX-d", "1?sub-record-check,exten,1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/i1/781519XXXX-d", "Exten Recording Check between 781519XXXX and 133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "CALLTYPE=external") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(CALLTYPE=)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Set("DAHDI/i1/781519XXXX-d", "CALLEE=dontcare") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(CALLEE=dontcare)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:6] GotoIf("DAHDI/i1/781519XXXX-d", "1?callee") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:11] Gosub("DAHDI/i1/781519XXXX-d", "recordcheck,1(dontcare,external,133)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/i1/781519XXXX-d", "Starting recording check against dontcare") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Goto("DAHDI/i1/781519XXXX-d", "dontcare") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:12] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:13] GotoIf("DAHDI/i1/781519XXXX-d", "1?macrodial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-exten-vm,s,19)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:19] GosubIf("DAHDI/i1/781519XXXX-d", "0?clrheader,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:20] Macro("DAHDI/i1/781519XXXX-d", "dial-one,20,Ttr,133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Set("DAHDI/i1/781519XXXX-d", "DEXTEN=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "__CRM_SOURCE=91781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(EXTTOCALL=133)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Set("DAHDI/i1/781519XXXX-d", "DIALSTATUS_CW=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] GosubIf("DAHDI/i1/781519XXXX-d", "0?screen,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:6] GosubIf("DAHDI/i1/781519XXXX-d", "0?cf,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:7] GotoIf("DAHDI/i1/781519XXXX-d", "1?skip1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:10] GotoIf("DAHDI/i1/781519XXXX-d", "0?nodial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:11] GotoIf("DAHDI/i1/781519XXXX-d", "0?continue") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:12] Set("DAHDI/i1/781519XXXX-d", "EXTHASCW=ENABLED") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:13] GotoIf("DAHDI/i1/781519XXXX-d", "0?next1:cwinusebusy") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:25] GotoIf("DAHDI/i1/781519XXXX-d", "0?next3:continue") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-dial-one,s,27)

Part 2 of logs:

[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:27] GotoIf("DAHDI/i1/781519XXXX-d", "0?nodial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:28] GosubIf("DAHDI/i1/781519XXXX-d", "1?dstring,1():dlocal,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Set("DAHDI/i1/781519XXXX-d", "DSTRING=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "DEVICES=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/i1/781519XXXX-d", "0?Return()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(DEVICES=33)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] Set("DAHDI/i1/781519XXXX-d", "LOOPCNT=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:6] Set("DAHDI/i1/781519XXXX-d", "ITER=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:7] Set("DAHDI/i1/781519XXXX-d", "THISDIAL=PJSIP/133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:8] GosubIf("DAHDI/i1/781519XXXX-d", "1?zap2dahdi,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] ExecIf("DAHDI/i1/781519XXXX-d", "0?Return()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Set("DAHDI/i1/781519XXXX-d", "NEWDIAL=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Set("DAHDI/i1/781519XXXX-d", "LOOPCNT2=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Set("DAHDI/i1/781519XXXX-d", "ITER2=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] Set("DAHDI/i1/781519XXXX-d", "THISPART2=PJSIP/133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [zap2d[email protected]:6] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(THISPART2=DAHDIIP/133)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:7] Set("DAHDI/i1/781519XXXX-d", "NEWDIAL=PJSIP/133&") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:8] Set("DAHDI/i1/781519XXXX-d", "ITER2=2") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:9] GotoIf("DAHDI/i1/781519XXXX-d", "0?begin2") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:10] Set("DAHDI/i1/781519XXXX-d", "THISDIAL=PJSIP/133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:11] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:9] GotoIf("DAHDI/i1/781519XXXX-d", "0?docheck") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:10] NoOp("DAHDI/i1/781519XXXX-d", "Debug: Found PJSIP Destination PJSIP/133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:11] GotoIf("DAHDI/i1/781519XXXX-d", "0?doset") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:12] NoOp("DAHDI/i1/781519XXXX-d", "Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:13] Set("DAHDI/i1/781519XXXX-d", "THISDIAL=PJSIP/133/sips:[email protected]:5061;transport=TLS") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:14] GotoIf("DAHDI/i1/781519XXXX-d", "0?skipset") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:15] Set("DAHDI/i1/781519XXXX-d", "DSTRING=PJSIP/133/sips:[email protected]:5061;transport=TLS&") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:16] Set("DAHDI/i1/781519XXXX-d", "ITER=2") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:17] GotoIf("DAHDI/i1/781519XXXX-d", "0?begin") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:18] ExecIf("DAHDI/i1/781519XXXX-d", "0?Return()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:19] Set("DAHDI/i1/781519XXXX-d", "DSTRING=PJSIP/133/sips:[email protected]:5061;transport=TLS") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:20] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:29] GotoIf("DAHDI/i1/781519XXXX-d", "0?nodial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:30] GotoIf("DAHDI/i1/781519XXXX-d", "0?skiptrace") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:31] GosubIf("DAHDI/i1/781519XXXX-d", "1?ctset,1():ctclear,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Set("DAHDI/i1/781519XXXX-d", "DB(CALLTRACE/133)=91781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:32] Set("DAHDI/i1/781519XXXX-d", "D_OPTIONS=Ttr") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:33] NoOp("DAHDI/i1/781519XXXX-d", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:34] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(ALERT_INFO=)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:35] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(ALERT_INFO=)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:36] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(ALERT_INFO=)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:37] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:38] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:39] GosubIf("DAHDI/i1/781519XXXX-d", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:40] ExecIf("DAHDI/i1/781519XXXX-d", "1?Set(CHANNEL(musicclass)=efi-hard-rock-muzak)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:41] GosubIf("DAHDI/i1/781519XXXX-d", "0?qwait,1()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:42] Set("DAHDI/i1/781519XXXX-d", "__CWIGNORE=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:43] Set("DAHDI/i1/781519XXXX-d", "__KEEPCID=TRUE") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:44] GotoIf("DAHDI/i1/781519XXXX-d", "0?usegoto,1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:45] GotoIf("DAHDI/i1/781519XXXX-d", "1?godial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-dial-one,s,50)
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:50] Macro("DAHDI/i1/781519XXXX-d", "dialout-one-predial-hook,") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] MacroExit("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:51] ExecIf("DAHDI/i1/781519XXXX-d", "1?Set(D_OPTIONS=trI)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:52] Dial("DAHDI/i1/781519XXXX-d", "PJSIP/133/sips:[email protected]:5061;transport=TLS,20,trIb(func-apply-sipheaders^s^1)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] app_stack.c: PJSIP/133-0000000c Internal Gosub(func-apply-sipheaders,s,1) start
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] ExecIf("PJSIP/133-0000000c", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] NoOp("PJSIP/133-0000000c", "Applying SIP Headers to channel") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] Set("PJSIP/133-0000000c", "SIPHEADERKEYS=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] While("PJSIP/133-0000000c", "0") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] app_while.c: Jumping to priority 8
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:9] Return("PJSIP/133-0000000c", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] app_stack.c: Spawn extension (from-internal, 133, 1) exited non-zero on 'PJSIP/133-0000000c'
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] app_stack.c: PJSIP/133-0000000c Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] app_dial.c: Called PJSIP/133/sips:[email protected]:5061;transport=TLS
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] app_dial.c: Connected line update to DAHDI/i1/781519XXXX-d prevented.
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] app_dial.c: PJSIP/133-0000000c is ringing
[2017-07-20 19:24:59] NOTICE[17201][C-0000000f] chan_dahdi.c: Fax detected, but no fax extension
[2017-07-20 19:24:59] NOTICE[17201][C-0000000f] res_fax.c: FAX CNG detected but no fax extension in context (ext-local)
[2017-07-20 19:24:59] NOTICE[[2017-07-20 19:25:11] VERBOSE[3467][C-0000000f] sig_pri.c: Span 1: Channel 0/1 got hangup request, cause 16
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_stack.c: PJSIP/133-0000000c Internal Gosub(crm-hangup,s,1) start
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/133-0000000c", "Sending Hangup to CRM") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] NoOp("PJSIP/133-0000000c", "HANGUP CAUSE: 0") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/133-0000000c", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] NoOp("PJSIP/133-0000000c", "MASTER CHANNEL: 1500593097.2431 = 1500593093.2430") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] GotoIf("PJSIP/133-0000000c", "1?return") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (crm-hangup,s,8)
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:8] Return("PJSIP/133-0000000c", "") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_stack.c: Spawn extension (from-internal, 133, 1) exited non-zero on 'PJSIP/133-0000000c'
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_stack.c: PJSIP/133-0000000c Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_macro.c: Spawn extension (macro-dial-one, s, 52) exited non-zero on 'DAHDI/i1/781519XXXX-d' in macro 'dial-one'
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_macro.c: Spawn extension (macro-exten-vm, s, 20) exited non-zero on 'DAHDI/i1/781519XXXX-d' in macro 'exten-vm'
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Spawn extension (ext-local, 133, 2) exited non-zero on 'DAHDI/i1/781519XXXX-d'
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 142
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] Macro("DAHDI/i1/781519XXXX-d", "hangupcall,") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 122
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 147
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] GotoIf("DAHDI/i1/781519XXXX-d", "1?theend") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 126
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 130
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(CDR(recordingfile)=)") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 230
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 109
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] Hangup("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'DAHDI/i1/781519XXXX-d' in macro 'hangupcall'
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 232
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'DAHDI/i1/781519XXXX-d'
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_stack.c: DAHDI/i1/781519XXXX-d Internal Gosub(crm-hangup,s,1) start
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 136
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/i1/781519XXXX-d", "Sending Hangup to CRM") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 135
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 231
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:2] NoOp("DAHDI/i1/781519XXXX-d", "HANGUP CAUSE: 16") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 145
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/i1/781519XXXX-d", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 144
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:4] NoOp("DAHDI/i1/781519XXXX-d", "MASTER CHANNEL: 1500593093.2430 = 1500593093.2430") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 129
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:5] GotoIf("DAHDI/i1/781519XXXX-d", "0?return") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 131
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:6] Set("DAHDI/i1/781519XXXX-d", "__CRM_HANGUP=1") in new stack
[2017-07-20 19:25:11] VERBOSE[3399] chan_sip.c: Extension Changed 133[ext-local] new state Idle for Notify User 115
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:7] AGI("DAHDI/i1/781519XXXX-d", "sangomacrm.agi") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] res_agi.c: <DAHDI/i1/781519XXXX-d>AGI Script sangomacrm.agi completed, returning 0
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [[email protected]:8] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on 'DAHDI/i1/781519XXXX-d'
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] app_stack.c: DAHDI/i1/781519XXXX-d Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] chan_dahdi.c: Hungup 'DAHDI/i1/781519XXXX-d'

Figured this one out. For some reason faxing to all 60 or so extensions was no problem with fax detection set to 3 or 4 seconds on a pure digital PRI (no sip involved on the telco side or CPE PRI to sip converter) for a long time. Apparently that short of a detection time is not cutting it anymore.

I had to set the extensions now to 6 seconds or errors are produced. After the change was made, all extensions work perfectly.

Thanks for the help everyone. Hopefully this info can help someone who needs it.

1 Like