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

EFI · July 20, 2017, 11:49pm

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!

lgaetz · July 20, 2017, 11:59pm

Output from

asterisk -x "module show like fax"

EFI · July 21, 2017, 12:02am

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.

[root@pbx ~]# 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

lgaetz · July 21, 2017, 12:36am

Looks okay, going to need a call trace.

EFI · July 21, 2017, 12:49am

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 [78141XX133@from-digital:1] Set("DAHDI/i1/781519XXXX-d", "__DIRECTION=INBOUND") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [78141XX133@from-digital: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 [s@sub-record-check:1] GotoIf("DAHDI/i1/781519XXXX-d", "0?initialized") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:3] Set("DAHDI/i1/781519XXXX-d", "NOW=1500593093") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check:4] Set("DAHDI/i1/781519XXXX-d", "__DAY=20") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check:5] Set("DAHDI/i1/781519XXXX-d", "__MONTH=07") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check:6] Set("DAHDI/i1/781519XXXX-d", "__YEAR=2017") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:8] Set("DAHDI/i1/781519XXXX-d", "__FROMEXTEN=unknown") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check:10] NoOp("DAHDI/i1/781519XXXX-d", "Recordings initialized") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [in@sub-record-check: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 [in@sub-record-check:2] Set("DAHDI/i1/781519XXXX-d", "FROMEXTEN=unknown") in new stack
[2017-07-20 19:24:53] VERBOSE[17201][C-0000000f] pbx.c: Executing [in@sub-record-check: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 [in@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:28] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [in@sub-record-check:5] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [78141XX133@from-digital: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 [s@app-blacklist-check:1] GotoIf("DAHDI/i1/781519XXXX-d", "0?blacklisted") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@app-blacklist-check: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 [s@app-blacklist-check:3] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital:12] NoOp("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital:17] Set("DAHDI/i1/781519XXXX-d", "CIDSFSCHEME=YmFzZV9FRkktRGVmYXVsdA==") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital:23] Answer("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:54] VERBOSE[17201][C-0000000f] pbx.c: Executing [78141XX133@from-digital:24] Wait("DAHDI/i1/781519XXXX-d", "3") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [78141XX133@from-digital: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 [5@app-setcid: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 [5@app-setcid: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 [5@app-setcid: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 [5@app-setcid: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 [133@from-did-direct: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 [133@ext-local:1] Set("DAHDI/i1/781519XXXX-d", "__RINGTIMER=20") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [133@ext-local: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 [s@macro-exten-vm:1] Macro("DAHDI/i1/781519XXXX-d", "user-callerid,") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:2] Set("DAHDI/i1/781519XXXX-d", "AMPUSER=91781519XXXX") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("DAHDI/i1/781519XXXX-d", "0?report") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:5] Set("DAHDI/i1/781519XXXX-d", "AMPUSER=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("DAHDI/i1/781519XXXX-d", "0?limit") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid:7] Set("DAHDI/i1/781519XXXX-d", "AMPUSERCIDNAME=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:15] GotoIf("DAHDI/i1/781519XXXX-d", "0?continue") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:17] Set("DAHDI/i1/781519XXXX-d", "__TTL=64") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid:31] GotoIf("DAHDI/i1/781519XXXX-d", "0?cnum") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-exten-vm:2] Set("DAHDI/i1/781519XXXX-d", "RingGroupMethod=none") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-exten-vm:3] Set("DAHDI/i1/781519XXXX-d", "__EXTTOCALL=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-exten-vm:4] Set("DAHDI/i1/781519XXXX-d", "__PICKUPMARK=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-exten-vm:5] Set("DAHDI/i1/781519XXXX-d", "RT=20") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-exten-vm: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 [s@sub-record-check: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 [s@sub-record-check:10] NoOp("DAHDI/i1/781519XXXX-d", "Recordings initialized") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [exten@sub-record-check: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 [exten@sub-record-check:2] Set("DAHDI/i1/781519XXXX-d", "CALLTYPE=external") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [exten@sub-record-check: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 [exten@sub-record-check:4] Set("DAHDI/i1/781519XXXX-d", "CALLEE=dontcare") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [exten@sub-record-check: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 [exten@sub-record-check: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 [exten@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:3] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [exten@sub-record-check:12] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-dial-one:1] Set("DAHDI/i1/781519XXXX-d", "DEXTEN=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one:4] Set("DAHDI/i1/781519XXXX-d", "DIALSTATUS_CW=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one:10] GotoIf("DAHDI/i1/781519XXXX-d", "0?nodial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one:11] GotoIf("DAHDI/i1/781519XXXX-d", "0?continue") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one:12] Set("DAHDI/i1/781519XXXX-d", "EXTHASCW=ENABLED") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [s@macro-dial-one: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)

EFI · July 21, 2017, 12:49am

Part 2 of logs:

[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one:27] GotoIf("DAHDI/i1/781519XXXX-d", "0?nodial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [dstring@macro-dial-one:1] Set("DAHDI/i1/781519XXXX-d", "DSTRING=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one:2] Set("DAHDI/i1/781519XXXX-d", "DEVICES=133") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("DAHDI/i1/781519XXXX-d", "0?Return()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one:5] Set("DAHDI/i1/781519XXXX-d", "LOOPCNT=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one:6] Set("DAHDI/i1/781519XXXX-d", "ITER=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one: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 [zap2dahdi@macro-dial-one:1] ExecIf("DAHDI/i1/781519XXXX-d", "0?Return()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("DAHDI/i1/781519XXXX-d", "NEWDIAL=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("DAHDI/i1/781519XXXX-d", "LOOPCNT2=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("DAHDI/i1/781519XXXX-d", "ITER2=1") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [zap2dahdi@macro-dial-one: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 [zap2dahdi@macro-dial-one: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 [zap2dahdi@macro-dial-one: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 [zap2dahdi@macro-dial-one:8] Set("DAHDI/i1/781519XXXX-d", "ITER2=2") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("DAHDI/i1/781519XXXX-d", "0?begin2") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [zap2dahdi@macro-dial-one: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 [zap2dahdi@macro-dial-one:11] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("DAHDI/i1/781519XXXX-d", "0?docheck") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one:11] GotoIf("DAHDI/i1/781519XXXX-d", "0?doset") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one: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 [dstring@macro-dial-one:14] GotoIf("DAHDI/i1/781519XXXX-d", "0?skipset") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one:16] Set("DAHDI/i1/781519XXXX-d", "ITER=2") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf("DAHDI/i1/781519XXXX-d", "0?begin") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf("DAHDI/i1/781519XXXX-d", "0?Return()") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [dstring@macro-dial-one: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 [dstring@macro-dial-one:20] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one:29] GotoIf("DAHDI/i1/781519XXXX-d", "0?nodial") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one:30] GotoIf("DAHDI/i1/781519XXXX-d", "0?skiptrace") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [ctset@macro-dial-one: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 [ctset@macro-dial-one:2] Return("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one:42] Set("DAHDI/i1/781519XXXX-d", "__CWIGNORE=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one:43] Set("DAHDI/i1/781519XXXX-d", "__KEEPCID=TRUE") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dial-one: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 [s@macro-dialout-one-predial-hook:1] MacroExit("DAHDI/i1/781519XXXX-d", "") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@macro-dial-one: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 [s@macro-dial-one: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 [s@func-apply-sipheaders: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 [s@func-apply-sipheaders: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 [s@func-apply-sipheaders:3] Set("PJSIP/133-0000000c", "SIPHEADERKEYS=") in new stack
[2017-07-20 19:24:57] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@func-apply-sipheaders: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 [s@func-apply-sipheaders: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 [s@crm-hangup: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 [s@crm-hangup:2] NoOp("PJSIP/133-0000000c", "HANGUP CAUSE: 0") in new stack
[2017-07-20 19:25:11] VERBOSE[17201][C-0000000f] pbx.c: Executing [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [h@ext-local: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 [s@macro-hangupcall: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 [s@macro-hangupcall: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 [s@macro-hangupcall: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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 [s@crm-hangup: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'

EFI · July 21, 2017, 3:51am

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.