Hello all,
The topology is as follows. Freepbx is using Grandstream GXX4104 with two PSTN lines. I have set up an IVR.
All incoming calls are working fine, no problem with hangups or CallerID or disconnect tones.
The weird part is when you try to call from an extension (any extension) to an external phone (gsm or landline). The result is to hear the IVR options!! I tried to disable one by one and eventually both trunks (both PSTN) and the result is the same. Even with no trunks enabled at all you hear the IVR when you try to make an outbound call. Could you please help me out?
Please find below the logs…
[2021-09-21 12:35:42] VERBOSE[2562] netsock2.c: Using SIP RTP Audio TOS bits 184
[2021-09-21 12:35:42] VERBOSE[2562] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2021-09-21 12:35:42] VERBOSE[2562] netsock2.c: Using SIP RTP Audio CoS mark 5
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/23-0000000e", "Catch-All DID Match - Found 06938751318 - You probably want a DID for this.") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Set("PJSIP/23-0000000e", "__FROM_DID=06938751318") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] Goto("PJSIP/23-0000000e", "ext-did,s,1") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (ext-did,s,1)
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] Set("PJSIP/23-0000000e", "__DIRECTION=INBOUND") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Gosub("PJSIP/23-0000000e", "sub-record-check,s,1(in,s,dontcare)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/23-0000000e", "0?initialized") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Set("PJSIP/23-0000000e", "__REC_STATUS=INITIALIZED") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] Set("PJSIP/23-0000000e", "NOW=1632216942") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:4] Set("PJSIP/23-0000000e", "__DAY=21") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:5] Set("PJSIP/23-0000000e", "__MONTH=09") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:6] Set("PJSIP/23-0000000e", "__YEAR=2021") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:7] Set("PJSIP/23-0000000e", "__TIMESTR=20210921-123542") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:8] Set("PJSIP/23-0000000e", "__FROMEXTEN=unknown") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:9] Set("PJSIP/23-0000000e", "__MON_FMT=wav") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:10] NoOp("PJSIP/23-0000000e", "Recordings initialized") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:11] ExecIf("PJSIP/23-0000000e", "0?Set(ARG3=dontcare)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:12] Set("PJSIP/23-0000000e", "REC_POLICY_MODE_SAVE=") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:13] ExecIf("PJSIP/23-0000000e", "0?Set(REC_STATUS=NO)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:14] GotoIf("PJSIP/23-0000000e", "2?checkaction") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:17] GotoIf("PJSIP/23-0000000e", "1?sub-record-check,in,1") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (sub-record-check,in,1)
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/23-0000000e", "Inbound Recording Check to s") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Set("PJSIP/23-0000000e", "FROMEXTEN=unknown") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/23-0000000e", "2?Set(FROMEXTEN=23)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:4] Gosub("PJSIP/23-0000000e", "recordcheck,1(dontcare,in,s)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/23-0000000e", "Starting recording check against dontcare") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Goto("PJSIP/23-0000000e", "dontcare") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] Return("PJSIP/23-0000000e", "") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:5] Return("PJSIP/23-0000000e", "") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] Set("PJSIP/23-0000000e", "CHANNEL(tonezone)=gr") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/23-0000000e", "0?Set(__FROM_DID=s)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:5] Set("PJSIP/23-0000000e", "returnhere=1") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:6] Gosub("PJSIP/23-0000000e", "app-blacklist-check,s,1()") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/23-0000000e", "0?blacklisted") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Set("PJSIP/23-0000000e", "CALLED_BLACKLIST=1") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] Return("PJSIP/23-0000000e", "") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:7] Set("PJSIP/23-0000000e", "CDR(did)=06938751318") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:8] GotoIf("PJSIP/23-0000000e", "0?") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/23-0000000e", "0 ?Set(CALLERID(name)=23)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:10] Set("PJSIP/23-0000000e", "__MOHCLASS=") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:11] Set("PJSIP/23-0000000e", "__REVERSAL_REJECT=FALSE") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:12] GotoIf("PJSIP/23-0000000e", "1?post-reverse-charge") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (ext-did,s,14)
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:14] NoOp("PJSIP/23-0000000e", "") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:15] Set("PJSIP/23-0000000e", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:16] Set("PJSIP/23-0000000e", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:17] Set("PJSIP/23-0000000e", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:18] Set("PJSIP/23-0000000e", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:19] NoOp("PJSIP/23-0000000e", "CallerID Entry Point") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:20] Set("PJSIP/23-0000000e", "__CRM_DIRECTION=INBOUND") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:21] Set("PJSIP/23-0000000e", "__CRM_SOURCE=23") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:22] Set("PJSIP/23-0000000e", "__CRM_LINKEDID=1632216942.17") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:23] AGI("PJSIP/23-0000000e", "agi://127.0.0.1/sangomacrm.agi,true") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] res_agi.c: <PJSIP/23-0000000e>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:24] ExecIf("PJSIP/23-0000000e", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:25] Goto("PJSIP/23-0000000e", "timeconditions,1,1") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (timeconditions,1,1)
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] Set("PJSIP/23-0000000e", "DB(TC/1/INUSESTATE)=INUSE") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Set("PJSIP/23-0000000e", "DB(TC/1/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] NoOp("PJSIP/23-0000000e", "TIMENOW: 12:35,Tue,21,Sep,Europe/Athens") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:4] NoOp("PJSIP/23-0000000e", "TIMEMATCHED: TRUE") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:5] GotoIfTime("PJSIP/23-0000000e", "08:00-16:00,mon-sat,1-31,jan-dec,Europe/Athens?truestate") in new stack
[2021-09-21 12:35:42] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (timeconditions,1,14)
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:14] GotoIf("PJSIP/23-0000000e", "0?falsegoto") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/23-0000000e", "0?Set(DB(TC/1)=)") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:16] Set("PJSIP/23-0000000e", "DEVICE_STATE(Custom:TC1)=NOT_INUSE") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:17] ExecIf("PJSIP/23-0000000e", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:18] GotoIf("PJSIP/23-0000000e", "1?ivr-2,s,1") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx_builtins.c: Goto (ivr-2,s,1)
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] Set("PJSIP/23-0000000e", "TIMEOUT_LOOPCOUNT=0") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] Set("PJSIP/23-0000000e", "INVALID_LOOPCOUNT=0") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] Set("PJSIP/23-0000000e", "_IVR_CONTEXT_ivr-2=") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:4] Set("PJSIP/23-0000000e", "_IVR_CONTEXT=ivr-2") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:5] Set("PJSIP/23-0000000e", "__IVR_RETVM=") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:6] GotoIf("PJSIP/23-0000000e", "0?skip") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:7] Answer("PJSIP/23-0000000e", "") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:8] Set("PJSIP/23-0000000e", "IVR_MSG=custom/Anakiklosi-day") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:9] Set("PJSIP/23-0000000e", "TIMEOUT(digit)=0") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] func_timeout.c: Digit timeout set to 0.000
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:10] Read("PJSIP/23-0000000e", "IVREXT,custom/Anakiklosi-day,,,0,0") in new stack
[2021-09-21 12:35:43] VERBOSE[7304][C-0000000b] file.c: <PJSIP/23-0000000e> Playing 'custom/Anakiklosi-day.ulaw' (language 'en')
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] app_read.c: User disconnected
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] Hangup("PJSIP/23-0000000e", "") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Spawn extension (ivr-2, h, 1) exited non-zero on 'PJSIP/23-0000000e'
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] app_stack.c: PJSIP/23-0000000e Internal Gosub(crm-hangup,s,1) start
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/23-0000000e", "Sending Hangup to CRM") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:2] NoOp("PJSIP/23-0000000e", "HANGUP CAUSE: 16") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/23-0000000e", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:4] NoOp("PJSIP/23-0000000e", "MASTER CHANNEL: 1632216942.17 = 1632216942.17") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:5] GotoIf("PJSIP/23-0000000e", "0?return") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:6] Set("PJSIP/23-0000000e", "__CRM_HANGUP=1") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:7] AGI("PJSIP/23-0000000e", "agi://127.0.0.1/sangomacrm.agi") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] res_agi.c: <PJSIP/23-0000000e>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] pbx.c: Executing [[email protected]:8] Return("PJSIP/23-0000000e", "") in new stack
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] app_stack.c: Spawn extension (ivr-2, h, 1) exited non-zero on 'PJSIP/23-0000000e'
[2021-09-21 12:35:44] VERBOSE[7304][C-0000000b] app_stack.c: PJSIP/23-0000000e Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2021-09-21 12:35:49] WARNING[2562] res_pjsip_registrar.c: Endpoint 'anonymous' (192.168.1.252:5060) has no configured AORs
[2021-09-21 12:35:52] WARNING[2562] res_pjsip_registrar.c: Endpoint 'anonymous' (192.168.1.252:5062) has no configured AORs
[2021-09-21 12:36:00] NOTICE[2562] res_pjsip_exten_state.c: Endpoint '23' state subscription failed: Extension '204' does not exist in context 'from-trunk' or has no associated hint
[2021-09-21 12:36:01] NOTICE[2562] res_pjsip_exten_state.c: Endpoint '23' state subscription failed: Extension '204' does not exist in context 'from-trunk' or has no associated hint