Nov 6 14:38:47 DEBUG[4179] chan_sip.c: Checking SIP call limits for device 207
Nov 6 14:38:47 DEBUG[4179] chan_sip.c: build_route: Contact hop: <sip:207@10.25.3.83>
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Macro("SIP/207-089e0058", "dialout-trunk|6|0421063214||") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "DIAL_TRUNK=6") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "DIAL_NUMBER=0421063214") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "ROUTE_PASSWD=") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '1'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "1?noauth") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Goto (macro-dialout-trunk,s,6)
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "GROUP()=OUT_6") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Macro("SIP/207-089e0058", "user-callerid") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '0'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "0?report") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Not taking any branch
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '0'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "0?start") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Not taking any branch
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is '207'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "REALCALLERIDNUM=207") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing NoOp("SIP/207-089e0058", "REALCALLERIDNUM is 207") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is '207'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "AMPUSER=207") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is 'Peter Zhu'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "AMPUSERCIDNAME=Peter Zhu") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '0'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "0?report") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Not taking any branch
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "CALLERID(all)=Peter Zhu <207>") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is '"Peter Zhu" <207>'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing NoOp("SIP/207-089e0058", "Using CallerID "Peter Zhu" <207>") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is '207'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Macro("SIP/207-089e0058", "record-enable|207|OUT") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is '0'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "0 > 0?2:4") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Goto (macro-record-enable,s,4)
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing DeadAGI("SIP/207-089e0058", "recordingcheck|20061106-143847|1162784327.17") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 6 14:38:47 VERBOSE[4320] logger.c: recordingcheck|20061106-143847|1162784327.17: Outbound recording not enabled
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- AGI Script recordingcheck completed, returning 0
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing NoOp("SIP/207-089e0058", "No recording needed") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Macro("SIP/207-089e0058", "outbound-callerid|6") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '1'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "1?start") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Goto (macro-outbound-callerid,s,3)
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing NoOp("SIP/207-089e0058", "REALCALLERIDNUM is 207") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is ''
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "USEROUTCID=") in new stack
Nov 6 14:38:47 DEBUG[4320] db.c: Unable to find key '207/emergency_cid' in family 'DEVICE'
Nov 6 14:38:47 DEBUG[4320] func_db.c: DB: DEVICE/207/emergency_cid not found in database.
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is ''
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "EMERGENCYCID=") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "TRUNKOUTCID=0388040804") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '1'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "1?trunkcid") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Goto (macro-outbound-callerid,s,11)
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '0'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "0?usercid") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Not taking any branch
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "CALLERID(all)=0388040804") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '1'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "1?report") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Goto (macro-outbound-callerid,s,15)
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is '"" <0388040804>'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing NoOp("SIP/207-089e0058", "CallerID set to "" <0388040804>") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '1'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "1?nomax") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Goto (macro-dialout-trunk,s,12)
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing AGI("SIP/207-089e0058", "fixlocalprefix") in new stack
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- AGI Script fixlocalprefix completed, returning 0
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "OUTNUM=0421063214") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Function result is 'SIP/voiceblue'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Set("SIP/207-089e0058", "custom=SIP/voiceblue") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Expression result is '0'
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing GotoIf("SIP/207-089e0058", "0?customtrunk") in new stack
Nov 6 14:38:47 DEBUG[4320] pbx.c: Not taking any branch
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Dial("SIP/207-089e0058", "SIP/voiceblue/0421063214|120|r") in new stack
Nov 6 14:38:47 DEBUG[4320] chan_sip.c: Setting NAT on RTP to 524288
Nov 6 14:38:47 DEBUG[4320] acl.c: ##### Testing 10.25.3.231 with 10.25.3.0
Nov 6 14:38:47 DEBUG[4320] chan_sip.c: Outgoing Call for 0421063214
Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Called voiceblue/0421063214
Nov 6 14:38:47 DEBUG[4179] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '55ce516a59b84c294c425c55695ac8ac@1
0.25.3.132' Request 102: Found
Nov 6 14:38:48 DEBUG[4179] acl.c: ##### Testing 220.240.81.246 with 10.25.3.0
Nov 6 14:38:48 DEBUG[4179] chan_sip.c: Target address 220.240.81.246 is not local, substituting externip
Nov 6 14:38:49 VERBOSE[4175] logger.c: -- Channel 0/2, span 1 got hangup request
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Echo cancellation already on
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Echo cancellation already on
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Unlinking slave 2 from 32
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Removed 12 from conference 3848/1023
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Removed 41 from conference 3848/1023
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Updated conferencing on 32, with 0 conference users
Nov 6 14:38:49 DEBUG[4288] channel.c: Returning from native bridge, channels: Zap/32-1, Zap/2-1
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Hangup: channel: 2 index = 0, normal = 12, callwait = -1, thirdcall = -1
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: disabled echo cancellation on channel 2
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Updated conferencing on 2, with 0 conference users
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: disabled echo cancellation on channel 2
Nov 6 14:38:49 VERBOSE[4288] logger.c: -- Hungup 'Zap/2-1'
Nov 6 14:38:49 DEBUG[4288] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Nov 6 14:38:49 VERBOSE[4288] logger.c: == Spawn extension (macro-dialout-trunk, s, 16) exited non-zero on 'Zap/32-1' in macro 'dialout-trunk'
Nov 6 14:38:49 VERBOSE[4288] logger.c: == Spawn extension (macro-dialout-trunk, s, 16) exited non-zero on 'Zap/32-1'
Nov 6 14:38:49 DEBUG[4288] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 6 14:38:49 DEBUG[4288] 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-11-06 14:38:06','\"Uniware Pty Ltd\" <0388040804>','0388040804','98458355','from-internal','Zap/32-1','Zap/2-1','Dial','ZAP/g1/98458355|120|r',43,34,'ANSWERED',3,'','1162784284.11')
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '"Uniware Pty Ltd" <0388040804>'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '0388040804'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '98458355'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is 'from-internal'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is 'Zap/32-1'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is 'Zap/2-1'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is 'Dial'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is 'ZAP/g1/98458355|120|r'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '2006-11-06 14:38:06'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '2006-11-06 14:38:15'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '2006-11-06 14:38:49'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '43'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '34'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is 'ANSWERED'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is 'DOCUMENTATION'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '(null)'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '1162784284.11'
Nov 6 14:38:49 DEBUG[4288] pbx.c: Function result is '(null)'
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Hangup: channel: 32 index = 0, normal = 41, callwait = -1, thirdcall = -1
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: disabled echo cancellation on channel 32
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/32-1
Nov 6 14:38:49 DEBUG[4288] chan_zap.c: Updated conferencing on 32, with 0 conference users
Nov 6 14:38:49 VERBOSE[4288] logger.c: -- Hungup 'Zap/32-1'
Nov 6 14:38:49 DEBUG[4176] chan_zap.c: disabled echo cancellation on channel 32
Nov 6 14:38:49 DEBUG[4179] chan_sip.c: Stopping retransmission on '151e1e5b161bb09364db9feb24bf97b5@220.240.241.114' of Request 102: Match
Found
Nov 6 14:38:49 DEBUG[4179] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '55ce516a59b84c294c425c55695ac8ac@1
0.25.3.132' Request 102: Found
Nov 6 14:38:49 DEBUG[4179] chan_sip.c: Oooh, we need to change our formats since our peer supports only 0xc (ulaw|alaw) and not 0x2 (gsm)
Nov 6 14:38:49 VERBOSE[4320] logger.c: -- SIP/voiceblue-089e2c48 is making progress passing it to SIP/207-089e0058
Nov 6 14:38:59 DEBUG[4179] acl.c: ##### Testing 220.240.81.246 with 10.25.3.0
Nov 6 14:38:59 DEBUG[4179] chan_sip.c: Target address 220.240.81.246 is not local, substituting externip
Nov 6 14:38:59 DEBUG[4179] chan_sip.c: Stopping retransmission on '5147c99d223f6f815fdebb6f3f1ad9e4@220.240.241.114' of Request 102: Match
Found
Nov 6 14:39:01 DEBUG[4179] chan_sip.c: Auto destroying call '5077-D1B9-1233-81B3-95A750C6247A@192.168.1.34'
Nov 6 14:39:16 VERBOSE[4326] logger.c: -- Starting simple switch on 'Zap/32-1'
Nov 6 14:39:16 DEBUG[4326] chan_zap.c: DTMF digit: 0 on Zap/32-1
Nov 6 14:39:17 DEBUG[4326] chan_zap.c: DTMF digit: 2 on Zap/32-1
Nov 6 14:39:17 DEBUG[4326] chan_zap.c: DTMF digit: 9 on Zap/32-1
Nov 6 14:39:17 DEBUG[4326] chan_zap.c: DTMF digit: 9 on Zap/32-1
Nov 6 14:39:17 DEBUG[4326] chan_zap.c: DTMF digit: 7 on Zap/32-1
Nov 6 14:39:17 DEBUG[4326] chan_zap.c: DTMF digit: 5 on Zap/32-1
Nov 6 14:39:17 DEBUG[4179] chan_sip.c: Acked pending invite 102
Nov 6 14:39:17 DEBUG[4179] chan_sip.c: Stopping retransmission on '55ce516a59b84c294c425c55695ac8ac@10.25.3.132' of Request 102: Match Fou
nd
Nov 6 14:39:17 VERBOSE[4320] logger.c: -- SIP/voiceblue-089e2c48 is circuit-busy
Nov 6 14:39:17 DEBUG[4320] chan_sip.c: update_call_counter(0421063214) - decrement call limit counter
Nov 6 14:39:17 VERBOSE[4320] logger.c: == Everyone is busy/congested at this time (1:0/1/0)
Nov 6 14:39:17 DEBUG[4320] app_dial.c: Exiting with DIALSTATUS=CONGESTION.
Nov 6 14:39:17 VERBOSE[4320] logger.c: -- Executing Goto("SIP/207-089e0058", "s-CONGESTION|1") in new stack
Nov 6 14:39:17 VERBOSE[4320] logger.c: -- Goto (macro-dialout-trunk,s-CONGESTION,1)
Nov 6 14:39:17 VERBOSE[4320] logger.c: -- Executing NoOp("SIP/207-089e0058", "Dial failed due to CONGESTION - failing through to other
trunks") in new stack
Nov 6 14:39:17 VERBOSE[4320] logger.c: -- Executing Macro("SIP/207-089e0058", "outisbusy|") in new stack
Nov 6 14:39:17 VERBOSE[4320] logger.c: -- Executing Playback("SIP/207-089e0058", "all-circuits-busy-now") in new stack
Nov 6 14:39:17 DEBUG[4320] channel.c: Scheduling timer at 160 sample intervals
Nov 6 14:39:17 VERBOSE[4320] logger.c: -- Playing 'all-circuits-busy-now' (language 'en')
Nov 6 14:39:17 DEBUG[4179] chan_sip.c: Stopping retransmission on '3457c71f437777f4@10.25.3.83' of Response