Jun 22 16:14:23 VERBOSE[5707] logger.c: Asterisk Event Logger restarted
Jun 22 16:14:23 VERBOSE[5707] logger.c: Asterisk Queue Logger restarted
Jun 22 16:14:32 VERBOSE[2977] logger.c:     -- Accepting AUTHENTICATED call from 192.168.0.8:
       > requested format = gsm,
       > requested prefs = (),
       > actual format = ulaw,
       > host prefs = (ulaw|alaw|gsm),
       > priority = mine
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing Macro("IAX2/220-1", "dialout-trunk|1|01572771006||") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Expression result is '1'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "1?3:2") in new stack
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Goto (macro-dialout-trunk,s,3)
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing Macro("IAX2/220-1", "user-callerid") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Expression result is '0'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "0?report") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Not taking any branch
Jun 22 16:14:32 DEBUG[5708] pbx.c: Expression result is '0'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "0?start") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Not taking any branch
Jun 22 16:14:32 DEBUG[5708] pbx.c: Function result is '220'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "REALCALLERIDNUM=220") in new stack
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing NoOp("IAX2/220-1", "REALCALLERIDNUM is 220") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Function result is '220'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "AMPUSER=220") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Function result is 'CamOn'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "AMPUSERCIDNAME=CamOn") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Expression result is '0'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "0?report") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Not taking any branch
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "CALLERID(all)=CamOn <220>") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Function result is '"CamOn" <220>'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing NoOp("IAX2/220-1", "Using CallerID "CamOn" <220>") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Function result is '220'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing Macro("IAX2/220-1", "record-enable|220|OUT") in new stack
Jun 22 16:14:32 DEBUG[5708] pbx.c: Function result is '0'
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "0 > 0?2:4") in new stack
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Goto (macro-record-enable,s,4)
Jun 22 16:14:32 DEBUG[2977] chan_iax2.c: Ooh, voice format changed to 4
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Executing AGI("IAX2/220-1", "recordingcheck|20060622-161432|1150989272.20") in new stack
Jun 22 16:14:32 VERBOSE[5708] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Jun 22 16:14:33 VERBOSE[5708] logger.c:   recordingcheck|20060622-161432|1150989272.20: Outbound recording not enabled
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- AGI Script recordingcheck completed, returning 0
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing NoOp("IAX2/220-1", "No recording needed") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Macro("IAX2/220-1", "outbound-callerid|1") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Expression result is '1'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "1?start") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Goto (macro-outbound-callerid,s,3)
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing NoOp("IAX2/220-1", "REALCALLERIDNUM is 220") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Function result is ''
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "USEROUTCID=") in new stack
Jun 22 16:14:33 DEBUG[5708] db.c: Unable to find key '220/emergency_cid' in family 'DEVICE'
Jun 22 16:14:33 DEBUG[5708] func_db.c: DB: DEVICE/220/emergency_cid not found in database.
Jun 22 16:14:33 DEBUG[5708] pbx.c: Function result is ''
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "EMERGENCYCID=") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "TRUNKOUTCID=01572771006") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Expression result is '1'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "1?trunkcid") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Goto (macro-outbound-callerid,s,11)
Jun 22 16:14:33 DEBUG[5708] pbx.c: Expression result is '0'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "0?usercid") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Not taking any branch
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "CALLERID(all)=01572771006") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Expression result is '1'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "1?report") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Goto (macro-outbound-callerid,s,15)
Jun 22 16:14:33 DEBUG[5708] pbx.c: Function result is '"" <01572771006>'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing NoOp("IAX2/220-1", "CallerID set to "" <01572771006>") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "GROUP()=OUT_1") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Function result is '1'
Jun 22 16:14:33 DEBUG[5708] pbx.c: Expression result is '0'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "0?108") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Not taking any branch
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "DIAL_NUMBER=01572771006") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "DIAL_TRUNK=1") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing AGI("IAX2/220-1", "fixlocalprefix") in new stack
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- AGI Script fixlocalprefix completed, returning 0
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "OUTNUM=01572771006") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Function result is 'ZAP/1'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Set("IAX2/220-1", "custom=ZAP/1") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Expression result is '0'
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing GotoIf("IAX2/220-1", "0?16") in new stack
Jun 22 16:14:33 DEBUG[5708] pbx.c: Not taking any branch
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Executing Dial("IAX2/220-1", "ZAP/1/01572771006|120|r") in new stack
Jun 22 16:14:33 DEBUG[5708] chan_zap.c: Dialing '01572771006'
Jun 22 16:14:33 DEBUG[5708] chan_zap.c: Deferring dialing...
Jun 22 16:14:33 VERBOSE[5708] logger.c:     -- Called 1/01572771006
Jun 22 16:14:34 DEBUG[5708] chan_zap.c: Exception on 12, channel 1
Jun 22 16:14:34 DEBUG[5708] chan_zap.c: Got event Hook Transition Complete(12) on channel 1 (index 0)
Jun 22 16:14:36 DEBUG[5708] chan_zap.c: Exception on 12, channel 1
Jun 22 16:14:36 DEBUG[5708] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0)
Jun 22 16:14:36 DEBUG[5708] chan_zap.c: Enabled echo cancellation on channel 1
Jun 22 16:14:36 DEBUG[5708] chan_zap.c: Engaged echo training on channel 1
Jun 22 16:14:38 DEBUG[5708] chan_zap.c: Exception on 12, channel 1
Jun 22 16:14:38 DEBUG[5708] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0)
Jun 22 16:14:38 DEBUG[5708] chan_zap.c: Echo cancellation already on
Jun 22 16:14:38 VERBOSE[5708] logger.c:     -- Zap/1-1 answered IAX2/220-1
Jun 22 16:14:44 DEBUG[2977] chan_iax2.c: Immediately destroying 1, having received hangup
Jun 22 16:14:44 DEBUG[5708] channel.c: Didn't get a frame from channel: IAX2/220-1
Jun 22 16:14:44 DEBUG[5708] channel.c: Bridge stops bridging channels IAX2/220-1 and Zap/1-1
Jun 22 16:14:44 DEBUG[5708] chan_zap.c: Hangup: channel: 1 index = 0, normal = 12, callwait = -1, thirdcall = -1
Jun 22 16:14:44 DEBUG[5708] chan_zap.c: disabled echo cancellation on channel 1
Jun 22 16:14:44 DEBUG[5708] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Jun 22 16:14:44 DEBUG[5708] chan_zap.c: Updated conferencing on 1, with 0 conference users
Jun 22 16:14:44 VERBOSE[5708] logger.c:     -- Hungup 'Zap/1-1'
Jun 22 16:14:44 DEBUG[5708] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jun 22 16:14:44 VERBOSE[5708] logger.c:   == Spawn extension (macro-dialout-trunk, s, 14) exited non-zero on 'IAX2/220-1' in macro 'dialout-trunk'
Jun 22 16:14:44 VERBOSE[5708] logger.c:   == Spawn extension (macro-dialout-trunk, s, 14) exited non-zero on 'IAX2/220-1'
Jun 22 16:14:44 DEBUG[5708] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jun 22 16:14:44 DEBUG[5708] 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-06-22 16:14:32','01572771006','01572771006','901572771006','from-internal', 'IAX2/220-1','Zap/1-1','Dial','ZAP/1/01572771006|120|r',12,6,'ANSWERED',3,'','1150989272.20')
Jun 22 16:14:44 DEBUG[5708] chan_iax2.c: We're hanging up IAX2/220-1 now...
Jun 22 16:14:44 DEBUG[5708] chan_iax2.c: Really destroying IAX2/220-1 now...
Jun 22 16:14:44 VERBOSE[5708] logger.c:     -- Hungup 'IAX2/220-1'