from inside:
[root@asterisk1 asterisk]# tail -f /var/log/asterisk/full
Dec 12 13:36:47 DEBUG[24210] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Dec 12 13:36:47 DEBUG[24210] chan_zap.c: disabled echo cancellation on channel 70
Dec 12 13:36:47 DEBUG[24210] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/70-1
Dec 12 13:36:47 DEBUG[24210] chan_zap.c: Updated conferencing on 70, with 0 conference users
Dec 12 13:36:47 DEBUG[24210] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/70-1
Dec 12 13:36:47 DEBUG[24210] chan_zap.c: disabled echo cancellation on channel 70
Dec 12 13:36:47 VERBOSE[24210] logger.c: -- Hungup 'Zap/70-1'
Dec 12 13:36:54 DEBUG[5484] chan_sip.c: Stopping retransmission on '715cc9d25e19c7e47aa7faba5f586fc5@192.168.1.250' of Request 102: Match Found
Dec 12 13:37:01 DEBUG[5484] chan_sip.c: Auto destroying call '5a2cb396e953418601e9919413d2dcfb@192.168.1.106'
Dec 12 13:37:09 DEBUG[5484] chan_sip.c: Stopping retransmission on '41f7d9aa19d12fbd2d7d55eb29b63dbc@192.168.1.250' of Request 102: Match Found
Dec 12 13:37:15 DEBUG[5484] chan_sip.c: Setting NAT on RTP to 0
Dec 12 13:37:15 DEBUG[5484] chan_sip.c: Stopping retransmission on 'dfff00a8eb95c94b27b9b38f653c4f79@192.168.1.106' of Response 1653404035: Match Found
Dec 12 13:37:15 DEBUG[5484] chan_sip.c: Setting NAT on RTP to 0
Dec 12 13:37:15 DEBUG[5484] chan_sip.c: Checking SIP call limits for device 6508
Dec 12 13:37:15 DEBUG[5484] chan_sip.c: build_route: Contact hop: sip:6508@192.168.1.106
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Macro("SIP/6508-09930690", "exten-vm|6643|6643") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Macro("SIP/6508-09930690", "user-callerid") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '0'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "0?report") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Not taking any branch
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '0'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "0?start") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Not taking any branch
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is '6508'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "REALCALLERIDNUM=6508") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing NoOp("SIP/6508-09930690", "REALCALLERIDNUM is 6508") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is '6508'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "AMPUSER=6508") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is 'Scanner Station'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "AMPUSERCIDNAME=Scanner Station") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '0'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "0?report") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Not taking any branch
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "CALLERID(all)=Scanner Station <6508>") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is '6508'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "REALCALLERIDNUM=6508") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing NoOp("SIP/6508-09930690", "TTL: ARG1: 6643") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '0'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "0?continue") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Not taking any branch
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '1'
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '-1'
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is '64'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "_TTL=64") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '1'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "1?continue") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is '"Scanner Station" <6508>'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing NoOp("SIP/6508-09930690", "Using CallerID "Scanner Station" <6508>") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing NoOp("SIP/6508-09930690", "CAME FROM: ") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "RRNODEST=") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "_NODEST=") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "FROMCONTEXT=exten-vm") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "VMBOX=6643") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "EXTTOCALL=6643") in new stack
Dec 12 13:37:15 DEBUG[24469] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 13:37:15 DEBUG[24469] func_db.c: DB: CFU/6643 not found in database.
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is ''
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "CFUEXT=") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '1'
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '0'
Dec 12 13:37:15 DEBUG[24469] pbx.c: Expression result is '1'
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is '15'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Set("SIP/6508-09930690", "RT=15") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing Macro("SIP/6508-09930690", "record-enable|6643|IN") in new stack
Dec 12 13:37:15 DEBUG[24469] pbx.c: Function result is '0'
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "0 > 0?2:4") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Goto (macro-record-enable,s,4)
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Executing DeadAGI("SIP/6508-09930690", "recordingcheck|20061212-133715|1165952235.7712") in new stack
Dec 12 13:37:15 VERBOSE[24469] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 12 13:37:16 DEBUG[5484] chan_sip.c: Auto destroying call '8bccc3064f55ca2b1d4800cc42a8f7df@192.168.1.105'
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1114' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1113' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1106' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1101' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1111' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1115' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1105' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1103' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1109' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1112' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1102' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1108' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1107' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1110' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1104' to 60 seconds (requested 300)
Dec 12 13:37:17 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1100' to 60 seconds (requested 300)
Dec 12 13:37:17 VERBOSE[24469] logger.c: recordingcheck|20061212-133715|1165952235.7712: Inbound recording not enabled
Dec 12 13:37:17 VERBOSE[24469] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 12 13:37:17 VERBOSE[24469] logger.c: -- Executing NoOp("SIP/6508-09930690", "No recording needed") in new stack
Dec 12 13:37:17 DEBUG[24469] pbx.c: Expression result is '0'
Dec 12 13:37:17 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "0?dolocaldial|1") in new stack
Dec 12 13:37:17 DEBUG[24469] pbx.c: Not taking any branch
Dec 12 13:37:17 VERBOSE[24469] logger.c: -- Executing Macro("SIP/6508-09930690", "dial|15|tr|6643") in new stack
Dec 12 13:37:17 VERBOSE[24469] logger.c: -- Executing DeadAGI("SIP/6508-09930690", "dialparties.agi") in new stack
Dec 12 13:37:17 VERBOSE[24469] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 12 13:37:20 VERBOSE[24469] logger.c: dialparties.agi: Starting New Dialparties.agi
Dec 12 13:37:20 VERBOSE[24469] logger.c: dialparties.agi: priority is 1
Dec 12 13:37:20 VERBOSE[24469] logger.c: dialparties.agi: Caller ID name is 'Scanner Station' number is '6508'
Dec 12 13:37:20 VERBOSE[24469] logger.c: dialparties.agi: Methodology of ring is 'none'
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- dialparties.agi: Added extension 6643 to extension map
Dec 12 13:37:20 DEBUG[24469] db.c: Unable to find key '6643' in family 'CF'
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- dialparties.agi: Extension 6643 cf is disabled
Dec 12 13:37:20 DEBUG[24469] db.c: Unable to find key '6643' in family 'DND'
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- dialparties.agi: Extension 6643 do not disturb is disabled
Dec 12 13:37:20 DEBUG[24469] db.c: Unable to find key '6643' in family 'CW'
Dec 12 13:37:20 DEBUG[24469] db.c: Unable to find key '6643' in family 'CFB'
Dec 12 13:37:20 DEBUG[24469] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: extnum: 6643
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: exthascw: 0
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: exthascfb: 0
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: extcfb:
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: exthascfu: 0
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: extcfu:
Dec 12 13:37:20 DEBUG[24505] manager.c: Manager received command 'login'
Dec 12 13:37:20 VERBOSE[24505] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 12 13:37:20 VERBOSE[24505] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 12 13:37:20 VERBOSE[24505] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 12 13:37:20 VERBOSE[24505] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 12 13:37:20 DEBUG[24505] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 12 13:37:20 DEBUG[24505] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 12 13:37:20 DEBUG[24505] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 12 13:37:20 DEBUG[24505] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 12 13:37:20 VERBOSE[24505] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 12 13:37:20 DEBUG[24505] manager.c: Manager received command 'ExtensionState'
Dec 12 13:37:20 DEBUG[24505] manager.c: Manager received command 'Logoff'
Dec 12 13:37:20 VERBOSE[24505] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 12 13:37:20 VERBOSE[24469] logger.c: > dialparties.agi: ExtensionState: 0
Dec 12 13:37:20 VERBOSE[24469] logger.c: dialparties.agi: Extension 6643 has ExtensionState: 0
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 6643
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- dialparties.agi: dbset CALLTRACE/6643 to 6508
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- Executing Dial("SIP/6508-09930690", "SIP/6643|15|tr") in new stack
Dec 12 13:37:20 DEBUG[24469] chan_sip.c: Setting NAT on RTP to 0
Dec 12 13:37:20 DEBUG[24469] chan_sip.c: Outgoing Call for 6643
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- Called 6643
Dec 12 13:37:20 DEBUG[5484] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5dabf33d3cbc751c56292d9246df1cc2@192.168.1.250' Request 102: Found
Dec 12 13:37:20 DEBUG[5484] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5dabf33d3cbc751c56292d9246df1cc2@192.168.1.250' Request 102: Found
Dec 12 13:37:20 VERBOSE[24469] logger.c: -- SIP/6643-098f50d0 is ringing
Dec 12 13:37:21 DEBUG[24469] chan_sip.c: update_call_counter(6643) - decrement call limit counter
Dec 12 13:37:21 DEBUG[24469] chan_sip.c: Acked pending invite 102
Dec 12 13:37:21 DEBUG[24469] chan_sip.c: Stopping retransmission on '5dabf33d3cbc751c56292d9246df1cc2@192.168.1.250' of Request 102: Match Found
Dec 12 13:37:21 DEBUG[24469] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Dec 12 13:37:21 VERBOSE[24469] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/6508-09930690' in macro 'dial'
Dec 12 13:37:21 VERBOSE[24469] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/6508-09930690' in macro 'exten-vm'
Dec 12 13:37:21 VERBOSE[24469] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/6508-09930690'
Dec 12 13:37:21 VERBOSE[24469] logger.c: -- Executing Macro("SIP/6508-09930690", "hangupcall") in new stack
Dec 12 13:37:21 VERBOSE[24469] logger.c: -- Executing ResetCDR("SIP/6508-09930690", "w") in new stack
Dec 12 13:37:21 DEBUG[24469] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 12 13:37:21 DEBUG[24469] 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 13:37:15','\"Scanner Station\" <6508>','6508','6643','from-internal', 'SIP/6508-09930690','SIP/6643-098f50d0','ResetCDR','w',6,0,'NO ANSWER',3,'','1165952235.7712')
Dec 12 13:37:21 VERBOSE[24469] logger.c: -- Executing NoCDR("SIP/6508-09930690", "") in new stack
Dec 12 13:37:21 WARNING[24469] cdr.c: CDR on channel 'SIP/6508-09930690' not posted
Dec 12 13:37:21 WARNING[24469] cdr.c: CDR on channel 'SIP/6508-09930690' lacks end
Dec 12 13:37:21 DEBUG[24469] pbx.c: Expression result is '1'
Dec 12 13:37:21 VERBOSE[24469] logger.c: -- Executing GotoIf("SIP/6508-09930690", "1?theend") in new stack
Dec 12 13:37:21 VERBOSE[24469] logger.c: -- Goto (macro-hangupcall,s,6)
Dec 12 13:37:21 VERBOSE[24469] logger.c: -- Executing Wait("SIP/6508-09930690", "5") in new stack
Dec 12 13:37:21 VERBOSE[24469] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/6508-09930690' in macro 'hangupcall'
Dec 12 13:37:21 VERBOSE[24469] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/6508-09930690'
Dec 12 13:37:21 DEBUG[24469] chan_sip.c: update_call_counter(6508) - decrement call limit counter
Dec 12 13:37:21 DEBUG[5484] chan_sip.c: Stopping retransmission on '5dabf33d3cbc751c56292d9246df1cc2@192.168.1.250' of Request 102: Match Found
Dec 12 13:37:21 DEBUG[5484] chan_sip.c: Stopping retransmission on '5dabf33d3cbc751c56292d9246df1cc2@192.168.1.250' of Request 102: Match Not Found
Dec 12 13:37:21 DEBUG[5484] chan_sip.c: Stopping retransmission on 'dfff00a8eb95c94b27b9b38f653c4f79@192.168.1.106' of Response 1653404036: Match Found
from outside:
[root@asterisk1 asterisk]# tail -f /var/log/asterisk/full
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: waitfordigit returned < 0...
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/34-1
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: Hangup: channel: 34 index = 0, normal = 22, callwait = -1, thirdcall = -1
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/34-1
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: Updated conferencing on 34, with 0 conference users
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/34-1
Dec 12 13:38:03 DEBUG[24517] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 13:38:03 VERBOSE[24517] logger.c: -- Hungup 'Zap/34-1'
Dec 12 13:38:09 DEBUG[5482] dsp.c: dsp busy pattern set to 2500,500
Dec 12 13:38:09 VERBOSE[5482] logger.c: -- Accepting overlap call from '3143926600' to '3926643' on channel 0/11, span 3
Dec 12 13:38:09 VERBOSE[24523] logger.c: -- Starting simple switch on 'Zap/59-1'
Dec 12 13:38:12 DEBUG[24523] chan_zap.c: Enabled echo cancellation on channel 59
Dec 12 13:38:12 VERBOSE[24523] logger.c: -- Executing Dial("Zap/59-1", "Zap/g0/3926643") in new stack
Dec 12 13:38:12 DEBUG[24523] dsp.c: dsp busy pattern set to 2500,500
Dec 12 13:38:12 VERBOSE[24523] logger.c: -- Requested transfer capability: 0x00 - SPEECH
Dec 12 13:38:12 VERBOSE[24523] logger.c: -- Called g0/3926643
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1114' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1113' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1106' to 60 seconds (requested 300)
Dec 12 13:38:12 DEBUG[5481] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/8 span 2
Dec 12 13:38:12 VERBOSE[24523] logger.c: -- Zap/32-1 is proceeding passing it to Zap/59-1
Dec 12 13:38:12 DEBUG[24523] chan_zap.c: Requested indication 15 on channel Zap/59-1
Dec 12 13:38:12 DEBUG[24523] chan_zap.c: Received AST_CONTROL_PROCEEDING on Zap/59-1
Dec 12 13:38:12 DEBUG[5481] dsp.c: dsp busy pattern set to 2500,500
Dec 12 13:38:12 VERBOSE[5481] logger.c: -- Accepting overlap call from '3143926600' to '6643' on channel 0/10, span 2
Dec 12 13:38:12 VERBOSE[24534] logger.c: -- Starting simple switch on 'Zap/34-1'
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1101' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1111' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1115' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1105' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1103' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1109' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1112' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1102' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1108' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1107' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1110' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1104' to 60 seconds (requested 300)
Dec 12 13:38:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1100' to 60 seconds (requested 300)
Dec 12 13:38:15 DEBUG[24534] chan_zap.c: Enabled echo cancellation on channel 34
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Macro("Zap/34-1", "exten-vm|6643|6643") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Macro("Zap/34-1", "user-callerid") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '0'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing GotoIf("Zap/34-1", "0?report") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Not taking any branch
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '0'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing GotoIf("Zap/34-1", "0?start") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Not taking any branch
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is '3143926600'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "REALCALLERIDNUM=3143926600") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing NoOp("Zap/34-1", "REALCALLERIDNUM is 3143926600") in new stack
Dec 12 13:38:15 DEBUG[24534] db.c: Unable to find key '3143926600/user' in family 'DEVICE'
Dec 12 13:38:15 DEBUG[24534] func_db.c: DB: DEVICE/3143926600/user not found in database.
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is ''
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "AMPUSER=") in new stack
Dec 12 13:38:15 DEBUG[24534] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Dec 12 13:38:15 DEBUG[24534] func_db.c: DB: AMPUSER//cidname not found in database.
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is ''
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "AMPUSERCIDNAME=") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '1'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing GotoIf("Zap/34-1", "1?report") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Goto (macro-user-callerid,s,10)
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing NoOp("Zap/34-1", "TTL: ARG1: 6643") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '0'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing GotoIf("Zap/34-1", "0?continue") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Not taking any branch
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '1'
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '-1'
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is '64'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "_TTL=64") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '1'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing GotoIf("Zap/34-1", "1?continue") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is '"FRONTIER MORTGA" <3143926600>'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing NoOp("Zap/34-1", "Using CallerID "FRONTIER MORTGA" <3143926600>") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing NoOp("Zap/34-1", "CAME FROM: ") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "RRNODEST=") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "_NODEST=") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "FROMCONTEXT=exten-vm") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "VMBOX=6643") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "EXTTOCALL=6643") in new stack
Dec 12 13:38:15 DEBUG[24534] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 13:38:15 DEBUG[24534] func_db.c: DB: CFU/6643 not found in database.
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is ''
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "CFUEXT=") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '1'
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '0'
Dec 12 13:38:15 DEBUG[24534] pbx.c: Expression result is '1'
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is '15'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Set("Zap/34-1", "RT=15") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing Macro("Zap/34-1", "record-enable|6643|IN") in new stack
Dec 12 13:38:15 DEBUG[24534] pbx.c: Function result is '0'
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing GotoIf("Zap/34-1", "0 > 0?2:4") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Goto (macro-record-enable,s,4)
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Executing DeadAGI("Zap/34-1", "recordingcheck|20061212-133815|1165952292.7719") in new stack
Dec 12 13:38:15 VERBOSE[24534] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 12 13:38:18 VERBOSE[24534] logger.c: recordingcheck|20061212-133815|1165952292.7719: Inbound recording not enabled
Dec 12 13:38:18 VERBOSE[24534] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 12 13:38:18 VERBOSE[24534] logger.c: -- Executing NoOp("Zap/34-1", "No recording needed") in new stack
Dec 12 13:38:18 DEBUG[24534] pbx.c: Expression result is '0'
Dec 12 13:38:18 VERBOSE[24534] logger.c: -- Executing GotoIf("Zap/34-1", "0?dolocaldial|1") in new stack
Dec 12 13:38:18 DEBUG[24534] pbx.c: Not taking any branch
Dec 12 13:38:18 VERBOSE[24534] logger.c: -- Executing Macro("Zap/34-1", "dial|15|tr|6643") in new stack
Dec 12 13:38:18 VERBOSE[24534] logger.c: -- Executing DeadAGI("Zap/34-1", "dialparties.agi") in new stack
Dec 12 13:38:18 VERBOSE[24534] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 12 13:38:20 VERBOSE[5481] logger.c: -- Channel 0/10, span 2 got hangup request
Dec 12 13:38:20 VERBOSE[5481] logger.c: -- PROGRESS with cause code 18 received
Dec 12 13:38:20 DEBUG[5481] chan_zap.c: Queuing frame from PRI_EVENT_PROGRESS on channel 0/8 span 2
Dec 12 13:38:20 VERBOSE[24523] logger.c: -- Zap/32-1 is making progress passing it to Zap/59-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Requested indication 14 on channel Zap/59-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Received AST_CONTROL_PROGRESS on Zap/59-1
Dec 12 13:38:20 VERBOSE[24534] logger.c: dialparties.agi: Starting New Dialparties.agi
Dec 12 13:38:20 VERBOSE[24534] logger.c: dialparties.agi: priority is 1
Dec 12 13:38:20 VERBOSE[24534] logger.c: dialparties.agi: Caller ID name is 'FRONTIER MORTGA' number is '3143926600'
Dec 12 13:38:20 VERBOSE[24534] logger.c: dialparties.agi: Methodology of ring is 'none'
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Dec 12 13:38:20 VERBOSE[24534] logger.c: -- dialparties.agi: Added extension 6643 to extension map
Dec 12 13:38:20 DEBUG[24534] db.c: Unable to find key '6643' in family 'CF'
Dec 12 13:38:20 VERBOSE[24534] logger.c: -- dialparties.agi: Extension 6643 cf is disabled
Dec 12 13:38:20 DEBUG[24534] db.c: Unable to find key '6643' in family 'DND'
Dec 12 13:38:20 VERBOSE[24534] logger.c: -- dialparties.agi: Extension 6643 do not disturb is disabled
Dec 12 13:38:20 DEBUG[24534] db.c: Unable to find key '6643' in family 'CW'
Dec 12 13:38:20 DEBUG[24534] db.c: Unable to find key '6643' in family 'CFB'
Dec 12 13:38:20 DEBUG[24534] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: extnum: 6643
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: exthascw: 0
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: exthascfb: 0
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: extcfb:
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: exthascfu: 0
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: extcfu:
Dec 12 13:38:20 DEBUG[24565] manager.c: Manager received command 'login'
Dec 12 13:38:20 VERBOSE[24565] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 12 13:38:20 VERBOSE[24565] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 12 13:38:20 VERBOSE[24565] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 12 13:38:20 VERBOSE[24565] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 12 13:38:20 DEBUG[24565] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 12 13:38:20 DEBUG[24565] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 12 13:38:20 DEBUG[24565] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 12 13:38:20 DEBUG[24565] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 12 13:38:20 VERBOSE[24565] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 12 13:38:20 DEBUG[24565] manager.c: Manager received command 'ExtensionState'
Dec 12 13:38:20 DEBUG[24565] manager.c: Manager received command 'Logoff'
Dec 12 13:38:20 VERBOSE[24565] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 12 13:38:20 VERBOSE[24534] logger.c: > dialparties.agi: ExtensionState: 0
Dec 12 13:38:20 VERBOSE[24534] logger.c: dialparties.agi: Extension 6643 has ExtensionState: 0
Dec 12 13:38:20 VERBOSE[24534] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 6643
Dec 12 13:38:20 VERBOSE[24534] logger.c: -- dialparties.agi: dbset CALLTRACE/6643 to 3143926600
Dec 12 13:38:20 VERBOSE[24534] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 12 13:38:20 DEBUG[24534] app_macro.c: Extension s, macroexten 6643, priority 9 returned normally even though call was hung up
Dec 12 13:38:20 DEBUG[24534] app_macro.c: Extension s, macroexten 6643, priority 12 returned normally even though call was hung up
Dec 12 13:38:20 DEBUG[24534] pbx.c: Extension 6643, priority 1 returned normally even though call was hung up
Dec 12 13:38:20 DEBUG[24534] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 12 13:38:20 DEBUG[24534] 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 13:38:15','\"FRONTIER MORTGA\" <3143926600>','3143926600','6643','from-pstn', 'Zap/34-1','','DeadAGI','dialparties.agi',5,0,'NO ANSWER',2,'','1165952292.7719')
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/34-1
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: Hangup: channel: 34 index = 0, normal = 22, callwait = -1, thirdcall = -1
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/34-1
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: Updated conferencing on 34, with 0 conference users
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/34-1
Dec 12 13:38:20 DEBUG[24534] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 13:38:20 VERBOSE[24534] logger.c: -- Hungup 'Zap/34-1'
Dec 12 13:38:20 VERBOSE[5482] logger.c: -- Channel 0/11, span 3 got hangup request
Dec 12 13:38:20 DEBUG[24523] app_dial.c: Unable to forward frame
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/32-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Hangup: channel: 32 index = 0, normal = 20, callwait = -1, thirdcall = -1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: disabled echo cancellation on channel 32
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/32-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Updated conferencing on 32, with 0 conference users
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/32-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: disabled echo cancellation on channel 32
Dec 12 13:38:20 VERBOSE[24523] logger.c: -- Hungup 'Zap/32-1'
Dec 12 13:38:20 DEBUG[24523] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Dec 12 13:38:20 VERBOSE[24523] logger.c: == Spawn extension (custom-to-from-alcatel, 3926643, 1) exited non-zero on 'Zap/59-1'
Dec 12 13:38:20 DEBUG[24523] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 12 13:38:20 DEBUG[24523] 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 13:38:12','\"test test\" <3143926600>','3143926600','3926643','custom-to-from-alcatel', 'Zap/59-1','Zap/32-1','Dial','Zap/g0/3926643',8,0,'NO ANSWER',2,'','1165952289.7717')
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/59-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Hangup: channel: 59 index = 0, normal = 39, callwait = -1, thirdcall = -1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: disabled echo cancellation on channel 59
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/59-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Updated conferencing on 59, with 0 conference users
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/59-1
Dec 12 13:38:20 DEBUG[24523] chan_zap.c: disabled echo cancellation on channel 59
Dec 12 13:38:20 VERBOSE[24523] logger.c: -- Hungup 'Zap/59-1'