[root@asterisk1 asterisk]# tail -f /var/log/asterisk/full
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: Stopping tones on 57/0 talking to 33/0
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: Stopping tones on 33/0 talking to 57/0
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: disabled echo cancellation on channel 57
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: disabled echo cancellation on channel 33
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: Making 33 slave to master 57 at 0
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: Added 21 to conference 9/57
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: Added 37 to conference 9/33
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: Updated conferencing on 57, with 0 conference users
Dec 12 12:50:37 DEBUG[19860] chan_zap.c: Updated conferencing on 33, with 0 conference users
Dec 12 12:50:50 VERBOSE[13527] logger.c:     -- Remote UNIX connection disconnected
Dec 12 12:51:03 DEBUG[5482] dsp.c: dsp busy pattern set to 2500,500
Dec 12 12:51:03 VERBOSE[5482] logger.c:     -- Accepting overlap call from '3143926600' to '3926643' on channel 0/10, span 3
Dec 12 12:51:03 VERBOSE[19900] logger.c:     -- Starting simple switch on 'Zap/58-1'
Dec 12 12:51:06 DEBUG[19900] chan_zap.c: Enabled echo cancellation on channel 58
Dec 12 12:51:06 VERBOSE[19900] logger.c:     -- Executing Dial("Zap/58-1", "Zap/g0/3926643") in new stack
Dec 12 12:51:06 DEBUG[19900] dsp.c: dsp busy pattern set to 2500,500
Dec 12 12:51:06 VERBOSE[19900] logger.c:     -- Requested transfer capability: 0x00 - SPEECH
Dec 12 12:51:06 VERBOSE[19900] logger.c:     -- Called g0/3926643
Dec 12 12:51:06 DEBUG[5481] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/10 span 2
Dec 12 12:51:06 VERBOSE[19900] logger.c:     -- Zap/34-1 is proceeding passing it to Zap/58-1
Dec 12 12:51:06 DEBUG[19900] chan_zap.c: Requested indication 15 on channel Zap/58-1
Dec 12 12:51:06 DEBUG[19900] chan_zap.c: Received AST_CONTROL_PROCEEDING on Zap/58-1
Dec 12 12:51:06 DEBUG[5481] dsp.c: dsp busy pattern set to 2500,500
Dec 12 12:51:06 VERBOSE[5481] logger.c:     -- Accepting overlap call from '3143926600' to '6643' on channel 0/11, span 2
Dec 12 12:51:06 VERBOSE[19905] logger.c:     -- Starting simple switch on 'Zap/35-1'
Dec 12 12:51:09 DEBUG[19905] chan_zap.c: Enabled echo cancellation on channel 35
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Macro("Zap/35-1", "exten-vm|6643|6643") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Macro("Zap/35-1", "user-callerid") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '0'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing GotoIf("Zap/35-1", "0?report") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Not taking any branch
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '0'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing GotoIf("Zap/35-1", "0?start") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Not taking any branch
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is '3143926600'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "REALCALLERIDNUM=3143926600") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing NoOp("Zap/35-1", "REALCALLERIDNUM is 3143926600") in new stack
Dec 12 12:51:09 DEBUG[19905] db.c: Unable to find key '3143926600/user' in family 'DEVICE'
Dec 12 12:51:09 DEBUG[19905] func_db.c: DB: DEVICE/3143926600/user not found in database.
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is ''
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "AMPUSER=") in new stack
Dec 12 12:51:09 DEBUG[19905] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Dec 12 12:51:09 DEBUG[19905] func_db.c: DB: AMPUSER//cidname not found in database.
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is ''
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "AMPUSERCIDNAME=") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '1'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing GotoIf("Zap/35-1", "1?report") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Goto (macro-user-callerid,s,10)
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing NoOp("Zap/35-1", "TTL:  ARG1: 6643") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '0'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing GotoIf("Zap/35-1", "0?continue") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Not taking any branch
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '1'
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '-1'
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is '64'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "_TTL=64") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '1'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing GotoIf("Zap/35-1", "1?continue") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Goto (macro-user-callerid,s,20)
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is '"FRONTIER MORTGA" <3143926600>'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing NoOp("Zap/35-1", "Using CallerID "FRONTIER MORTGA" <3143926600>") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing NoOp("Zap/35-1", "CAME FROM: ") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "RRNODEST=") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "_NODEST=") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "FROMCONTEXT=exten-vm") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "VMBOX=6643") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "EXTTOCALL=6643") in new stack
Dec 12 12:51:09 DEBUG[19905] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 12:51:09 DEBUG[19905] func_db.c: DB: CFU/6643 not found in database.
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is ''
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "CFUEXT=") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '1'
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '0'
Dec 12 12:51:09 DEBUG[19905] pbx.c: Expression result is '1'
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is '15'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Set("Zap/35-1", "RT=15") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing Macro("Zap/35-1", "record-enable|6643|IN") in new stack
Dec 12 12:51:09 DEBUG[19905] pbx.c: Function result is '0'
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing GotoIf("Zap/35-1", "0 > 0?2:4") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Goto (macro-record-enable,s,4)
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Executing DeadAGI("Zap/35-1", "recordingcheck|20061212-125109|1165949466.7589") in new stack
Dec 12 12:51:09 VERBOSE[19905] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 12 12:51:12 VERBOSE[19905] logger.c:   recordingcheck|20061212-125109|1165949466.7589: Inbound recording not enabled
Dec 12 12:51:12 VERBOSE[19905] logger.c:     -- AGI Script recordingcheck completed, returning 0
Dec 12 12:51:12 VERBOSE[19905] logger.c:     -- Executing NoOp("Zap/35-1", "No recording needed") in new stack
Dec 12 12:51:12 DEBUG[19905] pbx.c: Expression result is '0'
Dec 12 12:51:12 VERBOSE[19905] logger.c:     -- Executing GotoIf("Zap/35-1", "0?dolocaldial|1") in new stack
Dec 12 12:51:12 DEBUG[19905] pbx.c: Not taking any branch
Dec 12 12:51:12 VERBOSE[19905] logger.c:     -- Executing Macro("Zap/35-1", "dial|15|tr|6643") in new stack
Dec 12 12:51:12 VERBOSE[19905] logger.c:     -- Executing DeadAGI("Zap/35-1", "dialparties.agi") in new stack
Dec 12 12:51:12 VERBOSE[19905] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 12 12:51:14 VERBOSE[5481] logger.c:     -- Channel 0/11, span 2 got hangup request
Dec 12 12:51:14 VERBOSE[5481] logger.c:     -- PROGRESS with cause code 18 received
Dec 12 12:51:14 DEBUG[5481] chan_zap.c: Queuing frame from PRI_EVENT_PROGRESS on channel 0/10 span 2
Dec 12 12:51:14 VERBOSE[19900] logger.c:     -- Zap/34-1 is making progress passing it to Zap/58-1
Dec 12 12:51:14 DEBUG[19900] chan_zap.c: Requested indication 14 on channel Zap/58-1
Dec 12 12:51:14 DEBUG[19900] chan_zap.c: Received AST_CONTROL_PROGRESS on Zap/58-1
Dec 12 12:51:14 VERBOSE[19905] logger.c:   dialparties.agi: Starting New Dialparties.agi
Dec 12 12:51:14 VERBOSE[19905] logger.c:   dialparties.agi: priority is 1
Dec 12 12:51:14 VERBOSE[19905] logger.c:   dialparties.agi: Caller ID name is 'FRONTIER MORTGA' number is '3143926600'
Dec 12 12:51:14 VERBOSE[19905] logger.c:   dialparties.agi: Methodology of ring is  'none'
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: USE_CONFIRMATION:  'FALSE'
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: RINGGROUP_INDEX:   ''
Dec 12 12:51:14 VERBOSE[19905] logger.c:     --  dialparties.agi: Added extension 6643 to extension map
Dec 12 12:51:14 DEBUG[19905] db.c: Unable to find key '6643' in family 'CF'
Dec 12 12:51:14 VERBOSE[19905] logger.c:     --  dialparties.agi: Extension 6643 cf is disabled
Dec 12 12:51:14 DEBUG[19905] db.c: Unable to find key '6643' in family 'DND'
Dec 12 12:51:14 VERBOSE[19905] logger.c:     --  dialparties.agi: Extension 6643 do not disturb is disabled
Dec 12 12:51:14 DEBUG[19905] db.c: Unable to find key '6643' in family 'CW'
Dec 12 12:51:14 DEBUG[19905] db.c: Unable to find key '6643' in family 'CFB'
Dec 12 12:51:14 DEBUG[19905] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: extnum: 6643
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: exthascw: 0
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: exthascfb: 0
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: extcfb:
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: exthascfu: 0
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: extcfu:
Dec 12 12:51:14 DEBUG[19910] manager.c: Manager received command 'login'
Dec 12 12:51:14 VERBOSE[19910] logger.c:   == Parsing '/etc/asterisk/manager.conf': Dec 12 12:51:14 VERBOSE[19910] logger.c:   == Parsing '/etc/asterisk/manager.conf': Found
Dec 12 12:51:14 VERBOSE[19910] logger.c:   == Parsing '/etc/asterisk/manager_custom.conf': Dec 12 12:51:14 VERBOSE[19910] logger.c:   == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 12 12:51:14 DEBUG[19910] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 12 12:51:14 DEBUG[19910] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 12 12:51:14 DEBUG[19910] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 12 12:51:14 DEBUG[19910] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 12 12:51:14 VERBOSE[19910] logger.c:   == Manager 'admin' logged on from 127.0.0.1
Dec 12 12:51:14 DEBUG[19910] manager.c: Manager received command 'ExtensionState'
Dec 12 12:51:14 DEBUG[19910] manager.c: Manager received command 'Logoff'
Dec 12 12:51:14 VERBOSE[19910] logger.c:   == Manager 'admin' logged off from 127.0.0.1
Dec 12 12:51:14 VERBOSE[19905] logger.c:        >  dialparties.agi: ExtensionState: 0
Dec 12 12:51:14 VERBOSE[19905] logger.c:   dialparties.agi: Extension 6643 has ExtensionState: 0
Dec 12 12:51:14 VERBOSE[19905] logger.c:     --  dialparties.agi: Checking CW and CFB status for extension 6643
Dec 12 12:51:14 VERBOSE[19905] logger.c:     --  dialparties.agi: dbset CALLTRACE/6643 to 3143926600
Dec 12 12:51:14 VERBOSE[19905] logger.c:     -- AGI Script dialparties.agi completed, returning 0
Dec 12 12:51:14 DEBUG[19905] app_macro.c: Extension s, macroexten 6643, priority 9 returned normally even though call was hung up
Dec 12 12:51:14 DEBUG[19905] app_macro.c: Extension s, macroexten 6643, priority 12 returned normally even though call was hung up
Dec 12 12:51:14 DEBUG[19905] pbx.c: Extension 6643, priority 1 returned normally even though call was hung up
Dec 12 12:51:14 DEBUG[19905] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 12 12:51:14 DEBUG[19905] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2006-12-12 12:51:09','\"FRONTIER MORTGA\" <3143926600>','3143926600','6643','from-pstn', 'Zap/35-1','','DeadAGI','dialparties.agi',5,0,'NO ANSWER',2,'','1165949466.7589')
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/35-1
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: Hangup: channel: 35 index = 0, normal = 23, callwait = -1, thirdcall = -1
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: disabled echo cancellation on channel 35
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/35-1
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: Updated conferencing on 35, with 0 conference users
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/35-1
Dec 12 12:51:14 DEBUG[19905] chan_zap.c: disabled echo cancellation on channel 35
Dec 12 12:51:14 VERBOSE[19905] logger.c:     -- Hungup 'Zap/35-1'
Dec 12 12:51:16 VERBOSE[5482] logger.c:     -- Channel 0/10, span 3 got hangup request
Dec 12 12:51:16 DEBUG[19900] app_dial.c: Unable to forward frame
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/34-1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Hangup: channel: 34 index = 0, normal = 22, callwait = -1, thirdcall = -1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/34-1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Updated conferencing on 34, with 0 conference users
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/34-1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 12:51:16 VERBOSE[19900] logger.c:     -- Hungup 'Zap/34-1'
Dec 12 12:51:16 DEBUG[19900] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Dec 12 12:51:16 VERBOSE[19900] logger.c:   == Spawn extension (custom-to-from-alcatel, 3926643, 1) exited non-zero on 'Zap/58-1'
Dec 12 12:51:16 DEBUG[19900] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 12 12:51:16 DEBUG[19900] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2006-12-12 12:51:06','\"test test\" <3143926600>','3143926600','3926643','custom-to-from-alcatel', 'Zap/58-1','Zap/34-1','Dial','Zap/g0/3926643',10,0,'NO ANSWER',2,'','1165949463.7587')
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/58-1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Hangup: channel: 58 index = 0, normal = 38, callwait = -1, thirdcall = -1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: disabled echo cancellation on channel 58
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/58-1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Updated conferencing on 58, with 0 conference users
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/58-1
Dec 12 12:51:16 DEBUG[19900] chan_zap.c: disabled echo cancellation on channel 58
Dec 12 12:51:16 VERBOSE[19900] logger.c:     -- Hungup 'Zap/58-1'