Outgoing Calls are not Going Through

FreePBX Endpoints
1

I have a strange problem. I hooked up freepbx to a GSM gateway and I have setup some rules. Here is what I’m having:
-Outgoing calls from an extension works perfect via the GSM gateway trunk.
-Incoming calls from the GSM gateway to any extension work good too.

I have some extensions with “follow me” option setup. These extension have a mobile number called and the call goes over the same GSM gateway.
-Incoming calls from the GSM gateway to an extension with a “follow me” option that needs to go back via the GSM gateway never go through and I get line conjested.

Below are the logs from the freepbx. I have tried to dial from extension 9000 to extension 1801, which has a follow me to 00966504684651. The call never goes through.
I tried calling from 9000 to 00966504684651 and it works perfectly!

2

[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: CW Ignore is:
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: CF Ignore is:
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: CW IN_USE/BUSY is: 1
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Methodology of ring is ‘ringallv2-prim’
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Added extension 00966504684651# to extension map
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Extension 1801 cf is disabled
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Extension 00966504684651# cf is disabled
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Extension 1801 do not disturb is disabled
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: EXTENSION_STATE: 4 (UNAVAILABLE)
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Extension 1801 has ExtensionState: 4
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Discovered PJSIP Endpoint PJSIP/1801
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Ended up with no PJSIP contacts
[2020-07-20 06:47:27] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: dbset CALLTRACE/1801 to 9000
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: Filtered ARG3: 1801-00966504684651
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: RING ALL V2 : 00966504684651#
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: RVOL_MODE ‘’
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: RVOL is:
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_agi.c: dialparties.agi: RVOLPARENT is:
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_agi.c: <SIP/9000-00000004>AGI Script dialparties.agi completed, returning 0
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:8] GotoIf(“SIP/9000-00000004”, “1?normdial”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx_builtins.c: Goto (macro-dial,s,11)
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:11] NoOp(“SIP/9000-00000004”, “Returned from dialparties with groups to dial”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:12] NoOp(“SIP/9000-00000004”, "ringall array 00966504684651# ") in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:13] Set(“SIP/9000-00000004”, “__FMGL_DIAL=00966504684651#”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:14] Set(“SIP/9000-00000004”, “LOOPCNT=2”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:15] Set(“SIP/9000-00000004”, “ITER=1”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:16] Set(“SIP/9000-00000004”, “__EXTTOCALL=1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:17] NoOp(“SIP/9000-00000004”, “Working with 1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:18] ExecIf(“SIP/9000-00000004”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:19] ExecIf(“SIP/9000-00000004”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:20] Set(“SIP/9000-00000004”, “ITER=2”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:21] GotoIf(“SIP/9000-00000004”, “1?ndloopbegin”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx_builtins.c: Goto (macro-dial,s,16)
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:16] Set(“SIP/9000-00000004”, “__EXTTOCALL=00966504684651”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:17] NoOp(“SIP/9000-00000004”, “Working with 00966504684651”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:18] ExecIf(“SIP/9000-00000004”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:19] ExecIf(“SIP/9000-00000004”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:20] Set(“SIP/9000-00000004”, “ITER=3”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:21] GotoIf(“SIP/9000-00000004”, “0?ndloopbegin”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:22] Macro(“SIP/9000-00000004”, “dial-ringall-predial-hook,”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial-ringall-predial-hook:1] MacroExit(“SIP/9000-00000004”, “”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:23] ExecIf(“SIP/9000-00000004”, “0?Set(CWRING=r(callwaiting)):Set(CWRING=)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:24] ExecIf(“SIP/9000-00000004”, “0?Set(ds=Local/FMPR-1801@from-internal&Local/FMGL-00966504684651#@from-internal,75,m(none)TtIM(auto-blkvm)g)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@macro-dial:25] Dial(“SIP/9000-00000004”, “Local/FMPR-1801@from-internal&Local/FMGL-00966504684651#@from-internal,75,m(none)TtIM(auto-blkvm)b(func-apply-sipheaders^s^1),”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_stack.c: Local/FMPR-1801@from-internal-00000023;1 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“Local/FMPR-1801@from-internal-00000023;1”, “0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“Local/FMPR-1801@from-internal-00000023;1”, “Applying SIP Headers to channel Local/FMPR-1801@from-internal-00000023;1”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“Local/FMPR-1801@from-internal-00000023;1”, “TECH=Local”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“Local/FMPR-1801@from-internal-00000023;1”, “SIPHEADERKEYS=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:5] While(“Local/FMPR-1801@from-internal-00000023;1”, “0”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_while.c: Jumping to priority 13
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“Local/FMPR-1801@from-internal-00000023;1”, “”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_stack.c: Spawn extension (from-internal, 1801, 1) exited non-zero on ‘Local/FMPR-1801@from-internal-00000023;1’
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_stack.c: Local/FMPR-1801@from-internal-00000023;1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_stack.c: Local/FMGL-00966504684651#@from-internal-00000024;1 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“Local/FMGL-00966504684651#@from-internal-00000024;1”, “0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“Local/FMGL-00966504684651#@from-internal-00000024;1”, “Applying SIP Headers to channel Local/FMGL-00966504684651#@from-internal-00000024;1”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“Local/FMGL-00966504684651#@from-internal-00000024;1”, “TECH=Local”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“Local/FMGL-00966504684651#@from-internal-00000024;1”, “SIPHEADERKEYS=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:5] While(“Local/FMGL-00966504684651#@from-internal-00000024;1”, “0”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_while.c: Jumping to priority 13
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“Local/FMGL-00966504684651#@from-internal-00000024;1”, “”) in new stack
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_stack.c: Spawn extension (from-internal, 1801, 1) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000024;1’
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_stack.c: Local/FMGL-00966504684651#@from-internal-00000024;1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_dial.c: Called Local/FMPR-1801@from-internal
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] app_dial.c: Called Local/FMGL-00966504684651#@from-internal
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_musiconhold.c: Started music on hold, class ‘none’, on channel ‘SIP/9000-00000004’
[2020-07-20 06:47:28] WARNING[22383][C-0000001c] format_wav.c: Read failed (type)
[2020-07-20 06:47:28] WARNING[22383][C-0000001c] file.c: Unable to open format wav
[2020-07-20 06:47:28] WARNING[22383][C-0000001c] res_musiconhold.c: Unable to open file ‘/var/lib/asterisk/moh/.nomusic_reserved/silence’: No such file or directory
[2020-07-20 06:47:28] VERBOSE[22383][C-0000001c] res_musiconhold.c: Stopped music on hold on SIP/9000-00000004
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [FMPR-1801@from-internal:1] Set(“Local/FMPR-1801@from-internal-00000023;2”, “CDR_PROP(disable)=true”) in new stack
[2020-07-20 06:47:28] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:1] Set(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “CDR_PROP(disable)=true”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [FMPR-1801@from-internal:2] Set(“Local/FMPR-1801@from-internal-00000023;2”, “RingGroupMethod=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [FMPR-1801@from-internal:3] Set(“Local/FMPR-1801@from-internal-00000023;2”, “USE_CONFIRMATION=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [FMPR-1801@from-internal:4] Set(“Local/FMPR-1801@from-internal-00000023;2”, “RINGGROUP_INDEX=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [FMPR-1801@from-internal:5] Macro(“Local/FMPR-1801@from-internal-00000023;2”, “simple-dial,1801,15”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:1] Set(“Local/FMPR-1801@from-internal-00000023;2”, “__EXTTOCALL=1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:2] Set(“Local/FMPR-1801@from-internal-00000023;2”, “RT=15”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:3] Set(“Local/FMPR-1801@from-internal-00000023;2”, “CFUEXT=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:4] Set(“Local/FMPR-1801@from-internal-00000023;2”, “CFBEXT=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:5] Set(“Local/FMPR-1801@from-internal-00000023;2”, “CWI_TMP=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:6] Macro(“Local/FMPR-1801@from-internal-00000023;2”, “dial-one,15,Ttr,1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:1] Set(“Local/FMPR-1801@from-internal-00000023;2”, “DEXTEN=1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:2] Set(“Local/FMPR-1801@from-internal-00000023;2”, “__CRM_SOURCE=9000”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:3] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?Set(__EXTTOCALL=1801)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:4] Set(“Local/FMPR-1801@from-internal-00000023;2”, “DIALSTATUS_CW=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:5] GosubIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?screen,1()”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:6] GosubIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?cf,1()”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:7] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?skip1”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:10] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?nodial”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:11] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?continue”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:12] Set(“Local/FMPR-1801@from-internal-00000023;2”, “EXTHASCW=ENABLED”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:13] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?next1:cwinusebusy”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:25] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?next3:continue”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:27] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?nodial”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:28] GosubIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?dstring,1():dlocal,1()”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:1] Set(“Local/FMPR-1801@from-internal-00000023;2”, “DSTRING=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:2] Set(“Local/FMPR-1801@from-internal-00000023;2”, “DEVICES=1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?Return()”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?Set(DEVICES=801)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:5] Set(“Local/FMPR-1801@from-internal-00000023;2”, “LOOPCNT=1”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:6] Set(“Local/FMPR-1801@from-internal-00000023;2”, “ITER=1”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:7] Set(“Local/FMPR-1801@from-internal-00000023;2”, “THISDIAL=PJSIP/1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:8] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?docheck”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:9] NoOp(“Local/FMPR-1801@from-internal-00000023;2”, “Debug: Found PJSIP Destination PJSIP/1801”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:10] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?doset”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:11] NoOp(“Local/FMPR-1801@from-internal-00000023;2”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:12] Set(“Local/FMPR-1801@from-internal-00000023;2”, “THISDIAL=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:13] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?skipset”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-dial-one,dstring,16)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:16] Set(“Local/FMPR-1801@from-internal-00000023;2”, “ITER=2”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?begin”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?Return()”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:29] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?nodial”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-dial-one,s,61)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:61] NoOp(“Local/FMPR-1801@from-internal-00000023;2”, “”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:62] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?Set(DIALSTATUS=NOANSWER)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:63] NoOp(“Local/FMPR-1801@from-internal-00000023;2”, “Returned from dial-one with nothing to call and DIALSTATUS: CHANUNAVAIL”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-dial-one:64] MacroExit(“Local/FMPR-1801@from-internal-00000023;2”, “”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:7] Set(“Local/FMPR-1801@from-internal-00000023;2”, “__CWIGNORE=”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:8] Set(“Local/FMPR-1801@from-internal-00000023;2”, “PR_DIALSTATUS=CHANUNAVAIL”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:9] GosubIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?docfu,1()”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:10] GosubIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?docfb,1()”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:11] Set(“Local/FMPR-1801@from-internal-00000023;2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-simple-dial:12] Goto(“Local/FMPR-1801@from-internal-00000023;2”, “s-CHANUNAVAIL,1”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-simple-dial,s-CHANUNAVAIL,1)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s-CHANUNAVAIL@macro-simple-dial:1] NoOp(“Local/FMPR-1801@from-internal-00000023;2”, “Extension is reporting s-CHANUNAVAIL”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [FMPR-1801@from-internal:6] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?Set(SHARED(FM_DND,SIP/9000-00000004)=DND)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [FMPR-1801@from-internal:7] Hangup(“Local/FMPR-1801@from-internal-00000023;2”, “”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Spawn extension (from-internal, FMPR-1801, 7) exited non-zero on ‘Local/FMPR-1801@from-internal-00000023;2’
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [h@from-internal:1] Macro(“Local/FMPR-1801@from-internal-00000023;2”, “hangupcall”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?theend”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“Local/FMPR-1801@from-internal-00000023;2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-hangupcall:4] NoOp(“Local/FMPR-1801@from-internal-00000023;2”, " montior file= ") in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-hangupcall:5] GotoIf(“Local/FMPR-1801@from-internal-00000023;2”, “1?skipagi”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Executing [s@macro-hangupcall:7] Hangup(“Local/FMPR-1801@from-internal-00000023;2”, “”) in new stack
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘Local/FMPR-1801@from-internal-00000023;2’ in macro ‘hangupcall’
[2020-07-20 06:47:28] VERBOSE[22385][C-0000001c] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘Local/FMPR-1801@from-internal-00000023;2’
[2020-07-20 06:47:28] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:2] Set(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “DIALNUMS=00966504684651#”) in new stack
[2020-07-20 06:47:28] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:3] Set(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “ENDLOOP=1595216863”) in new stack
[2020-07-20 06:47:28] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:28] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1”) in new stack
[2020-07-20 06:47:29] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1?start”) in new stack
[2020-07-20 06:47:29] VERBOSE[22386][C-0000001c] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:29] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:29] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1”) in new stack
[2020-07-20 06:47:30] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1?start”) in new stack
[2020-07-20 06:47:30] VERBOSE[22386][C-0000001c] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:30] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:30] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1”) in new stack
[2020-07-20 06:47:31] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1?start”) in new stack
[2020-07-20 06:47:31] VERBOSE[22386][C-0000001c] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:31] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:31] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1?start”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1”) in new stack
[2020-07-20 06:47:32] WARNING[2685] chan_sip.c: Retransmission timeout reached on transmission UtBaNZSvcf6Ls-fDjgQEyQ… for seqno 2 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6399ms with no response
[2020-07-20 06:47:32] WARNING[2685] chan_sip.c: Hanging up call UtBaNZSvcf6Ls-fDjgQEyQ… - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2020-07-20 06:47:32] VERBOSE[22383][C-0000001c] app_macro.c: Spawn extension (macro-dial, s, 25) exited non-zero on ‘SIP/9000-00000004’ in macro ‘dial’
[2020-07-20 06:47:32] VERBOSE[22383][C-0000001c] pbx.c: Spawn extension (followme-sub, 1801, 41) exited non-zero on ‘SIP/9000-00000004’
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Spawn extension (from-internal, FMGL-00966504684651#, 5) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000024;2’
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [h@from-internal:1] Macro(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “hangupcall”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1?theend”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [s@macro-hangupcall:4] NoOp(“Local/FMGL-00966504684651#@from-internal-00000024;2”, " montior file= ") in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [s@macro-hangupcall:5] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “1?skipagi”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Executing [s@macro-hangupcall:7] Hangup(“Local/FMGL-00966504684651#@from-internal-00000024;2”, “”) in new stack
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000024;2’ in macro ‘hangupcall’
[2020-07-20 06:47:32] VERBOSE[22386][C-0000001c] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000024;2’
[2020-07-20 06:47:38] VERBOSE[2685][C-0000001d] netsock2.c: Using SIP RTP TOS bits 184
[2020-07-20 06:47:38] VERBOSE[2685][C-0000001d] netsock2.c: Using SIP RTP CoS mark 5
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@from-internal:1] GotoIf(“SIP/9000-00000005”, “0?ext-local,1801,1:followme-check,1801,1”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (followme-check,1801,1)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-check:1] Gosub(“SIP/9000-00000005”, “followme-sub,1801,1()”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:1] GotoIf(“SIP/9000-00000005”, “0?skipclid”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:2] Macro(“SIP/9000-00000005”, “user-callerid,”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/9000-00000005”, “TOUCH_MONITOR=1595216858.115”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/9000-00000005”, “AMPUSER=9000”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:3] Set(“SIP/9000-00000005”, “HOTDESCKCHAN=9000-00000005”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:4] Set(“SIP/9000-00000005”, “HOTDESKEXTEN=9000”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/9000-00000005”, “HOTDESKCALL=0”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:6] ExecIf(“SIP/9000-00000005”, “0?Set(HOTDESKCALL=1)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:7] ExecIf(“SIP/9000-00000005”, “0?Set(CALLERID(name)=)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:8] GotoIf(“SIP/9000-00000005”, “0?report”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:9] ExecIf(“SIP/9000-00000005”, “1?Set(REALCALLERIDNUM=9000)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:10] Set(“SIP/9000-00000005”, “AMPUSER=9000”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:11] GotoIf(“SIP/9000-00000005”, “0?limit”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:12] Set(“SIP/9000-00000005”, “AMPUSERCIDNAME=Marwan Kandeel Zoiper Extension”) in new stack

3

Freepbx logs part 2:
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:13] ExecIf(“SIP/9000-00000005”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:14] GotoIf(“SIP/9000-00000005”, “0?report”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:15] Set(“SIP/9000-00000005”, “AMPUSERCID=9000”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:16] Set(“SIP/9000-00000005”, “__DIAL_OPTIONS=Ttr”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:17] Set(“SIP/9000-00000005”, “CALLERID(all)=“Marwan Kandeel Zoiper Extension” <9000>”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:18] ExecIf(“SIP/9000-00000005”, “0?Set(CUSDIAL=)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:19] ExecIf(“SIP/9000-00000005”, “0?Set(CALLERID(all)=“Marwan Kandeel Zoiper Extension” <9000>)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:20] GotoIf(“SIP/9000-00000005”, “0?limit”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:21] ExecIf(“SIP/9000-00000005”, “0?Set(GROUP(concurrency_limit)=9000)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:22] ExecIf(“SIP/9000-00000005”, “0?Set(CHANNEL(language)=)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:23] NoOp(“SIP/9000-00000005”, “Macro Depth is 1”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:24] GotoIf(“SIP/9000-00000005”, “1?report2:macroerror”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (macro-user-callerid,s,25)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:25] GotoIf(“SIP/9000-00000005”, “0?continue”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:26] ExecIf(“SIP/9000-00000005”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:27] Set(“SIP/9000-00000005”, “__TTL=64”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:28] GotoIf(“SIP/9000-00000005”, “1?continue”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (macro-user-callerid,s,44)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:44] Set(“SIP/9000-00000005”, “CALLERID(number)=9000”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:45] Set(“SIP/9000-00000005”, “CALLERID(name)=Marwan Kandeel Zoiper Extension”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:46] GotoIf(“SIP/9000-00000005”, “0?cnum”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:47] Set(“SIP/9000-00000005”, “CDR(cnam)=Marwan Kandeel Zoiper Extension”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:48] Set(“SIP/9000-00000005”, “CDR(cnum)=9000”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-user-callerid:49] Set(“SIP/9000-00000005”, “CHANNEL(language)=en”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:3] Set(“SIP/9000-00000005”, “DIAL_OPTIONS=TtrI”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:4] Set(“SIP/9000-00000005”, “CONNECTEDLINE(num,i)=1801”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:5] Gosub(“SIP/9000-00000005”, “sub-presencestate-display,s,1(1801)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-presencestate-display:1] Goto(“SIP/9000-00000005”, “state-available,1”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (sub-presencestate-display,state-available,1)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [state-available@sub-presencestate-display:1] Set(“SIP/9000-00000005”, “PRESENCESTATE_DISPLAY=(Available)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [state-available@sub-presencestate-display:2] Return(“SIP/9000-00000005”, “”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:6] Set(“SIP/9000-00000005”, “CONNECTEDLINE(name)=Auto Works On Call Support(Available)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:7] Set(“SIP/9000-00000005”, “FM_DIALSTATUS=UNAVAILABLE”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:8] Set(“SIP/9000-00000005”, “__EXTTOCALL=1801”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:9] Set(“SIP/9000-00000005”, “__PICKUPMARK=1801”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:10] Macro(“SIP/9000-00000005”, “blkvm-setifempty,”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/9000-00000005”, “1?init”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (macro-blkvm-setifempty,s,4)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-blkvm-setifempty:4] Set(“SIP/9000-00000005”, “__BLKVM_CHANNEL=SIP/9000-00000005”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-blkvm-setifempty:5] Set(“SIP/9000-00000005”, “SHARED(BLKVM,SIP/9000-00000005)=TRUE”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-blkvm-setifempty:6] Set(“SIP/9000-00000005”, “GOSUB_RETVAL=TRUE”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/9000-00000005”, “”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:11] GotoIf(“SIP/9000-00000005”, “1?skipov”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (followme-sub,1801,14)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:14] Set(“SIP/9000-00000005”, “RRNODEST=”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:15] Set(“SIP/9000-00000005”, “__NODEST=1801”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:16] GosubIf(“SIP/9000-00000005”, “0?sub-fmsetcid,s,1()”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:17] GotoIf(“SIP/9000-00000005”, “1?skipprepend”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (followme-sub,1801,19)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:19] Set(“SIP/9000-00000005”, “RecordMethod=Group”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:20] Gosub(“SIP/9000-00000005”, “sub-record-check,s,1(exten,1801,)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/9000-00000005”, “0?initialized”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:2] Set(“SIP/9000-00000005”, “__REC_STATUS=INITIALIZED”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:3] Set(“SIP/9000-00000005”, “NOW=1595216858”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:4] Set(“SIP/9000-00000005”, “__DAY=20”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:5] Set(“SIP/9000-00000005”, “__MONTH=07”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:6] Set(“SIP/9000-00000005”, “__YEAR=2020”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:7] Set(“SIP/9000-00000005”, “__TIMESTR=20200720-064738”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:8] Set(“SIP/9000-00000005”, “__FROMEXTEN=9000”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:9] Set(“SIP/9000-00000005”, “__MON_FMT=wav”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/9000-00000005”, “Recordings initialized”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/9000-00000005”, “1?Set(ARG3=dontcare)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/9000-00000005”, “REC_POLICY_MODE_SAVE=”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/9000-00000005”, “0?Set(REC_STATUS=NO)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/9000-00000005”, “5?checkaction”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (sub-record-check,s,17)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/9000-00000005”, “1?sub-record-check,exten,1”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:1] NoOp(“SIP/9000-00000005”, “Exten Recording Check between 9000 and 1801”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:2] Set(“SIP/9000-00000005”, “CALLTYPE=internal”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:3] ExecIf(“SIP/9000-00000005”, “0?Set(CALLTYPE=)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:4] Set(“SIP/9000-00000005”, “CALLEE=dontcare”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:5] ExecIf(“SIP/9000-00000005”, “0?Set(CALLEE=dontcare)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:6] GotoIf(“SIP/9000-00000005”, “0?callee”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:7] GotoIf(“SIP/9000-00000005”, “1?caller”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (sub-record-check,exten,13)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:13] Set(“SIP/9000-00000005”, “RECMODE=dontcare”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:14] ExecIf(“SIP/9000-00000005”, “0?Set(RECMODE=dontcare)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:15] ExecIf(“SIP/9000-00000005”, “1?Set(RECMODE=dontcare)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:16] Gosub(“SIP/9000-00000005”, “recordcheck,1(dontcare,internal,1801)”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/9000-00000005”, “Starting recording check against dontcare”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/9000-00000005”, “dontcare”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/9000-00000005”, “”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [exten@sub-record-check:17] Return(“SIP/9000-00000005”, “”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:21] GotoIf(“SIP/9000-00000005”, “1?skipdring”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (followme-sub,1801,24)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:24] Set(“SIP/9000-00000005”, “STRATEGY=ringallv2-prim”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:25] Set(“SIP/9000-00000005”, “__RVOL=”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:26] GotoIf(“SIP/9000-00000005”, “1?skipsimple”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (followme-sub,1801,29)
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:29] Set(“SIP/9000-00000005”, “RingGroupMethod=ringallv2-prim”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:30] Set(“SIP/9000-00000005”, “_FMGRP=1801”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:31] GotoIf(“SIP/9000-00000005”, “0?DIALGRP”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:32] Answer(“SIP/9000-00000005”, “”) in new stack
[2020-07-20 06:47:38] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:33] Wait(“SIP/9000-00000005”, “1”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:34] Playback(“SIP/9000-00000005”, “custom/AutoWorks-PleaseHold-AR-voice-hq&custom/AutoWorks-CallRecording-AR-voice-hq”) in new stack
[2020-07-20 06:47:39] WARNING[22403][C-0000001d] file.c: File custom/AutoWorks-PleaseHold-AR-voice-hq does not exist in any format
[2020-07-20 06:47:39] WARNING[22403][C-0000001d] file.c: Unable to open custom/AutoWorks-PleaseHold-AR-voice-hq (format (ulaw)): No such file or directory
[2020-07-20 06:47:39] WARNING[22403][C-0000001d] app_playback.c: Playback failed on SIP/9000-00000005 for custom/AutoWorks-PleaseHold-AR-voice-hq&custom/AutoWorks-CallRecording-AR-voice-hq
[2020-07-20 06:47:39] WARNING[22403][C-0000001d] file.c: File custom/AutoWorks-CallRecording-AR-voice-hq does not exist in any format
[2020-07-20 06:47:39] WARNING[22403][C-0000001d] file.c: Unable to open custom/AutoWorks-CallRecording-AR-voice-hq (format (ulaw)): No such file or directory
[2020-07-20 06:47:39] WARNING[22403][C-0000001d] app_playback.c: Playback failed on SIP/9000-00000005 for custom/AutoWorks-PleaseHold-AR-voice-hq&custom/AutoWorks-CallRecording-AR-voice-hq
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:35] ExecIf(“SIP/9000-00000005”, “0?Set(DOPTS=TtrI):Set(DOPTS=m(none)TtI)”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:36] Set(“SIP/9000-00000005”, “__ALT_CONFIRM_MSG=”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:37] GotoIf(“SIP/9000-00000005”, “0?doconfirm”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:38] GotoIf(“SIP/9000-00000005”, “1?ringallv21”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (followme-sub,1801,41)
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [1801@followme-sub:41] Macro(“SIP/9000-00000005”, “dial,75,m(none)TtI,00966504684651#”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:1] NoOp(“SIP/9000-00000005”, "Blind Transfer: , Attended Transfer: , User: 9000, Alert Info: ") in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:2] Set(“SIP/9000-00000005”, “__CRM_SOURCE=9000”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:3] ExecIf(“SIP/9000-00000005”, “1?Set(ALERT_INFO=)”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:4] ExecIf(“SIP/9000-00000005”, “0?Set(ALERT_INFO=)”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:5] ExecIf(“SIP/9000-00000005”, “0?Set(ALERT_INFO=)”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:6] ExecIf(“SIP/9000-00000005”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:7] AGI(“SIP/9000-00000005”, “dialparties.agi”) in new stack
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Caller ID name is ‘Marwan Kandeel Zoiper Extension’ number is ‘9000’
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: CW Ignore is:
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: CF Ignore is:
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: CW IN_USE/BUSY is: 1
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Methodology of ring is ‘ringallv2-prim’
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Added extension 00966504684651# to extension map
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Extension 1801 cf is disabled
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Extension 00966504684651# cf is disabled
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Extension 1801 do not disturb is disabled
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: EXTENSION_STATE: 4 (UNAVAILABLE)
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Extension 1801 has ExtensionState: 4
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Discovered PJSIP Endpoint PJSIP/1801
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Ended up with no PJSIP contacts
[2020-07-20 06:47:39] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: dbset CALLTRACE/1801 to 9000
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: Filtered ARG3: 1801-00966504684651
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: RING ALL V2 : 00966504684651#
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: RVOL_MODE ‘’
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: RVOL is:
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_agi.c: dialparties.agi: RVOLPARENT is:
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_agi.c: <SIP/9000-00000005>AGI Script dialparties.agi completed, returning 0
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:8] GotoIf(“SIP/9000-00000005”, “1?normdial”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (macro-dial,s,11)
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:11] NoOp(“SIP/9000-00000005”, “Returned from dialparties with groups to dial”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:12] NoOp(“SIP/9000-00000005”, "ringall array 00966504684651# ") in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:13] Set(“SIP/9000-00000005”, “__FMGL_DIAL=00966504684651#”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:14] Set(“SIP/9000-00000005”, “LOOPCNT=2”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:15] Set(“SIP/9000-00000005”, “ITER=1”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:16] Set(“SIP/9000-00000005”, “__EXTTOCALL=1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:17] NoOp(“SIP/9000-00000005”, “Working with 1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:18] ExecIf(“SIP/9000-00000005”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:19] ExecIf(“SIP/9000-00000005”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:20] Set(“SIP/9000-00000005”, “ITER=2”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:21] GotoIf(“SIP/9000-00000005”, “1?ndloopbegin”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx_builtins.c: Goto (macro-dial,s,16)
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:16] Set(“SIP/9000-00000005”, “__EXTTOCALL=00966504684651”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:17] NoOp(“SIP/9000-00000005”, “Working with 00966504684651”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:18] ExecIf(“SIP/9000-00000005”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:19] ExecIf(“SIP/9000-00000005”, “0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:20] Set(“SIP/9000-00000005”, “ITER=3”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:21] GotoIf(“SIP/9000-00000005”, “0?ndloopbegin”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:22] Macro(“SIP/9000-00000005”, “dial-ringall-predial-hook,”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial-ringall-predial-hook:1] MacroExit(“SIP/9000-00000005”, “”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:23] ExecIf(“SIP/9000-00000005”, “0?Set(CWRING=r(callwaiting)):Set(CWRING=)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:24] ExecIf(“SIP/9000-00000005”, “0?Set(ds=Local/FMPR-1801@from-internal&Local/FMGL-00966504684651#@from-internal,75,m(none)TtIM(auto-blkvm)g)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@macro-dial:25] Dial(“SIP/9000-00000005”, “Local/FMPR-1801@from-internal&Local/FMGL-00966504684651#@from-internal,75,m(none)TtIM(auto-blkvm)b(func-apply-sipheaders^s^1),”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_stack.c: Local/FMPR-1801@from-internal-00000025;1 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“Local/FMPR-1801@from-internal-00000025;1”, “0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“Local/FMPR-1801@from-internal-00000025;1”, “Applying SIP Headers to channel Local/FMPR-1801@from-internal-00000025;1”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“Local/FMPR-1801@from-internal-00000025;1”, “TECH=Local”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“Local/FMPR-1801@from-internal-00000025;1”, “SIPHEADERKEYS=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:5] While(“Local/FMPR-1801@from-internal-00000025;1”, “0”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_while.c: Jumping to priority 13
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“Local/FMPR-1801@from-internal-00000025;1”, “”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_stack.c: Spawn extension (from-internal, 1801, 1) exited non-zero on ‘Local/FMPR-1801@from-internal-00000025;1’
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_stack.c: Local/FMPR-1801@from-internal-00000025;1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_stack.c: Local/FMGL-00966504684651#@from-internal-00000026;1 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“Local/FMGL-00966504684651#@from-internal-00000026;1”, “0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“Local/FMGL-00966504684651#@from-internal-00000026;1”, “Applying SIP Headers to channel Local/FMGL-00966504684651#@from-internal-00000026;1”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“Local/FMGL-00966504684651#@from-internal-00000026;1”, “TECH=Local”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“Local/FMGL-00966504684651#@from-internal-00000026;1”, “SIPHEADERKEYS=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:5] While(“Local/FMGL-00966504684651#@from-internal-00000026;1”, “0”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_while.c: Jumping to priority 13
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“Local/FMGL-00966504684651#@from-internal-00000026;1”, “”) in new stack
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_stack.c: Spawn extension (from-internal, 1801, 1) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000026;1’
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_stack.c: Local/FMGL-00966504684651#@from-internal-00000026;1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_dial.c: Called Local/FMPR-1801@from-internal
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] app_dial.c: Called Local/FMGL-00966504684651#@from-internal
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_musiconhold.c: Started music on hold, class ‘none’, on channel ‘SIP/9000-00000005’
[2020-07-20 06:47:40] WARNING[22403][C-0000001d] format_wav.c: Read failed (type)
[2020-07-20 06:47:40] WARNING[22403][C-0000001d] file.c: Unable to open format wav
[2020-07-20 06:47:40] WARNING[22403][C-0000001d] res_musiconhold.c: Unable to open file ‘/var/lib/asterisk/moh/.nomusic_reserved/silence’: No such file or directory
[2020-07-20 06:47:40] VERBOSE[22403][C-0000001d] res_musiconhold.c: Stopped music on hold on SIP/9000-00000005
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [FMPR-1801@from-internal:1] Set(“Local/FMPR-1801@from-internal-00000025;2”, “CDR_PROP(disable)=true”) in new stack
[2020-07-20 06:47:40] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:1] Set(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “CDR_PROP(disable)=true”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [FMPR-1801@from-internal:2] Set(“Local/FMPR-1801@from-internal-00000025;2”, “RingGroupMethod=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [FMPR-1801@from-internal:3] Set(“Local/FMPR-1801@from-internal-00000025;2”, “USE_CONFIRMATION=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [FMPR-1801@from-internal:4] Set(“Local/FMPR-1801@from-internal-00000025;2”, “RINGGROUP_INDEX=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [FMPR-1801@from-internal:5] Macro(“Local/FMPR-1801@from-internal-00000025;2”, “simple-dial,1801,15”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:1] Set(“Local/FMPR-1801@from-internal-00000025;2”, “__EXTTOCALL=1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:2] Set(“Local/FMPR-1801@from-internal-00000025;2”, “RT=15”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:3] Set(“Local/FMPR-1801@from-internal-00000025;2”, “CFUEXT=”) in new stack

4

Freepbx logs part 3:

[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:4] Set(“Local/FMPR-1801@from-internal-00000025;2”, “CFBEXT=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:5] Set(“Local/FMPR-1801@from-internal-00000025;2”, “CWI_TMP=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:6] Macro(“Local/FMPR-1801@from-internal-00000025;2”, “dial-one,15,Ttr,1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:1] Set(“Local/FMPR-1801@from-internal-00000025;2”, “DEXTEN=1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:2] Set(“Local/FMPR-1801@from-internal-00000025;2”, “__CRM_SOURCE=9000”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:3] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?Set(__EXTTOCALL=1801)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:4] Set(“Local/FMPR-1801@from-internal-00000025;2”, “DIALSTATUS_CW=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:5] GosubIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?screen,1()”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:6] GosubIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?cf,1()”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:7] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?skip1”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:10] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?nodial”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:11] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?continue”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:12] Set(“Local/FMPR-1801@from-internal-00000025;2”, “EXTHASCW=ENABLED”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:13] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?next1:cwinusebusy”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:25] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?next3:continue”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:27] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?nodial”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:28] GosubIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?dstring,1():dlocal,1()”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:1] Set(“Local/FMPR-1801@from-internal-00000025;2”, “DSTRING=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:2] Set(“Local/FMPR-1801@from-internal-00000025;2”, “DEVICES=1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?Return()”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?Set(DEVICES=801)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:5] Set(“Local/FMPR-1801@from-internal-00000025;2”, “LOOPCNT=1”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:6] Set(“Local/FMPR-1801@from-internal-00000025;2”, “ITER=1”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:7] Set(“Local/FMPR-1801@from-internal-00000025;2”, “THISDIAL=PJSIP/1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:8] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?docheck”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:9] NoOp(“Local/FMPR-1801@from-internal-00000025;2”, “Debug: Found PJSIP Destination PJSIP/1801”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:10] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?doset”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:11] NoOp(“Local/FMPR-1801@from-internal-00000025;2”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:12] Set(“Local/FMPR-1801@from-internal-00000025;2”, “THISDIAL=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:13] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?skipset”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-dial-one,dstring,16)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:16] Set(“Local/FMPR-1801@from-internal-00000025;2”, “ITER=2”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?begin”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?Return()”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:29] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?nodial”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-dial-one,s,61)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:61] NoOp(“Local/FMPR-1801@from-internal-00000025;2”, “”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:62] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?Set(DIALSTATUS=NOANSWER)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:63] NoOp(“Local/FMPR-1801@from-internal-00000025;2”, “Returned from dial-one with nothing to call and DIALSTATUS: CHANUNAVAIL”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-dial-one:64] MacroExit(“Local/FMPR-1801@from-internal-00000025;2”, “”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:7] Set(“Local/FMPR-1801@from-internal-00000025;2”, “__CWIGNORE=”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:8] Set(“Local/FMPR-1801@from-internal-00000025;2”, “PR_DIALSTATUS=CHANUNAVAIL”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:9] GosubIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?docfu,1()”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:10] GosubIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?docfb,1()”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:11] Set(“Local/FMPR-1801@from-internal-00000025;2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-simple-dial:12] Goto(“Local/FMPR-1801@from-internal-00000025;2”, “s-CHANUNAVAIL,1”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-simple-dial,s-CHANUNAVAIL,1)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s-CHANUNAVAIL@macro-simple-dial:1] NoOp(“Local/FMPR-1801@from-internal-00000025;2”, “Extension is reporting s-CHANUNAVAIL”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [FMPR-1801@from-internal:6] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?Set(SHARED(FM_DND,SIP/9000-00000005)=DND)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [FMPR-1801@from-internal:7] Hangup(“Local/FMPR-1801@from-internal-00000025;2”, “”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Spawn extension (from-internal, FMPR-1801, 7) exited non-zero on ‘Local/FMPR-1801@from-internal-00000025;2’
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [h@from-internal:1] Macro(“Local/FMPR-1801@from-internal-00000025;2”, “hangupcall”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?theend”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“Local/FMPR-1801@from-internal-00000025;2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-hangupcall:4] NoOp(“Local/FMPR-1801@from-internal-00000025;2”, " montior file= ") in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-hangupcall:5] GotoIf(“Local/FMPR-1801@from-internal-00000025;2”, “1?skipagi”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Executing [s@macro-hangupcall:7] Hangup(“Local/FMPR-1801@from-internal-00000025;2”, “”) in new stack
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘Local/FMPR-1801@from-internal-00000025;2’ in macro ‘hangupcall’
[2020-07-20 06:47:40] VERBOSE[22406][C-0000001d] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘Local/FMPR-1801@from-internal-00000025;2’
[2020-07-20 06:47:40] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:2] Set(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “DIALNUMS=00966504684651#”) in new stack
[2020-07-20 06:47:40] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:3] Set(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “ENDLOOP=1595216875”) in new stack
[2020-07-20 06:47:40] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:40] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1”) in new stack
[2020-07-20 06:47:41] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1?start”) in new stack
[2020-07-20 06:47:41] VERBOSE[22407][C-0000001d] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:41] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:41] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1”) in new stack
[2020-07-20 06:47:42] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1?start”) in new stack
[2020-07-20 06:47:42] VERBOSE[22407][C-0000001d] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:42] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:42] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1”) in new stack
[2020-07-20 06:47:43] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1?start”) in new stack
[2020-07-20 06:47:43] VERBOSE[22407][C-0000001d] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:43] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:43] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:6] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1?start”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx_builtins.c: Goto (from-internal,FMGL-00966504684651#,4)
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:4] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “0?dodnd”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [FMGL-00966504684651#@from-internal:5] Wait(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1”) in new stack
[2020-07-20 06:47:44] WARNING[2685] chan_sip.c: Retransmission timeout reached on transmission BHhDYGCrNQX8-RxvsZ976A… for seqno 2 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6399ms with no response
[2020-07-20 06:47:44] WARNING[2685] chan_sip.c: Hanging up call BHhDYGCrNQX8-RxvsZ976A… - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2020-07-20 06:47:44] VERBOSE[22403][C-0000001d] app_macro.c: Spawn extension (macro-dial, s, 25) exited non-zero on ‘SIP/9000-00000005’ in macro ‘dial’
[2020-07-20 06:47:44] VERBOSE[22403][C-0000001d] pbx.c: Spawn extension (followme-sub, 1801, 41) exited non-zero on ‘SIP/9000-00000005’
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Spawn extension (from-internal, FMGL-00966504684651#, 5) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000026;2’
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [h@from-internal:1] Macro(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “hangupcall”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1?theend”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [s@macro-hangupcall:4] NoOp(“Local/FMGL-00966504684651#@from-internal-00000026;2”, " montior file= ") in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [s@macro-hangupcall:5] GotoIf(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “1?skipagi”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Executing [s@macro-hangupcall:7] Hangup(“Local/FMGL-00966504684651#@from-internal-00000026;2”, “”) in new stack
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000026;2’ in macro ‘hangupcall’
[2020-07-20 06:47:44] VERBOSE[22407][C-0000001d] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘Local/FMGL-00966504684651#@from-internal-00000026;2’

5

If you want people to look at logs, make an effort to make them readable. Share log files using pastebin.

1 Like
6

Sorry! Missed that part! I will do it over pastebin ASAP.

7

There’s that. Not your problem, but a problem.

This is not good, and may well be part of your problem.

Where is the hash mark coming from? I’m pretty sure that’s not supposed to be there.

Did you follow the error messages here?

Like the other place this happens, this is a problem, but probably not your problem.

That’s all I’ve got. There are plenty of configuration errors in there - maybe get started on those, including the networking errors.

8

This hash tells FreePBX to dial an external line on follow me activation. We use it if we want to dial a user’s mobile when they are away from their extension. Below is FreePBX’s explaination:

Screenshot%20from%202020-07-21%2004-16-02
Screenshot%20from%202020-07-21%2004-16-021366×768 134 KB

9

Can you help me with this part? I have all network good. I’m able to ping both endpoints from each other and connectivity is 100% good. I have disabled FreePBX’s firewall and intrusion detection. Still getting the call dropped after 7 or 10 seconds and I see “Retransmission timeout reached on transmission”.

10

Here is pinging from FreePBX to the endpoint:

[root@jedpbx ~]# ping 192.168.22.60
PING 192.168.22.60 (192.168.22.60) 56(84) bytes of data.
64 bytes from 192.168.22.60: icmp_seq=1 ttl=64 time=5.63 ms
64 bytes from 192.168.22.60: icmp_seq=2 ttl=64 time=5.85 ms
64 bytes from 192.168.22.60: icmp_seq=3 ttl=64 time=5.14 ms
64 bytes from 192.168.22.60: icmp_seq=4 ttl=64 time=5.24 ms
64 bytes from 192.168.22.60: icmp_seq=5 ttl=64 time=5.10 ms
64 bytes from 192.168.22.60: icmp_seq=6 ttl=64 time=7.70 ms
64 bytes from 192.168.22.60: icmp_seq=7 ttl=64 time=5.45 ms
64 bytes from 192.168.22.60: icmp_seq=8 ttl=64 time=5.13 ms
64 bytes from 192.168.22.60: icmp_seq=9 ttl=64 time=5.15 ms
64 bytes from 192.168.22.60: icmp_seq=10 ttl=64 time=10.0 ms
64 bytes from 192.168.22.60: icmp_seq=11 ttl=64 time=5.13 ms
64 bytes from 192.168.22.60: icmp_seq=12 ttl=64 time=6.28 ms
64 bytes from 192.168.22.60: icmp_seq=13 ttl=64 time=5.48 ms
64 bytes from 192.168.22.60: icmp_seq=14 ttl=64 time=5.06 ms
64 bytes from 192.168.22.60: icmp_seq=15 ttl=64 time=6.31 ms
64 bytes from 192.168.22.60: icmp_seq=16 ttl=64 time=6.64 ms
64 bytes from 192.168.22.60: icmp_seq=17 ttl=64 time=5.21 ms
64 bytes from 192.168.22.60: icmp_seq=18 ttl=64 time=4.91 ms
64 bytes from 192.168.22.60: icmp_seq=19 ttl=64 time=4.96 ms
64 bytes from 192.168.22.60: icmp_seq=20 ttl=64 time=5.06 ms
64 bytes from 192.168.22.60: icmp_seq=21 ttl=64 time=6.60 ms
64 bytes from 192.168.22.60: icmp_seq=22 ttl=64 time=7.78 ms
64 bytes from 192.168.22.60: icmp_seq=23 ttl=64 time=4.97 ms
64 bytes from 192.168.22.60: icmp_seq=24 ttl=64 time=6.22 ms
64 bytes from 192.168.22.60: icmp_seq=25 ttl=64 time=6.32 ms
64 bytes from 192.168.22.60: icmp_seq=26 ttl=64 time=6.57 ms
64 bytes from 192.168.22.60: icmp_seq=27 ttl=64 time=7.79 ms
64 bytes from 192.168.22.60: icmp_seq=28 ttl=64 time=5.00 ms
64 bytes from 192.168.22.60: icmp_seq=29 ttl=64 time=5.19 ms
64 bytes from 192.168.22.60: icmp_seq=30 ttl=64 time=7.31 ms
64 bytes from 192.168.22.60: icmp_seq=31 ttl=64 time=5.18 ms
64 bytes from 192.168.22.60: icmp_seq=32 ttl=64 time=5.26 ms
64 bytes from 192.168.22.60: icmp_seq=33 ttl=64 time=4.92 ms

11

Ping uses ICMP, which only tests the basic network connection. In the logs, there are links to follow to troubleshoot your NAT errors. Start with those.

12

Hello @marwan83,

If you have only one channel on your GSM gateway, it is impossible to use it when it is occupied with an incoming call. Try to verify my point by routing the followme destination through your regular outbound route and through your GSM gateway.

Thank you,

Daniel Friedman
Trixton LTD.

13

Thanks for the input. I have a 4 channel GSM gateway and it was working perfectly good before.

14

Hello @marwan83,

Before what? clearly, you have a problem with your GSM gateway configuration. It is not sending a second simultaneous call to the other ports of the GSM gateway.

Thank you,

Daniel Friedman
Trixton LTD.

15

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