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: Nov 6 14:38:47 VERBOSE[4320] logger.c: -- Executing Macro("SIP/207-089e0058", "dialout-trunk|6|0421063214||") in new st ack 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 sta ck 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|1162784 327.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@10.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:39:17 DEBUG[4179] chan_sip.c: Stopping retransmission on '55ce516a59b84c294c425c55695ac8ac@10.25.3.132' of Request 102: Match Found 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 t hrough 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 47241: Match Found Nov 6 14:39:21 VERBOSE[4320] logger.c: -- Executing NoCDR("SIP/207-089e0058", "") in new stack Nov 6 14:39:21 WARNING[4320] cdr.c: CDR on channel 'SIP/207-089e0058' not posted Nov 6 14:39:21 WARNING[4320] cdr.c: CDR on channel 'SIP/207-089e0058' lacks end Nov 6 14:39:21 VERBOSE[4320] logger.c: -- Executing Wait("SIP/207-089e0058", "5") in new stack Nov 6 14:39:24 VERBOSE[4320] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/207-089e0058'in macro 'hangupcall' Nov 6 14:39:24 VERBOSE[4320] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/207-089e0058'in macro 'outisbusy' Nov 6 14:39:24 VERBOSE[4320] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/207-089e0058' Nov 6 14:39:24 DEBUG[4320] chan_sip.c: update_call_counter(207) - decrement call limit cou