VMX - follow me and outbound mobiles not working

curto · May 4, 2010, 5:13pm

We have Followed Phillipes excellent article on setting up VMX and Follow me to enable a controlled call flow for trackign down a user.

Everything appears to work just correctly - except the outbound calls are not being mde to the external mobile number.

We have tried various ring strategies and none see to make a difference.

We are running FreepBX 2.7.0.1 PIAF 1.4 and Centos 5.2

Our outbound calls are current sent out a PRI

THe system is functioning pefectly for all other operations.

I have attached a log of the call flow when dialing into an extension (568)

The spawning for the to different dial streams appear to happen OK but none of the mobile calls appears to go off the network.

We have tested this on a couple of extensions and to differnet external mobile number

These same mobile numbers can de dialed from the Internal system

[2010-05-04 10:37:27] VERBOSE[24772] logger.c: – Executing [7500@ext-queues:17] Set(“Zap/19-1”, “MONITOR_FILENAME=/var/spool/asterisk/monitor/q7500-20100504-103727-1272933447.10710”) in new stack
[2010-05-04 10:37:52] VERBOSE[24772] logger.c: – Executing [7501@ext-queues:17] Set(“Zap/19-1”, “MONITOR_FILENAME=/var/spool/asterisk/monitor/q7501-20100504-103752-1272933447.10710”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [92557568@from-pstn:1] Set(“Zap/3-1”, “__FROM_DID=92557568”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [92557568@from-pstn:2] Gosub(“Zap/3-1”, “app-blacklist-check|s|1”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@app-blacklist-check:1] LookupBlacklist(“Zap/3-1”, “”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@app-blacklist-check:2] GotoIf(“Zap/3-1”, “0?blacklisted”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@app-blacklist-check:3] Set(“Zap/3-1”, “CALLED_BLACKLIST=1”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@app-blacklist-check:4] Return(“Zap/3-1”, “”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [92557568@from-pstn:3] ExecIf(“Zap/3-1”, “1 |Set|CALLERID(name)=410720545”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [92557568@from-pstn:4] Set(“Zap/3-1”, “__CALLINGPRES_SV=allowed_passed_screen”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [92557568@from-pstn:5] SetCallerPres(“Zap/3-1”, “allowed_not_screened”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [92557568@from-pstn:6] Goto(“Zap/3-1”, “from-did-direct|568|1”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (from-did-direct,568,1)
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [568@from-did-direct:1] GotoIf(“Zap/3-1”, “1?ext-local|568|1”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (ext-local,568,1)
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [568@ext-local:1] Macro(“Zap/3-1”, “exten-vm|568|568”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:1] Macro(“Zap/3-1”, “user-callerid|”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:1] Set(“Zap/3-1”, “AMPUSER=410720545”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Zap/3-1”, “0?report”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“Zap/3-1”, “1|Set|REALCALLERIDNUM=410720545”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: ExecIf
[2010-05-05 03:04:31] DEBUG[29334] func_db.c: DB: DEVICE/410720545/user not found in database.
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:4] Set(“Zap/3-1”, “AMPUSER=”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] DEBUG[29334] func_db.c: DB: AMPUSER//cidname not found in database.
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:5] Set(“Zap/3-1”, “AMPUSERCIDNAME=”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“Zap/3-1”, “1?report”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,10)
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“Zap/3-1”, “0?continue”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:11] Set(“Zap/3-1”, “__TTL=64”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“Zap/3-1”, “1?continue”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,19)
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:19] NoOp(“Zap/3-1”, “Using CallerID “410720545” <410720545>”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:2] Set(“Zap/3-1”, “RingGroupMethod=none”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:3] Set(“Zap/3-1”, “VMBOX=568”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:4] Set(“Zap/3-1”, “EXTTOCALL=568”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] DEBUG[29334] func_db.c: DB: CFU/568 not found in database.
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:5] Set(“Zap/3-1”, “CFUEXT=”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] DEBUG[29334] func_db.c: DB: CFB/568 not found in database.
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:6] Set(“Zap/3-1”, “CFBEXT=”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:7] Set(“Zap/3-1”, “RT=15”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:8] Macro(“Zap/3-1”, “record-enable|568|IN”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“Zap/3-1”, “1?check”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,4)
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“Zap/3-1”, “0|MacroExit|”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: ExecIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“Zap/3-1”, “0?Group:OUT”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,15)
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“Zap/3-1”, “1?IN”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,20)
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:20] ExecIf(“Zap/3-1”, “1|MacroExit|”) in new stack
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:9] Macro(“Zap/3-1”, “dial|15|tr|568”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-dial:1] GotoIf(“Zap/3-1”, “1?dial”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Goto (macro-dial,s,3)
[2010-05-05 03:04:31] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Executing [s@macro-dial:3] AGI(“Zap/3-1”, “dialparties.agi”) in new stack
[2010-05-05 03:04:31] VERBOSE[29334] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: dialparties.agi: Starting New Dialparties.agi
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: dialparties.agi: Caller ID name is ‘410720545’ number is ‘410720545’
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: dialparties.agi: Methodology of ring is ‘none’
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – dialparties.agi: Added extension 568 to extension map
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – dialparties.agi: Extension 568 cf is disabled
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – dialparties.agi: Extension 568 do not disturb is disabled
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: dialparties.agi: ExtensionState: 0
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: dialparties.agi: Extension 568 has ExtensionState: 0
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – dialparties.agi: Checking CW and CFB status for extension 568
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – dialparties.agi: dbset CALLTRACE/568 to 410720545
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – dialparties.agi: Filtered ARG3: 568
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – AGI Script dialparties.agi completed, returning 0
[2010-05-05 03:04:32] DEBUG[29334] app_macro.c: Executed application: AGI
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – Executing [s@macro-dial:7] Dial(“Zap/3-1”, “USTM/568@CraigC|15|tr”) in new stack
[2010-05-05 03:04:32] NOTICE[29334] chan_unistim.c: Asked to get a channel of format alaw while capability is 12 result : alaw (8)
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – unistim_request(568@CraigC)
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – Called 568@CraigC
[2010-05-05 03:04:32] VERBOSE[29334] logger.c: – USTM/568@CraigC-0 is ringing
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Nobody picked up in 15000 ms
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Dial
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-dial:8] Set(“Zap/3-1”, “DIALSTATUS=NOANSWER”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-dial:9] GosubIf(“Zap/3-1”, “0?NOANSWER|1”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GosubIf
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:10] GotoIf(“Zap/3-1”, “0?exit|return”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:11] Set(“Zap/3-1”, “SV_DIALSTATUS=NOANSWER”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:12] GosubIf(“Zap/3-1”, “0?docfu|1”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GosubIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:13] GosubIf(“Zap/3-1”, “0?docfb|1”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GosubIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:14] Set(“Zap/3-1”, “DIALSTATUS=NOANSWER”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:15] NoOp(“Zap/3-1”, “Voicemail is 568”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:16] GotoIf(“Zap/3-1”, “0?s-NOANSWER|1”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:17] NoOp(“Zap/3-1”, “Sending to Voicemail box 568”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-exten-vm:18] Macro(“Zap/3-1”, “vm|568|NOANSWER|”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-vm:1] Macro(“Zap/3-1”, “user-callerid|SKIPTTL”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:1] Set(“Zap/3-1”, “AMPUSER=410720545”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Zap/3-1”, “0?report”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“Zap/3-1”, “0|Set|REALCALLERIDNUM=410720545”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: ExecIf
[2010-05-05 03:04:47] DEBUG[29334] func_db.c: DB: DEVICE/410720545/user not found in database.
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:4] Set(“Zap/3-1”, “AMPUSER=”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] DEBUG[29334] func_db.c: DB: AMPUSER//cidname not found in database.
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:5] Set(“Zap/3-1”, “AMPUSERCIDNAME=”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“Zap/3-1”, “1?report”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,10)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“Zap/3-1”, “1?continue”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,19)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:19] NoOp(“Zap/3-1”, “Using CallerID “410720545” <410720545>”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-vm:2] Set(“Zap/3-1”, “VMGAIN=”"") in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] WARNING[29334] func_db.c: DB requires an argument, DB(/)
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-vm:3] GotoIf(“Zap/3-1”, “1?vmx|1”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,1)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:1] Set(“Zap/3-1”, “MEXTEN=568”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:2] Set(“Zap/3-1”, “MMODE=NOANSWER”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:3] Set(“Zap/3-1”, “RETVM=”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:4] Set(“Zap/3-1”, “MODE=unavail”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:5] GotoIf(“Zap/3-1”, “0?chknomsg”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:6] Set(“Zap/3-1”, “VM_OPTS=s”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:7] GotoIf(“Zap/3-1”, “0?s-NOANSWER|1”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:8] GotoIf(“Zap/3-1”, “1?notdirect”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,10)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:10] NoOp(“Zap/3-1”, “Checking if ext 568 is enabled: enabled”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:11] GotoIf(“Zap/3-1”, “0?s-NOANSWER|1”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:12] Macro(“Zap/3-1”, “get-vmcontext|568”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-get-vmcontext:1] Set(“Zap/3-1”, “VMCONTEXT=default”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“Zap/3-1”, “0?200:300”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-get-vmcontext,s,300)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [s@macro-get-vmcontext:300] NoOp(“Zap/3-1”, “”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: NoOp
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:13] GotoIf(“Zap/3-1”, “0?tmpgreet”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:14] GotoIf(“Zap/3-1”, “0?nofile”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:15] Set(“Zap/3-1”, “LOOPCOUNT=0”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:16] GotoIf(“Zap/3-1”, “1?vmxtime”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,18)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:18] GotoIf(“Zap/3-1”, “1?vmxloops”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,20)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:20] GotoIf(“Zap/3-1”, “1?vmxanswer”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,22)
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:22] Answer(“Zap/3-1”, “”) in new stack
[2010-05-05 03:04:47] DEBUG[29334] app_macro.c: Executed application: Answer
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:23] Read(“Zap/3-1”, “ACTION|/var/spool/asterisk/voicemail/default/568/unavail|1|skip|1|2”) in new stack
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – Accepting a maximum of 1 digits.
[2010-05-05 03:04:47] VERBOSE[29334] logger.c: – <Zap/3-1> Playing ‘/var/spool/asterisk/voicemail/default/568/unavail’ (language ‘au’)
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – User entered ‘1’
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Read
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:24] GotoIf(“Zap/3-1”, “1?checkopt”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,36)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:36] GotoIf(“Zap/3-1”, “1?doopt”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,54)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:54] NoOp(“Zap/3-1”, “Got a valid option: FM568”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:55] Set(“Zap/3-1”, “VMX_EXT=FM568”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:56] GotoIf(“Zap/3-1”, “1?getdest”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,61)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:61] GotoIf(“Zap/3-1”, “0?vmxpri”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:62] Set(“Zap/3-1”, “VMX_CONTEXT=ext-findmefollow”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:63] GotoIf(“Zap/3-1”, “0?vmxgoto”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:64] Set(“Zap/3-1”, “VMX_PRI=1”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:65] Goto(“Zap/3-1”, “ext-findmefollow|FM568|1”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (ext-findmefollow,FM568,1)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Goto
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: == Channel ‘Zap/3-1’ jumping out of macro ‘vm’
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: == Channel ‘Zap/3-1’ jumping out of macro ‘exten-vm’
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [FM568@ext-findmefollow:1] Goto(“Zap/3-1”, “568|FM568”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (ext-findmefollow,568,2)
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:2] Macro(“Zap/3-1”, “user-callerid|”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:1] Set(“Zap/3-1”, “AMPUSER=410720545”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Zap/3-1”, “0?report”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“Zap/3-1”, “0|Set|REALCALLERIDNUM=410720545”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: ExecIf
[2010-05-05 03:04:51] DEBUG[29334] func_db.c: DB: DEVICE/410720545/user not found in database.
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:4] Set(“Zap/3-1”, “AMPUSER=”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] DEBUG[29334] func_db.c: DB: AMPUSER//cidname not found in database.
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:5] Set(“Zap/3-1”, “AMPUSERCIDNAME=”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“Zap/3-1”, “1?report”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,10)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“Zap/3-1”, “0?continue”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:11] Set(“Zap/3-1”, “__TTL=63”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“Zap/3-1”, “1?continue”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,19)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:19] NoOp(“Zap/3-1”, “Using CallerID “410720545” <410720545>”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:3] GotoIf(“Zap/3-1”, “1?skipdb”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (ext-findmefollow,568,5)
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:5] Set(“Zap/3-1”, “__NODEST=”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:6] Set(“Zap/3-1”, “__BLKVM_OVERRIDE=BLKVM/568/Zap/3-1”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:7] Set(“Zap/3-1”, “__BLKVM_BASE=568”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:8] Set(“Zap/3-1”, “DB(BLKVM/568/Zap/3-1)=TRUE”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:9] Set(“Zap/3-1”, “RRNODEST=”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:10] Set(“Zap/3-1”, “__NODEST=568”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:11] GosubIf(“Zap/3-1”, “0?sub-fmsetcid|s|1”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:12] Set(“Zap/3-1”, “RecordMethod=Group”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:13] Macro(“Zap/3-1”, “record-enable|568-0410720545|Group”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“Zap/3-1”, “1?check”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,4)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“Zap/3-1”, “0|MacroExit|”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: ExecIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“Zap/3-1”, “1?Group:OUT”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,6)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:6] Set(“Zap/3-1”, “LOOPCNT=2”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:7] Set(“Zap/3-1”, “ITER=1”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:8] GotoIf(“Zap/3-1”, “1?continue”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,13)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:13] Set(“Zap/3-1”, “ITER=2”) in new stack
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:14] GotoIf(“Zap/3-1”, “1?begin”) in new stack
[2010-05-05 03:04:51] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,8)
[2010-05-05 03:04:51] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:52] DEBUG[29334] func_db.c: DB: AMPUSER/0410720545/recording not found in database.
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:8] GotoIf(“Zap/3-1”, “1?continue”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Goto (macro-record-enable,s,13)
[2010-05-05 03:04:52] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:13] Set(“Zap/3-1”, “ITER=3”) in new stack
[2010-05-05 03:04:52] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:14] GotoIf(“Zap/3-1”, “0?begin”) in new stack
[2010-05-05 03:04:52] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“Zap/3-1”, “0?IN”) in new stack
[2010-05-05 03:04:52] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:52] DEBUG[29334] func_db.c: DB: AMPUSER/568-0410720545/recording not found in database.
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-record-enable:16] ExecIf(“Zap/3-1”, “1|MacroExit|”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:14] Set(“Zap/3-1”, “RingGroupMethod=ringallv2”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:15] Set(“Zap/3-1”, “_FMGRP=568”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:16] GotoIf(“Zap/3-1”, “0?doconfirm”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:17] Macro(“Zap/3-1”, “dial|25|tr|568-0410720545”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-dial:1] GotoIf(“Zap/3-1”, “1?dial”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Goto (macro-dial,s,3)
[2010-05-05 03:04:52] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-dial:3] AGI(“Zap/3-1”, “dialparties.agi”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: dialparties.agi: Starting New Dialparties.agi
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: dialparties.agi: Caller ID name is ‘410720545’ number is ‘410720545’
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: dialparties.agi: Methodology of ring is ‘ringallv2’
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Added extension 568 to extension map
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Added extension 0410720545 to extension map
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Extension 568 cf is disabled
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Extension 0410720545 cf is disabled
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Extension 568 do not disturb is disabled
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Extension 0410720545 do not disturb is disabled
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: dialparties.agi: ExtensionState: 0
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: dialparties.agi: Extension 568 has ExtensionState: 0
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Checking CW and CFB status for extension 568
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: dbset CALLTRACE/568 to 410720545
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: dialparties.agi: ExtensionState: -1
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: dialparties.agi: Extension 0410720545 has ExtensionState: -1
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Checking CW and CFB status for extension 0410720545
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: dbset CALLTRACE/0410720545 to 410720545
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – dialparties.agi: Filtered ARG3: 568-0410720545
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – AGI Script dialparties.agi completed, returning 0
[2010-05-05 03:04:52] DEBUG[29334] app_macro.c: Executed application: AGI
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Executing [s@macro-dial:7] Dial(“Zap/3-1”, “Local/FMPR-568@from-internal&Local/FMGL-0410720545@from-internal|25|trM(auto-blkvm)”) in new stack
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Called FMPR-568@from-internal
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Called FMGL-0410720545@from-internal
[2010-05-05 03:04:52] VERBOSE[29334] logger.c: – Local/FMPR-568@from-internal-90cd,1 is ringing
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: == Everyone is busy/congested at this time (2:0/0/2)
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Dial
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-dial:8] Set(“Zap/3-1”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-dial:9] GosubIf(“Zap/3-1”, “0?CHANUNAVAIL|1”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GosubIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:18] Goto(“Zap/3-1”, “nextstep”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (ext-findmefollow,568,20)
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:20] Set(“Zap/3-1”, “RingGroupMethod=”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:21] GotoIf(“Zap/3-1”, “0?nodest”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:22] Set(“Zap/3-1”, “__NODEST=”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:23] DBdel(“Zap/3-1”, “BLKVM/568/Zap/3-1”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – DBdel: family=BLKVM, key=568/Zap/3-1
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [568@ext-findmefollow:24] Goto(“Zap/3-1”, “ext-local|vmb568|1”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (ext-local,vmb568,1)
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmb568@ext-local:1] Macro(“Zap/3-1”, “vm|568|BUSY|”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-vm:1] Macro(“Zap/3-1”, “user-callerid|SKIPTTL”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:1] Set(“Zap/3-1”, “AMPUSER=410720545”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Zap/3-1”, “0?report”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“Zap/3-1”, “0|Set|REALCALLERIDNUM=410720545”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: ExecIf
[2010-05-05 03:05:17] DEBUG[29334] func_db.c: DB: DEVICE/410720545/user not found in database.
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:4] Set(“Zap/3-1”, “AMPUSER=”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] DEBUG[29334] func_db.c: DB: AMPUSER//cidname not found in database.
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:5] Set(“Zap/3-1”, “AMPUSERCIDNAME=”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“Zap/3-1”, “1?report”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,10)
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“Zap/3-1”, “1?continue”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (macro-user-callerid,s,19)
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-user-callerid:19] NoOp(“Zap/3-1”, “Using CallerID “410720545” <410720545>”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-vm:2] Set(“Zap/3-1”, “VMGAIN=”"") in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] DEBUG[29334] func_db.c: DB: BLKVM/568/Zap/3-1 not found in database.
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-vm:3] GotoIf(“Zap/3-1”, “1?vmx|1”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,1)
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:1] Set(“Zap/3-1”, “MEXTEN=568”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:2] Set(“Zap/3-1”, “MMODE=BUSY”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:3] Set(“Zap/3-1”, “RETVM=”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:4] Set(“Zap/3-1”, “MODE=busy”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:5] GotoIf(“Zap/3-1”, “0?chknomsg”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:6] Set(“Zap/3-1”, “VM_OPTS=s”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:7] GotoIf(“Zap/3-1”, “0?s-BUSY|1”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:8] GotoIf(“Zap/3-1”, “1?notdirect”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (macro-vm,vmx,10)
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:10] NoOp(“Zap/3-1”, “Checking if ext 568 is enabled: disabled”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [vmx@macro-vm:11] GotoIf(“Zap/3-1”, “1?s-BUSY|1”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (macro-vm,s-BUSY,1)
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s-BUSY@macro-vm:1] NoOp(“Zap/3-1”, “BUSY voicemail”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Noop
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s-BUSY@macro-vm:2] Macro(“Zap/3-1”, “get-vmcontext|568”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-get-vmcontext:1] Set(“Zap/3-1”, “VMCONTEXT=default”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Set
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“Zap/3-1”, “0?200:300”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Goto (macro-get-vmcontext,s,300)
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: GotoIf
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s@macro-get-vmcontext:300] NoOp(“Zap/3-1”, “”) in new stack
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: NoOp
[2010-05-05 03:05:17] DEBUG[29334] app_macro.c: Executed application: Macro
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – Executing [s-BUSY@macro-vm:3] VoiceMail(“Zap/3-1”, “568@default|sb”) in new stack
[2010-05-05 03:05:17] VERBOSE[29334] logger.c: – <Zap/3-1> Playing ‘/var/spool/asterisk/voicemail/default/568/busy’ (language ‘au’)
[2010-05-05 03:05:19] VERBOSE[29334] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Zap/3-1’ in macro ‘vm’
[2010-05-05 03:05:19] VERBOSE[29334] logger.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Zap/3-1’
[2010-05-05 03:05:19] DEBUG[29334] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/3-1
[2010-05-05 03:05:19] DEBUG[29334] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
[2010-05-05 03:05:19] DEBUG[29334] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/3-1
[2010-05-05 03:05:19] VERBOSE[29334] logger.c: – Hungup ‘Zap/3-1’

ANy ideeas ?

regards

Craig

mickecarlsson · May 5, 2010, 4:54am

Executing [s@macro-dial:7] Dial(“Zap/3-1”, “Local/FMPR-568@from-internal&Local/FMGL-0410720545@from-internal|25|trM(auto-blkvm)”) in new stack

You are trying to call FMPR-568 and FMGL-0410720545, that cant be dialed and you receive:

logger.c: – Executing [s@macro-dial:8] Set(“Zap/3-1”, “DIALSTATUS=CHANUNAVAIL”) in new stack

Where are FMPR and FMGL coming from?

curto · May 6, 2010, 1:35am

I had this working last week just fine on my test extension (568) and went to roll it out for a couple of people this week and it stopped working.

The only change (no module updates etc) was some dialplan and ZAP channels last week to solve a dialout problem that i worked through with Phillipe and the support team.

I have tried to remove the Follow me from my test extension, restart asterisk and re-add it but we still get the same stuff happening.

Any ideas ?

regards

Craig

curto · May 6, 2010, 2:32am

Mike,

I had a look through the files on disk for some reason Extensions.conf has the following

[findmefollow-ringallv2]
exten => _FMPR-.,1,Noop(In FMPR ${FMGRP} with ${EXTEN:5})
exten => _FMPR-.,n,Set(RingGroupMethod=)
exten => _FMPR-.,n,Set(USE_CONFIRMATION=)
exten => _FMPR-.,n,Set(RINGGROUP_INDEX=)
exten => _FMPR-.,n,Macro(simple-dial,${EXTEN:5},${FMREALPRERING})
exten => _FMPR-.,n,GotoIf($["${DIALSTATUS}" != “BUSY”]?nodnd)
exten => _FMPR-.,n,Set(DB(FM/DND/${FMGRP}/${FMUNIQUE})=DND)
exten => _FMPR-.,n(nodnd),Noop(Ending FMPR ${FMGRP} with ${EXTEN:5} and dialstatus ${DIALSTATUS})
exten => _FMPR-.,n,Hangup()

exten => _FMGL-.,1,Noop(In FMGL ${FMGRP} with ${EXTEN:5})
exten => _FMGL-.,n,GotoIf($["${DB(FM/DND/${FMGRP}/${FMUNIQUE})}" = “DND”]?dodnd)
exten => _FMGL-.,n,Wait(1)
exten => _FMGL-.,n,GotoIf($["${DB(FM/DND/${FMGRP}/${FMUNIQUE})}" = “DND”]?dodnd)
exten => _FMGL-.,n,Wait(1)
exten => _FMGL-.,n,GotoIf($["${DB(FM/DND/${FMGRP}/${FMUNIQUE})}" = “DND”]?dodnd)
exten => _FMGL-.,n,Wait(${FMPRERING})
exten => _FMGL-.,n,GotoIf($["${DB(FM/DND/${FMGRP}/${FMUNIQUE})}" = “DND”]?dodnd)
exten => _FMGL-.,n,DBDel(FM/DND/${FMGRP}/${FMUNIQUE})
exten => _FMGL-.,n(dodial),Macro(dial,${FMGRPTIME},${DIAL_OPTIONS},${EXTEN:5})
exten => _FMGL-.,n,Noop(Ending FMGL ${FMGRP} with ${EXTEN:5} and dialstatus ${DIALSTATUS})
exten => _FMGL-.,n,Hangup()
exten => _FMGL-.,n+10(dodnd),DBDel(FM/DND/${FMGRP}/${FMUNIQUE})
exten => _FMGL-.,n,GotoIf($["${FMPRIME}" = “FALSE”]?dodial)
exten => _FMGL-.,n,Noop(Got DND in FMGL ${FMGRP} with ${EXTEN:5} in ${RingGroupMethod} mode, aborting)
exten => _FMGL-.,n,Hangup()

Presumably this is coming out the database each time an apply configuration is done ?

No idea how it got in there - but i would assume it has a purpose ?

Craig