[2012-12-17 16:01:29] VERBOSE[15403] asterisk.c: -- Remote UNIX connection [2012-12-17 16:01:44] DEBUG[15413] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 3 [2012-12-17 16:01:44] DEBUG[15413] sig_analog.c: channel (3) - signaling (2) - event (ANALOG_EVENT_RINGOFFHOOK) [2012-12-17 16:01:44] DEBUG[15424] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: DAHDI/3-1 ChannelState: 1 ChannelStateDesc: Rsrvd CallerIDNum: 995 CallerIDName: device AccountCode: Exten: Context: from-internal Uniqueid: 1355749304.4 [2012-12-17 16:01:44] DEBUG[15413] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2012-12-17 16:01:44] DEBUG[15413] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2012-12-17 16:01:44] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:01:44] DEBUG[15406] devicestate.c: Changing state for DAHDI/3 - state 2 (In use) [2012-12-17 16:01:44] DEBUG[31575] sig_analog.c: __analog_ss_thread 3 [2012-12-17 16:01:44] DEBUG[15406] devicestate.c: device 'DAHDI/3' state '2' [2012-12-17 16:01:44] VERBOSE[31575] sig_analog.c: -- Starting simple switch on 'DAHDI/3-1' [2012-12-17 16:01:44] DEBUG[15424] manager.c: Examining event: Event: DAHDIChannel Privilege: call,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 DAHDISpan: 1 DAHDIChannel: 3 [2012-12-17 16:01:44] DEBUG[15419] app_queue.c: Device 'DAHDI/3' changed to state '2' (In use) [2012-12-17 16:01:44] DEBUG[15424] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 995 Context: ext-local Hint: DAHDI/3 Status: 1 [2012-12-17 16:01:44] DEBUG[15407] app_queue.c: Extension '995@ext-local' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2012-12-17 16:01:45] DEBUG[31575] sig_analog.c: Begin DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[31575] chan_dahdi.c: Begin DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[15424] manager.c: Examining event: Event: DTMF Privilege: dtmf,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 Digit: 9 Direction: Received Begin: Yes End: No [2012-12-17 16:01:45] DEBUG[31575] sig_analog.c: End DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[31575] chan_dahdi.c: End DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[15424] manager.c: Examining event: Event: DTMF Privilege: dtmf,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 Digit: 9 Direction: Received Begin: No End: Yes [2012-12-17 16:01:45] DEBUG[31575] sig_analog.c: waitfordigit returned '9' (57), timeout = 0 [2012-12-17 16:01:45] DEBUG[31575] features.c: Checking if 9@from-internal is a parking exten [2012-12-17 16:01:45] DEBUG[31575] sig_analog.c: Begin DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[31575] chan_dahdi.c: Begin DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[15424] manager.c: Examining event: Event: DTMF Privilege: dtmf,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 Digit: 9 Direction: Received Begin: Yes End: No [2012-12-17 16:01:45] DEBUG[31575] sig_analog.c: End DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[31575] chan_dahdi.c: End DTMF digit: 0x39 '9' on DAHDI/3-1 [2012-12-17 16:01:45] DEBUG[31575] sig_analog.c: waitfordigit returned '9' (57), timeout = 0 [2012-12-17 16:01:45] DEBUG[15424] manager.c: Examining event: Event: DTMF Privilege: dtmf,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 Digit: 9 Direction: Received Begin: No End: Yes [2012-12-17 16:01:45] DEBUG[31575] features.c: Checking if 99@from-internal is a parking exten [2012-12-17 16:01:46] DEBUG[31575] sig_analog.c: Begin DTMF digit: 0x36 '6' on DAHDI/3-1 [2012-12-17 16:01:46] DEBUG[31575] chan_dahdi.c: Begin DTMF digit: 0x36 '6' on DAHDI/3-1 [2012-12-17 16:01:46] DEBUG[15424] manager.c: Examining event: Event: DTMF Privilege: dtmf,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 Digit: 6 Direction: Received Begin: Yes End: No [2012-12-17 16:01:46] DEBUG[31575] sig_analog.c: End DTMF digit: 0x36 '6' on DAHDI/3-1 [2012-12-17 16:01:46] DEBUG[31575] chan_dahdi.c: End DTMF digit: 0x36 '6' on DAHDI/3-1 [2012-12-17 16:01:46] DEBUG[15424] manager.c: Examining event: Event: DTMF Privilege: dtmf,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 Digit: 6 Direction: Received Begin: No End: Yes [2012-12-17 16:01:46] DEBUG[31575] sig_analog.c: waitfordigit returned '6' (54), timeout = 0 [2012-12-17 16:01:46] DEBUG[31575] features.c: Checking if 996@from-internal is a parking exten [2012-12-17 16:01:49] DEBUG[31575] features.c: Checking if 996@from-internal is a parking exten [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: DAHDI/3-1 CallerIDNum: 995 CallerIDName: device Uniqueid: 1355749304.4 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: NewCallerid Privilege: call,all Channel: DAHDI/3-1 CallerIDNum: 995 CallerIDName: device Uniqueid: 1355749304.4 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [2012-12-17 16:01:49] DEBUG[31575] chan_dahdi.c: No echo cancellation requested [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: DAHDI/3-1 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 995 CallerIDName: device ConnectedLineNum: ConnectedLineName: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '0' [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [996@from-internal:1] ExecIf("DAHDI/3-1", "0?Set(__RINGTIMER=0)") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: from-internal Extension: 996 Priority: 1 Application: ExecIf AppData: 0?Set(__RINGTIMER=0) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Macro' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [996@from-internal:2] Macro("DAHDI/3-1", "exten-vm,novm,996,0,0,0") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: from-internal Extension: 996 Priority: 2 Application: Macro AppData: exten-vm,novm,996,0,0,0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: from-internal Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: novm Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: Changing state for DAHDI/3 - state 2 (In use) [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: device 'DAHDI/3' state '2' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG2 Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG3 Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15419] app_queue.c: Device 'DAHDI/3' changed to state '2' (In use) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Macro' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-exten-vm:1] Macro("DAHDI/3-1", "user-callerid,") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:1] Set("DAHDI/3-1", "AMPUSER=995") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'CHANNEL' is 'DAHDI/3-1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSERCIDNAME' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("DAHDI/3-1", "0?report") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'REALCALLERIDNUM' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("DAHDI/3-1", "1?Set(REALCALLERIDNUM=995)") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'REALCALLERIDNUM:1:2' (from 'REALCALLERIDNUM:1:2}" = ""' len 19) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'REALCALLERIDNUM' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'CALLERID(number)' (from 'CALLERID(number)})' len 16) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'REALCALLERIDNUM' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:4] Set("DAHDI/3-1", "AMPUSER=995") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:5] Set("DAHDI/3-1", "AMPUSERCIDNAME=995") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSERCIDNAME' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("DAHDI/3-1", "0?report") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DB_RESULT' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:7] Set("DAHDI/3-1", "AMPUSERCID=995") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSERCIDNAME' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSERCID' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:8] Set("DAHDI/3-1", "CALLERID(all)="995" <995>") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '3' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:9] GotoIf("DAHDI/3-1", "0?limit") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '3' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG4 Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:10] ExecIf("DAHDI/3-1", "0?Set(GROUP(concurrency_limit)=995)") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG5 Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-exten-vm Extension: s Priority: 1 Application: Macro AppData: user-callerid, Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: s Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: macro-exten-vm Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 1 Application: Set AppData: AMPUSER=995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: AMPUSER Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 2 Application: GotoIf AppData: 0?report Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 3 Application: ExecIf AppData: 1?Set(REALCALLERIDNUM=995) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: REALCALLERIDNUM Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 4 Application: Set AppData: AMPUSER=995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: AMPUSER Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 5 Application: Set AppData: AMPUSERCIDNAME=995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: AMPUSERCIDNAME Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 6 Application: GotoIf AppData: 0?report Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 7 Application: Set AppData: AMPUSERCID=995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: AMPUSERCID Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 8 Application: Set AppData: CALLERID(all)="995" <995> Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 9 Application: GotoIf AppData: 0?limit Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 10 Application: ExecIf AppData: 0?Set(GROUP(concurrency_limit)=995) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'ARG1' (from 'ARG1}"="LIMIT" & ${LEN(${AMPUSER})}' len 4) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'LEN(${AMPUSER})' (from 'LEN(${AMPUSER})}' len 15) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'AMPUSER' (from 'AMPUSER})' len 7) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '3' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'AMPUSER' (from 'AMPUSER})' len 7) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:11] ExecIf("DAHDI/3-1", "0?Set(CHANNEL(language)=)") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 11 Application: ExecIf AppData: 0?Set(CHANNEL(language)=) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DB(AMPUSER/${AMPUSER}/language)' (from 'DB(AMPUSER/${AMPUSER}/language)}" != ""' len 31) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'AMPUSER' (from 'AMPUSER}/language)' len 7) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DB(AMPUSER/${AMPUSER}/language)' (from 'DB(AMPUSER/${AMPUSER}/language)})' len 31) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'AMPUSER' (from 'AMPUSER}/language)' len 7) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:12] GotoIf("DAHDI/3-1", "0?continue") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'TTL' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'TTL' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '-1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '64' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:13] Set("DAHDI/3-1", "__TTL=64") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'TTL' is '64' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:14] GotoIf("DAHDI/3-1", "1?continue") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-user-callerid,s,25) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:25] Set("DAHDI/3-1", "CALLERID(number)=995") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:26] Set("DAHDI/3-1", "CALLERID(name)=995") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'CHANNEL(language)' (from 'CHANNEL(language)}' len 17) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'en' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'en' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-user-callerid:27] Set("DAHDI/3-1", "CHANNEL(language)=en") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Macro [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-exten-vm:2] Set("DAHDI/3-1", "RingGroupMethod=none") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG2' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-exten-vm:3] Set("DAHDI/3-1", "__EXTTOCALL=996") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG2' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-exten-vm:4] Set("DAHDI/3-1", "__PICKUPMARK=996") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is 'novm' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTTOCALL' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CFU' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CFU/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTTOCALL' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CFB' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CFB/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG3' is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG4' is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG5' is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'RINGTIMER' is '15' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-exten-vm:5] Set("DAHDI/3-1", "RT=") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTTOCALL' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Macro' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-exten-vm:6] Macro("DAHDI/3-1", "record-enable,996,IN") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'BLINDTRANSFER' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-record-enable:1] GotoIf("DAHDI/3-1", "1?check") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-record-enable,s,4) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-record-enable:4] ExecIf("DAHDI/3-1", "0?MacroExit()") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'ARG1' (from 'ARG1}"=""' len 4) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG2' is 'IN' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-record-enable:5] GotoIf("DAHDI/3-1", "0?Group:OUT") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-record-enable,s,14) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG2' is 'IN' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-record-enable:14] GotoIf("DAHDI/3-1", "1?IN") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-record-enable,s,18) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DB(AMPUSER/996/recording)' (from 'DB(AMPUSER/996/recording)}' len 25) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'out=Never|in=Never' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'in=Never' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-record-enable:18] ExecIf("DAHDI/3-1", "1?MacroExit()") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Macro [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'RT' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DIAL_OPTIONS' is 'tr' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTTOCALL' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Macro' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-exten-vm:7] Macro("DAHDI/3-1", "dial-one,,tr,996") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG3' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:1] Set("DAHDI/3-1", "DEXTEN=996") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:2] Set("DAHDI/3-1", "DIALSTATUS_CW=") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'FROM_DID' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'SCREEN' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996/screen' in family 'AMPUSER' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: AMPUSER/996/screen not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GosubIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:3] GosubIf("DAHDI/3-1", "0?screen,1") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GosubIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'FROM_DID' (from 'FROM_DID}"!="" & "${SCREEN}"="" & "${DB(AMPUSER/${DEXTEN}/screen)}"!=""' len 8) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'FROM_DID' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'SCREEN' (from 'SCREEN}"="" & "${DB(AMPUSER/${DEXTEN}/screen)}"!=""' len 6) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'SCREEN' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DB(AMPUSER/${DEXTEN}/screen)' (from 'DB(AMPUSER/${DEXTEN}/screen)}"!=""' len 28) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEXTEN' (from 'DEXTEN}/screen)' len 6) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996/screen' in family 'AMPUSER' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: AMPUSER/996/screen not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CF' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CF/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GosubIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:4] GosubIf("DAHDI/3-1", "0?cf,1") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GosubIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DB(CF/${DEXTEN})' (from 'DB(CF/${DEXTEN})}"!=""' len 16) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEXTEN' (from 'DEXTEN})' len 6) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CF' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CF/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'DND' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: DND/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:5] GotoIf("DAHDI/3-1", "1?skip1") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-dial-one,s,8) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:8] GotoIf("DAHDI/3-1", "0?nodial") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:9] GotoIf("DAHDI/3-1", "0?continue") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'CWIGNORE' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CW' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CW/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:10] Set("DAHDI/3-1", "EXTHASCW=") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTHASCW' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CFB' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CFB/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CFU' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CFU/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:11] GotoIf("DAHDI/3-1", "1?next1:cwinusebusy") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-dial-one,s,12) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CFU' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CFU/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'NOT_INUSE' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'NOT_INUSE' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:12] GotoIf("DAHDI/3-1", "0?docfu:skip3") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-dial-one,s,16) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTHASCW' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] db.c: Unable to find key '996' in family 'CFB' [2012-12-17 16:01:49] DEBUG[31575] func_db.c: DB: CFB/996 not found in database. [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:16] GotoIf("DAHDI/3-1", "1?next2:continue") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-dial-one,s,17) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'NOT_INUSE' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'NOT_INUSE' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'NOT_INUSE' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:17] GotoIf("DAHDI/3-1", "1?continue") in new stack [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Goto (macro-dial-one,s,25) [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:25] GotoIf("DAHDI/3-1", "0?nodial") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GosubIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:26] GosubIf("DAHDI/3-1", "1?dstring,1:dlocal,1") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_stack.c: Channel DAHDI/3-1 has no datastore, so we're allocating one. [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GosubIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEXTEN:-1' (from 'DEXTEN:-1}"!="#"' len 9) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Incrementing gosub_level [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:1] Set("DAHDI/3-1", "DSTRING=") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:2] Set("DAHDI/3-1", "DEVICES=996") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:3] ExecIf("DAHDI/3-1", "0?Return()") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEVICES' (from 'DEVICES}"=""' len 7) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:4] ExecIf("DAHDI/3-1", "0?Set(DEVICES=96)") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEVICES:0:1' (from 'DEVICES:0:1}"="&"' len 11) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEVICES:1' (from 'DEVICES:1})' len 9) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEVICES' (from 'DEVICES}' len 7) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:5] Set("DAHDI/3-1", "LOOPCNT=1") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 12 Application: GotoIf AppData: 0?continue Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 13 Application: Set AppData: __TTL=64 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: __TTL Value: 64 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 14 Application: GotoIf AppData: 1?continue Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 25 Application: Set AppData: CALLERID(number)=995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 26 Application: Set AppData: CALLERID(name)=995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-user-callerid Extension: s Priority: 27 Application: Set AppData: CHANNEL(language)=en Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: novm Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: from-internal Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-exten-vm Extension: s Priority: 2 Application: Set AppData: RingGroupMethod=none Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: RingGroupMethod Value: none Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-exten-vm Extension: s Priority: 3 Application: Set AppData: __EXTTOCALL=996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: __EXTTOCALL Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-exten-vm Extension: s Priority: 4 Application: Set AppData: __PICKUPMARK=996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: __PICKUPMARK Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-exten-vm Extension: s Priority: 5 Application: Set AppData: RT= Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: RT Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-exten-vm Extension: s Priority: 6 Application: Macro AppData: record-enable,996,IN Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: s Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: macro-exten-vm Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 6 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG2 Value: IN Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-record-enable Extension: s Priority: 1 Application: GotoIf AppData: 1?check Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-record-enable Extension: s Priority: 4 Application: ExecIf AppData: 0?MacroExit() Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-record-enable Extension: s Priority: 5 Application: GotoIf AppData: 0?Group:OUT Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-record-enable Extension: s Priority: 14 Application: GotoIf AppData: 1?IN Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: out=Never|in=Never Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-record-enable Extension: s Priority: 18 Application: ExecIf AppData: 1?MacroExit() Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: novm Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG2 Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: from-internal Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-exten-vm Extension: s Priority: 7 Application: Macro AppData: dial-one,,tr,996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: s Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: macro-exten-vm Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 7 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG2 Value: tr Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG3 Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 1 Application: Set AppData: DEXTEN=996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DEXTEN Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 2 Application: Set AppData: DIALSTATUS_CW= Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALSTATUS_CW Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 3 Application: GosubIf AppData: 0?screen,1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 4 Application: GosubIf AppData: 0?cf,1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 5 Application: GotoIf AppData: 1?skip1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 8 Application: GotoIf AppData: 0?nodial Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 9 Application: GotoIf AppData: 0?continue Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 10 Application: Set AppData: EXTHASCW= Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: EXTHASCW Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 11 Application: GotoIf AppData: 1?next1:cwinusebusy Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 12 Application: GotoIf AppData: 0?docfu:skip3 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 16 Application: GotoIf AppData: 1?next2:continue Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 17 Application: GotoIf AppData: 1?continue Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 25 Application: GotoIf AppData: 0?nodial Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 26 Application: GosubIf AppData: 1?dstring,1:dlocal,1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: LOCAL(ARGC) Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 1 Application: Set AppData: DSTRING= Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DSTRING Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 2 Application: Set AppData: DEVICES=996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DEVICES Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 3 Application: ExecIf AppData: 0?Return() Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 4 Application: ExecIf AppData: 0?Set(DEVICES=96) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 5 Application: Set AppData: LOOPCNT=1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: LOOPCNT Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:6] Set("DAHDI/3-1", "ITER=1") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 6 Application: Set AppData: ITER=1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ITER Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ITER' is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'DEVICES' (from 'DEVICES}' len 7) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEVICES' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:7] Set("DAHDI/3-1", "THISDIAL=DAHDI/4") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 7 Application: Set AppData: THISDIAL=DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: THISDIAL Value: DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ASTCHANDAHDI' is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GosubIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:8] GosubIf("DAHDI/3-1", "1?zap2dahdi,1") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 8 Application: GosubIf AppData: 1?zap2dahdi,1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: LOCAL(ARGC) Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GosubIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'ASTCHANDAHDI' (from 'ASTCHANDAHDI}" != ""' len 12) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ASTCHANDAHDI' is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Incrementing gosub_level [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISDIAL' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("DAHDI/3-1", "0?Return()") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 1 Application: ExecIf AppData: 0?Return() Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'THISDIAL' (from 'THISDIAL}" = ""' len 8) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISDIAL' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:2] Set("DAHDI/3-1", "NEWDIAL=") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 2 Application: Set AppData: NEWDIAL= Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: NEWDIAL Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'THISDIAL' (from 'THISDIAL}' len 8) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISDIAL' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:3] Set("DAHDI/3-1", "LOOPCNT2=1") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 3 Application: Set AppData: LOOPCNT2=1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: LOOPCNT2 Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:4] Set("DAHDI/3-1", "ITER2=1") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 4 Application: Set AppData: ITER2=1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ITER2 Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ITER2' is '1' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'THISDIAL' (from 'THISDIAL}' len 8) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISDIAL' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:5] Set("DAHDI/3-1", "THISPART2=DAHDI/4") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 5 Application: Set AppData: THISPART2=DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: THISPART2 Value: DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISPART2' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISPART2' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("DAHDI/3-1", "0?Set(THISPART2=DAHDIDI/4)") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'THISPART2:0:3' (from 'THISPART2:0:3}" = "ZAP"' len 13) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISPART2' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'THISPART2:3' (from 'THISPART2:3})' len 11) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISPART2' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'NEWDIAL' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISPART2' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:7] Set("DAHDI/3-1", "NEWDIAL=DAHDI/4&") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ITER2' is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '2' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:8] Set("DAHDI/3-1", "ITER2=2") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ITER2' is '2' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'LOOPCNT2' is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("DAHDI/3-1", "0?begin2") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'NEWDIAL' is 'DAHDI/4&' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '8' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '7' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'NEWDIAL' is 'DAHDI/4&' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("DAHDI/3-1", "THISDIAL=DAHDI/4") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Return' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("DAHDI/3-1", "") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Return [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Decrementing gosub_level [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DSTRING' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'THISDIAL' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:9] Set("DAHDI/3-1", "DSTRING=DAHDI/4&") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ITER' is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '2' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:10] Set("DAHDI/3-1", "ITER=2") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ITER' is '2' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'LOOPCNT' is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:11] GotoIf("DAHDI/3-1", "0?begin") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DSTRING' is 'DAHDI/4&' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '8' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '7' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DSTRING' is 'DAHDI/4&' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:12] Set("DAHDI/3-1", "DSTRING=DAHDI/4") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Return' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [dstring@macro-dial-one:13] Return("DAHDI/3-1", "") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Return [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Decrementing gosub_level [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DSTRING' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '7' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:27] GotoIf("DAHDI/3-1", "0?nodial") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:28] GotoIf("DAHDI/3-1", "0?skiptrace") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] func_strings.c: FUNCTION REGEX (^[+]?[0-9]+$)(995) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GosubIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:29] GosubIf("DAHDI/3-1", "1?ctset,1:ctclear,1") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GosubIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'REGEX("^[\+]?[0-9]+$" ${CALLERID(number)})' (from 'REGEX("^[\+]?[0-9]+$" ${CALLERID(number)})} = 1' len 42) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'CALLERID(number)' (from 'CALLERID(number)})' len 16) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] func_strings.c: FUNCTION REGEX (^[+]?[0-9]+$)(995) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '1' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Incrementing gosub_level [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DEXTEN' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [ctset@macro-dial-one:1] Set("DAHDI/3-1", "DB(CALLTRACE/996)=995") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Return' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [ctset@macro-dial-one:2] Return("DAHDI/3-1", "") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Return [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Decrementing gosub_level [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'NODEST' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG2' is 'tr' [2012-12-17 16:01:49] DEBUG[31575] func_strings.c: FUNCTION REGEX ((M[(]auto-blkvm[)]))(tr) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG2' is 'tr' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG2' is 'tr' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is 'tr' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:30] Set("DAHDI/3-1", "D_OPTIONS=tr") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ALERT_INFO' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ALERT_INFO' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:31] ExecIf("DAHDI/3-1", "0?SIPAddHeader(Alert-Info: )") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'ALERT_INFO' (from 'ALERT_INFO}"!=""' len 10) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ALERT_INFO' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'ALERT_INFO' (from 'ALERT_INFO})' len 10) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ALERT_INFO' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'SIPADDHEADER' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'SIPADDHEADER' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:32] ExecIf("DAHDI/3-1", "0?SIPAddHeader()") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'SIPADDHEADER' (from 'SIPADDHEADER}"!=""' len 12) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'SIPADDHEADER' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'SIPADDHEADER' (from 'SIPADDHEADER})' len 12) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'SIPADDHEADER' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'MOHCLASS' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'MOHCLASS' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'ExecIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:33] ExecIf("DAHDI/3-1", "0?Set(CHANNEL(musicclass)=)") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: ExecIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'MOHCLASS' (from 'MOHCLASS}"!=""' len 8) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'MOHCLASS' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'MOHCLASS' (from 'MOHCLASS})' len 8) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'MOHCLASS' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'QUEUEWAIT' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GosubIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:34] GosubIf("DAHDI/3-1", "0?qwait,1") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GosubIf [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Evaluating 'QUEUEWAIT' (from 'QUEUEWAIT}"!=""' len 9) [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'QUEUEWAIT' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'CWIGNORE' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:35] Set("DAHDI/3-1", "__CWIGNORE=") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:36] Set("DAHDI/3-1", "__KEEPCID=TRUE") in new stack [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'USEGOTO' is NULL [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:37] GotoIf("DAHDI/3-1", "0?usegoto,1") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 6 Application: ExecIf AppData: 0?Set(THISPART2=DAHDIDI/4) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 7 Application: Set AppData: NEWDIAL=DAHDI/4& Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: NEWDIAL Value: DAHDI/4& Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 8 Application: Set AppData: ITER2=2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ITER2 Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 9 Application: GotoIf AppData: 0?begin2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 10 Application: Set AppData: THISDIAL=DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: THISDIAL Value: DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: zap2dahdi Priority: 11 Application: Return AppData: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: GOSUB_RETVAL Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 9 Application: Set AppData: DSTRING=DAHDI/4& Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DSTRING Value: DAHDI/4& Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 10 Application: Set AppData: ITER=2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ITER Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 11 Application: GotoIf AppData: 0?begin Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 12 Application: Set AppData: DSTRING=DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DSTRING Value: DAHDI/4 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: dstring Priority: 13 Application: Return AppData: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: GOSUB_RETVAL Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 27 Application: GotoIf AppData: 0?nodial Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 28 Application: GotoIf AppData: 0?skiptrace Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 29 Application: GosubIf AppData: 1?ctset,1:ctclear,1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: LOCAL(ARGC) Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: ctset Priority: 1 Application: Set AppData: DB(CALLTRACE/996)=995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: ctset Priority: 2 Application: Return AppData: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: GOSUB_RETVAL Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 30 Application: Set AppData: D_OPTIONS=tr Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: D_OPTIONS Value: tr Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 31 Application: ExecIf AppData: 0?SIPAddHeader(Alert-Info: ) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 32 Application: ExecIf AppData: 0?SIPAddHeader() Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 33 Application: ExecIf AppData: 0?Set(CHANNEL(musicclass)=) Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 34 Application: GosubIf AppData: 0?qwait,1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 35 Application: Set AppData: __CWIGNORE= Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: __CWIGNORE Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 36 Application: Set AppData: __KEEPCID=TRUE Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: __KEEPCID Value: TRUE Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 37 Application: GotoIf AppData: 0?usegoto,1 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTTOCALL' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'AMPUSER' is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '995' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Expression result is '0' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:38] GotoIf("DAHDI/3-1", "0?godial") in new stack [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Not taking any branch [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 995 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 38 Application: GotoIf AppData: 0?godial Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTTOCALL' is '996' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DB_RESULT Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Function result is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:39] Set("DAHDI/3-1", "CONNECTEDLINE(name,i)=996") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 39 Application: Set AppData: CONNECTEDLINE(name,i)=996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'EXTTOCALL' is '996' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:40] Set("DAHDI/3-1", "CONNECTEDLINE(num)=996") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 40 Application: Set AppData: CONNECTEDLINE(num)=996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] chan_dahdi.c: Requested indication 22 on channel DAHDI/3-1 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'D_OPTIONS' is 'tr' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Set' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:41] Set("DAHDI/3-1", "D_OPTIONS=trI") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 41 Application: Set AppData: D_OPTIONS=trI Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: D_OPTIONS Value: trI Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] app_macro.c: Executed application: Set [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'DSTRING' is 'DAHDI/4' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'ARG1' is '' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Result of 'D_OPTIONS' is 'trI' [2012-12-17 16:01:49] DEBUG[31575] pbx.c: Launching 'Dial' [2012-12-17 16:01:49] VERBOSE[31575] pbx.c: -- Executing [s@macro-dial-one:42] Dial("DAHDI/3-1", "DAHDI/4,,trI") in new stack [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: s Priority: 42 Application: Dial AppData: DAHDI/4,,trI Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALSTATUS Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALEDPEERNUMBER Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALEDPEERNAME Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ANSWEREDTIME Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] sig_analog.c: analog_available 4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALEDTIME Value: Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[31575] chan_dahdi.c: Using channel 4 [2012-12-17 16:01:49] DEBUG[31575] sig_analog.c: analog_request 4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: DAHDI/4-1 ChannelState: 1 ChannelStateDesc: Rsrvd CallerIDNum: 996 CallerIDName: device AccountCode: Exten: Context: from-internal Uniqueid: 1355749309.5 [2012-12-17 16:01:49] DEBUG[31575] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2012-12-17 16:01:49] DEBUG[31575] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: DAHDIChannel Privilege: call,all Channel: DAHDI/4-1 Uniqueid: 1355749309.5 DAHDISpan: 1 DAHDIChannel: 4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/4-1 Variable: DIALEDPEERNUMBER Value: 4 Uniqueid: 1355749309.5 [2012-12-17 16:01:49] DEBUG[31575] rtp_engine.c: Can't find native functions for channel 'DAHDI/4-1' [2012-12-17 16:01:49] DEBUG[31575] rtp_engine.c: Seeded SDP of 'DAHDI/4-1' with that of 'DAHDI/3-1' [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DIALEDTIME. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ANSWEREDTIME. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DIALEDPEERNAME. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DIALEDPEERNUMBER. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DIALSTATUS. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable MACRO_DEPTH. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable D_OPTIONS. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DB_RESULT. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Copying hard-transferable variable KEEPCID. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Copying hard-transferable variable CWIGNORE. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable GOSUB_RETVAL. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DSTRING. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ITER. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable THISDIAL. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ITER2. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable NEWDIAL. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable THISPART2. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable LOOPCNT2. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable LOOPCNT. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DEVICES. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable EXTHASCW. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DIALSTATUS_CW. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable DEXTEN. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ARG3. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ARG2. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ARG1. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable MACRO_PRIORITY. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable MACRO_CONTEXT. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable MACRO_EXTEN. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable RT. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Copying hard-transferable variable PICKUPMARK. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Copying hard-transferable variable EXTTOCALL. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable RingGroupMethod. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Copying hard-transferable variable TTL. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable AMPUSERCID. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable AMPUSERCIDNAME. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable AMPUSER. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable REALCALLERIDNUM. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ARG5. [2012-12-17 16:01:49] DEBUG[31575] channel.c: Not copying variable ARG4. [2012-12-17 16:01:49] DEBUG[31575] sig_analog.c: CALLING CID_NAME: 995 CID_NUM:: 995 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: DAHDI/4-1 ChannelState: 5 ChannelStateDesc: Ringing CallerIDNum: 996 CallerIDName: device ConnectedLineNum: 995 ConnectedLineName: 995 Uniqueid: 1355749309.5 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Dial Privilege: call,all SubEvent: Begin Channel: DAHDI/3-1 Destination: DAHDI/4-1 CallerIDNum: 995 CallerIDName: 995 ConnectedLineNum: 996 ConnectedLineName: 996 UniqueID: 1355749304.4 DestUniqueID: 1355749309.5 Dialstring: 4 [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: Changing state for DAHDI/4 - state 6 (Ringing) [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: device 'DAHDI/4' state '6' [2012-12-17 16:01:49] VERBOSE[31575] app_dial.c: -- Called DAHDI/4 [2012-12-17 16:01:49] DEBUG[31575] chan_dahdi.c: Requested indication 3 on channel DAHDI/3-1 [2012-12-17 16:01:49] VERBOSE[31575] app_dial.c: -- DAHDI/4-1 is ringing [2012-12-17 16:01:49] DEBUG[31575] chan_dahdi.c: Requested indication 3 on channel DAHDI/3-1 [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:49] DEBUG[15419] app_queue.c: Device 'DAHDI/4' changed to state '6' (Ringing) [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: Changing state for DAHDI/4 - state 6 (Ringing) [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: device 'DAHDI/4' state '6' [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: Changing state for DAHDI/3 - state 6 (Ringing) [2012-12-17 16:01:49] DEBUG[15406] devicestate.c: device 'DAHDI/3' state '6' [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: DAHDI/3-1 ChannelState: 5 ChannelStateDesc: Ringing CallerIDNum: 995 CallerIDName: 995 ConnectedLineNum: 996 ConnectedLineName: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 996 Context: ext-local Hint: DAHDI/4 Status: 8 [2012-12-17 16:01:49] DEBUG[15407] app_queue.c: Extension '996@ext-local' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [2012-12-17 16:01:49] DEBUG[15419] app_queue.c: Device 'DAHDI/4' changed to state '6' (Ringing) [2012-12-17 16:01:49] DEBUG[15419] app_queue.c: Device 'DAHDI/3' changed to state '6' (Ringing) [2012-12-17 16:01:49] DEBUG[15407] app_queue.c: Extension '995@ext-local' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [2012-12-17 16:01:49] DEBUG[15424] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 995 Context: ext-local Hint: DAHDI/3 Status: 8 [2012-12-17 16:01:50] DEBUG[31575] sig_analog.c: analog_exception 4 [2012-12-17 16:01:50] DEBUG[31575] sig_analog.c: Exception on 11, channel 4 [2012-12-17 16:01:50] DEBUG[31575] sig_analog.c: __analog_handle_event 4 [2012-12-17 16:01:50] DEBUG[31575] sig_analog.c: Got event ANALOG_EVENT_RINGEROFF(8) on channel 4 (index 0) [2012-12-17 16:01:50] DEBUG[31575] sig_analog.c: Sending callerid. CID_NAME: '995' CID_NUM: '995' [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: Starting cid spill [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 0 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 160 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 320 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 480 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 640 of 9134, res = -1 [2012-12-17 16:01:50] VERBOSE[31575] app_dial.c: -- DAHDI/4-1 is ringing [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 640 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 640 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 640 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 800 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 800 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 960 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 960 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1120 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1120 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1280 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1280 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1440 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1440 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1600 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1600 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1760 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1760 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1920 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 1920 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2080 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2080 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2240 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2240 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2400 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2400 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2560 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2560 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2720 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2720 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2880 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 2880 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3040 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3040 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3200 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3200 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3360 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3360 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3520 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3520 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3680 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3680 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3840 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 3840 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4000 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4000 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4160 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4160 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4320 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4320 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4480 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4480 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4640 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4640 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4800 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4800 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4960 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 4960 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5120 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5120 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5280 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5280 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5440 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5440 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5600 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5600 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5760 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5760 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5920 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 5920 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6080 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6080 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6240 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6240 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6400 of 9134, res = -1 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6400 of 9134, res = 160 [2012-12-17 16:01:50] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6560 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6560 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6720 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6720 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6880 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 6880 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7040 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7040 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7200 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7200 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7360 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7360 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7520 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7520 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7680 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7680 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7840 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 7840 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8000 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8000 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8160 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8160 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8320 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8320 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8480 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8480 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8640 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8640 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8800 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8800 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8960 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 8960 of 9134, res = 160 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 9120 of 9134, res = -1 [2012-12-17 16:01:51] DEBUG[31575] chan_dahdi.c: writing callerid at pos 9120 of 9134, res = 14 [2012-12-17 16:01:54] DEBUG[31575] sig_analog.c: analog_exception 4 [2012-12-17 16:01:54] DEBUG[31575] sig_analog.c: Exception on 11, channel 4 [2012-12-17 16:01:54] DEBUG[31575] sig_analog.c: __analog_handle_event 4 [2012-12-17 16:01:54] DEBUG[31575] sig_analog.c: Got event ANALOG_EVENT_RINGERON(7) on channel 4 (index 0) [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: analog_exception 4 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: Exception on 11, channel 4 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: __analog_handle_event 4 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: Got event ANALOG_EVENT_RINGEROFF(8) on channel 4 (index 0) [2012-12-17 16:01:55] VERBOSE[31575] app_dial.c: -- DAHDI/4-1 is ringing [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: analog_exception 4 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: Exception on 11, channel 4 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: __analog_handle_event 4 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: Got event ANALOG_EVENT_RINGOFFHOOK(2) on channel 4 (index 0) [2012-12-17 16:01:55] DEBUG[31575] chan_dahdi.c: No echo cancellation requested [2012-12-17 16:01:55] DEBUG[31575] chan_dahdi.c: No echo training requested [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: channel 4 answered [2012-12-17 16:01:55] VERBOSE[31575] app_dial.c: -- DAHDI/4-1 answered DAHDI/3-1 [2012-12-17 16:01:55] DEBUG[31575] chan_dahdi.c: Requested indication -1 on channel DAHDI/3-1 [2012-12-17 16:01:55] DEBUG[31575] chan_dahdi.c: Requested indication 3 on channel DAHDI/4-1 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: analog_answer 3 [2012-12-17 16:01:55] DEBUG[31575] sig_analog.c: Took DAHDI/3-1 off hook [2012-12-17 16:01:55] DEBUG[31575] chan_dahdi.c: Requested indication -1 on channel DAHDI/3-1 [2012-12-17 16:01:55] DEBUG[31575] features.c: bridge answer set, chan answer set [2012-12-17 16:01:55] DEBUG[31575] features.c: Removing dialed interfaces datastore on DAHDI/4-1 since we're bridging [2012-12-17 16:01:55] DEBUG[31575] chan_dahdi.c: Requested indication 20 on channel DAHDI/3-1 [2012-12-17 16:01:55] DEBUG[31575] chan_dahdi.c: Requested indication 20 on channel DAHDI/4-1 [2012-12-17 16:01:55] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:01:55] DEBUG[15406] devicestate.c: Changing state for DAHDI/4 - state 2 (In use) [2012-12-17 16:01:55] DEBUG[15406] devicestate.c: device 'DAHDI/4' state '2' [2012-12-17 16:01:55] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:01:55] DEBUG[15406] devicestate.c: Changing state for DAHDI/3 - state 2 (In use) [2012-12-17 16:01:55] DEBUG[15407] app_queue.c: Extension '996@ext-local' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2012-12-17 16:01:55] DEBUG[15419] app_queue.c: Device 'DAHDI/4' changed to state '2' (In use) [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: DAHDI/4-1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 996 CallerIDName: device ConnectedLineNum: 995 ConnectedLineName: 995 Uniqueid: 1355749309.5 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALSTATUS Value: ANSWER Uniqueid: 1355749304.4 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALEDPEERNAME Value: DAHDI/4-1 Uniqueid: 1355749304.4 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALEDPEERNUMBER Value: 4 Uniqueid: 1355749304.4 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: BRIDGEPEER Value: DAHDI/4-1 Uniqueid: 1355749304.4 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/4-1 Variable: BRIDGEPEER Value: DAHDI/3-1 Uniqueid: 1355749309.5 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: DAHDI/3-1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 995 CallerIDName: 995 ConnectedLineNum: 996 ConnectedLineName: 996 Uniqueid: 1355749304.4 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: NewAccountCode Privilege: call,all Channel: DAHDI/4-1 Uniqueid: 1355749309.5 AccountCode: OldAccountCode: [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: Bridge Privilege: call,all Bridgestate: Link Bridgetype: core Channel1: DAHDI/3-1 Channel2: DAHDI/4-1 Uniqueid1: 1355749304.4 Uniqueid2: 1355749309.5 CallerID1: 995 CallerID2: 996 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: BRIDGEPEER Value: DAHDI/4-1 Uniqueid: 1355749304.4 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/4-1 Variable: BRIDGEPEER Value: DAHDI/3-1 Uniqueid: 1355749309.5 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: BRIDGEPEER Value: DAHDI/4-1 Uniqueid: 1355749304.4 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/4-1 Variable: BRIDGEPEER Value: DAHDI/3-1 Uniqueid: 1355749309.5 [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 996 Context: ext-local Hint: DAHDI/4 Status: 1 [2012-12-17 16:01:55] DEBUG[15406] devicestate.c: device 'DAHDI/3' state '2' [2012-12-17 16:01:55] DEBUG[15407] app_queue.c: Extension '995@ext-local' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2012-12-17 16:01:55] DEBUG[15419] app_queue.c: Device 'DAHDI/3' changed to state '2' (In use) [2012-12-17 16:01:55] DEBUG[15424] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 995 Context: ext-local Hint: DAHDI/3 Status: 1 [2012-12-17 16:01:59] DEBUG[31575] sig_analog.c: analog_exception 3 [2012-12-17 16:01:59] DEBUG[31575] sig_analog.c: Exception on 10, channel 3 [2012-12-17 16:01:59] DEBUG[31575] sig_analog.c: __analog_handle_event 3 [2012-12-17 16:01:59] DEBUG[31575] sig_analog.c: Got event ANALOG_EVENT_WINKFLASH(3) on channel 3 (index 0) [2012-12-17 16:01:59] DEBUG[31575] sig_analog.c: Winkflash, index: 0, normal: 10, callwait: -1, thirdcall: -1 [2012-12-17 16:01:59] DEBUG[31575] chan_dahdi.c: Allocated Threeway subchannel on FD 21 channel 5 [2012-12-17 16:01:59] DEBUG[31575] sig_analog.c: Swapping 2 and 0 [2012-12-17 16:01:59] WARNING[31575] sig_analog.c: Unable to start dial recall tone on channel 3 [2012-12-17 16:01:59] VERBOSE[31575] sig_analog.c: -- Started three way call on channel 3 [2012-12-17 16:01:59] DEBUG[31575] sig_analog.c: Updated conferencing on 3, with 0 conference users [2012-12-17 16:01:59] DEBUG[31575] chan_dahdi.c: Requested indication 16 on channel DAHDI/4-1 [2012-12-17 16:01:59] VERBOSE[31575] res_musiconhold.c: -- Started music on hold, class 'default', on DAHDI/4-1 [2012-12-17 16:01:59] DEBUG[31575] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [2012-12-17 16:01:59] DEBUG[31576] sig_analog.c: __analog_ss_thread 3 [2012-12-17 16:01:59] VERBOSE[31576] sig_analog.c: -- Starting simple switch on 'DAHDI/3-2' [2012-12-17 16:01:59] DEBUG[15424] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: DAHDI/3-2 ChannelState: 1 ChannelStateDesc: Rsrvd CallerIDNum: 995 CallerIDName: device AccountCode: Exten: Context: from-internal Uniqueid: 1355749319.6 [2012-12-17 16:01:59] DEBUG[15424] manager.c: Examining event: Event: DAHDIChannel Privilege: call,all Channel: DAHDI/3-2 Uniqueid: 1355749319.6 DAHDISpan: 1 DAHDIChannel: 3 [2012-12-17 16:01:59] DEBUG[15424] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: DAHDI/4-1 UniqueID: 1355749309.5 Class: default [2012-12-17 16:01:59] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:01:59] DEBUG[15406] devicestate.c: Changing state for DAHDI/3 - state 2 (In use) [2012-12-17 16:01:59] DEBUG[15406] devicestate.c: device 'DAHDI/3' state '2' [2012-12-17 16:01:59] DEBUG[15419] app_queue.c: Device 'DAHDI/3' changed to state '2' (In use) [2012-12-17 16:01:59] DEBUG[31575] channel.c: Set channel DAHDI/4-1 to write format slin [2012-12-17 16:01:59] DEBUG[31575] res_musiconhold.c: DAHDI/4-1 Opened file 0 '/var/lib/asterisk/moh//macroform-cold_day' [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: analog_exception 4 [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: Exception on 11, channel 4 [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: __analog_handle_event 4 [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: Got event ANALOG_EVENT_ONHOOK(1) on channel 4 (index 0) [2012-12-17 16:02:07] VERBOSE[31575] res_musiconhold.c: -- Stopped music on hold on DAHDI/4-1 [2012-12-17 16:02:07] DEBUG[31575] channel.c: Set channel DAHDI/4-1 to write format ulaw [2012-12-17 16:02:07] DEBUG[31575] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2012-12-17 16:02:07] DEBUG[31575] channel.c: Didn't get a frame from channel: DAHDI/4-1 [2012-12-17 16:02:07] DEBUG[31575] chan_dahdi.c: Requested indication 20 on channel DAHDI/3-1 [2012-12-17 16:02:07] DEBUG[31575] channel.c: Bridge stops bridging channels DAHDI/3-1 and DAHDI/4-1 [2012-12-17 16:02:07] DEBUG[31575] channel.c: Soft-Hanging up channel 'DAHDI/3-1' [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Launching 'Macro' [2012-12-17 16:02:07] VERBOSE[31575] pbx.c: -- Executing [h@macro-dial-one:1] Macro("DAHDI/3-1", "hangupcall,") in new stack [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Result of 'USE_CONFIRMATION' is NULL [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Result of 'RINGGROUP_INDEX' is NULL [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Result of 'CHANNEL' is 'DAHDI/3-1' [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Result of 'UNIQCHAN' is NULL [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Expression result is '1' [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Launching 'GotoIf' [2012-12-17 16:02:07] VERBOSE[31575] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("DAHDI/3-1", "1?theend") in new stack [2012-12-17 16:02:07] VERBOSE[31575] pbx.c: -- Goto (macro-hangupcall,s,3) [2012-12-17 16:02:07] DEBUG[31575] app_macro.c: Executed application: GotoIf [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Launching 'Hangup' [2012-12-17 16:02:07] VERBOSE[31575] pbx.c: -- Executing [s@macro-hangupcall:3] Hangup("DAHDI/3-1", "") in new stack [2012-12-17 16:02:07] DEBUG[31575] app_macro.c: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'DAHDI/3-1' in macro 'hangupcall' [2012-12-17 16:02:07] VERBOSE[31575] app_macro.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'DAHDI/3-1' in macro 'hangupcall' [2012-12-17 16:02:07] DEBUG[31575] features.c: Spawn extension (macro-dial-one,h,1) exited non-zero on 'DAHDI/3-1' [2012-12-17 16:02:07] VERBOSE[31575] features.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'DAHDI/3-1' [2012-12-17 16:02:07] DEBUG[31575] channel.c: Hanging up channel 'DAHDI/4-1' [2012-12-17 16:02:07] DEBUG[31575] chan_dahdi.c: dahdi_hangup(DAHDI/4-1) [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: analog_hangup 4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: DAHDI/3-1 Channel2: DAHDI/4-1 Uniqueid1: 1355749304.4 Uniqueid2: 1355749309.5 CallerID1: 995 CallerID2: 996 [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: Hangup: channel: 4 index = 0, normal = 1, callwait = 0, thirdcall = 0 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ANSWEREDTIME Value: 12 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALEDTIME Value: 23 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[31575] chan_dahdi.c: Set option TONE VERIFY, mode: OFF(0) on DAHDI/4-1 [2012-12-17 16:02:07] DEBUG[31575] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/4-1 [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: Updated conferencing on 4, with 0 conference users [2012-12-17 16:02:07] VERBOSE[31575] sig_analog.c: -- Hanging up on 'DAHDI/4-1' [2012-12-17 16:02:07] VERBOSE[31575] chan_dahdi.c: -- Hungup 'DAHDI/4-1' [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-dial-one Extension: h Priority: 1 Application: Macro AppData: hangupcall, Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_IN_HANGUP Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: h Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: macro-dial-one Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 3 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 3 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-hangupcall Extension: s Priority: 1 Application: GotoIf AppData: 1?theend Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 3 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/3-1 Context: macro-hangupcall Extension: s Priority: 3 Application: Hangup AppData: Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: s Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: macro-exten-vm Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 7 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: DAHDI/4-1 Uniqueid: 1355749309.5 CallerIDNum: 996 CallerIDName: device ConnectedLineNum: 995 ConnectedLineName: 995 Cause: 16 Cause-txt: Normal Clearing [2012-12-17 16:02:07] DEBUG[31575] app_dial.c: Exiting with DIALSTATUS=ANSWER. [2012-12-17 16:02:07] DEBUG[31575] app_macro.c: Spawn extension (macro-dial-one,s,42) exited non-zero on 'DAHDI/3-1' in macro 'dial-one' [2012-12-17 16:02:07] VERBOSE[31575] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on 'DAHDI/3-1' in macro 'dial-one' [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: DIALSTATUS Value: ANSWER Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Dial Privilege: call,all SubEvent: End Channel: DAHDI/3-1 UniqueID: 1355749304.4 DialStatus: ANSWER [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG1 Value: novm Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG2 Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: ARG3 Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_EXTEN Value: 996 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_CONTEXT Value: from-internal Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_PRIORITY Value: 2 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[31575] app_macro.c: Spawn extension (macro-exten-vm,s,7) exited non-zero on 'DAHDI/3-1' in macro 'exten-vm' [2012-12-17 16:02:07] VERBOSE[31575] app_macro.c: == Spawn extension (macro-exten-vm, s, 7) exited non-zero on 'DAHDI/3-1' in macro 'exten-vm' [2012-12-17 16:02:07] DEBUG[31575] pbx.c: Spawn extension (from-internal,996,2) exited non-zero on 'DAHDI/3-1' [2012-12-17 16:02:07] VERBOSE[31575] pbx.c: == Spawn extension (from-internal, 996, 2) exited non-zero on 'DAHDI/3-1' [2012-12-17 16:02:07] DEBUG[31575] channel.c: Soft-Hanging up channel 'DAHDI/3-1' [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: Changing state for DAHDI/4 - state 0 (Unknown) [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: device 'DAHDI/4' state '0' [2012-12-17 16:02:07] DEBUG[31575] channel.c: Hanging up channel 'DAHDI/3-1' [2012-12-17 16:02:07] DEBUG[31575] chan_dahdi.c: dahdi_hangup(DAHDI/3-1) [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: analog_hangup 3 [2012-12-17 16:02:07] DEBUG[31575] sig_analog.c: Hangup: channel: 3 index = 2, normal = 1, callwait = 0, thirdcall = 1 [2012-12-17 16:02:07] DEBUG[31575] chan_dahdi.c: Released sub 2 of channel 3 [2012-12-17 16:02:07] VERBOSE[31575] sig_analog.c: -- Hanging up on 'DAHDI/3-1' [2012-12-17 16:02:07] VERBOSE[31575] chan_dahdi.c: -- Hungup 'DAHDI/3-1' [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/3-1 Variable: MACRO_DEPTH Value: 0 Uniqueid: 1355749304.4 [2012-12-17 16:02:07] DEBUG[15419] app_queue.c: Device 'DAHDI/4' changed to state '0' (Unknown) [2012-12-17 16:02:07] DEBUG[15407] devicestate.c: No provider found, checking channel drivers for DAHDI - 4 [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: DAHDI/3-1 Uniqueid: 1355749304.4 CallerIDNum: 995 CallerIDName: 995 ConnectedLineNum: 996 ConnectedLineName: 996 Cause: 16 Cause-txt: Normal Clearing [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:02:07] DEBUG[15407] app_queue.c: Extension '996@ext-local' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: Changing state for DAHDI/3 - state 2 (In use) [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: device 'DAHDI/3' state '2' [2012-12-17 16:02:07] DEBUG[15419] app_queue.c: Device 'DAHDI/3' changed to state '2' (In use) [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 996 Context: ext-local Hint: DAHDI/4 Status: 0 [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: analog_exception 3 [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: Exception on 10, channel 3 [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: __analog_handle_event 3 [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: Got event ANALOG_EVENT_ONHOOK(1) on channel 3 (index 0) [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: waitfordigit returned < 0... [2012-12-17 16:02:07] DEBUG[31576] channel.c: Hanging up channel 'DAHDI/3-2' [2012-12-17 16:02:07] DEBUG[31576] chan_dahdi.c: dahdi_hangup(DAHDI/3-2) [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: analog_hangup 3 [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: Hangup: channel: 3 index = 0, normal = 1, callwait = 0, thirdcall = 0 [2012-12-17 16:02:07] DEBUG[31576] chan_dahdi.c: Set option TONE VERIFY, mode: OFF(0) on DAHDI/3-2 [2012-12-17 16:02:07] DEBUG[31576] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/3-2 [2012-12-17 16:02:07] DEBUG[31576] sig_analog.c: Updated conferencing on 3, with 0 conference users [2012-12-17 16:02:07] VERBOSE[31576] sig_analog.c: -- Hanging up on 'DAHDI/3-2' [2012-12-17 16:02:07] VERBOSE[31576] chan_dahdi.c: -- Hungup 'DAHDI/3-2' [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: DAHDI/3-2 Uniqueid: 1355749319.6 CallerIDNum: 995 CallerIDName: device ConnectedLineNum: ConnectedLineName: Cause: 0 Cause-txt: Unknown [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: Changing state for DAHDI/3 - state 0 (Unknown) [2012-12-17 16:02:07] DEBUG[15406] devicestate.c: device 'DAHDI/3' state '0' [2012-12-17 16:02:07] DEBUG[15407] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [2012-12-17 16:02:07] DEBUG[15407] app_queue.c: Extension '995@ext-local' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2012-12-17 16:02:07] DEBUG[15419] app_queue.c: Device 'DAHDI/3' changed to state '0' (Unknown) [2012-12-17 16:02:07] DEBUG[15424] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 995 Context: ext-local Hint: DAHDI/3 Status: 0 [2012-12-17 16:02:11] VERBOSE[31574] asterisk.c: -- Remote UNIX connection disconnected [2012-12-17 16:03:01] DEBUG[31590] manager.c: Running action 'Login'