rendered paste body
Apr 26 19:56:39 DEBUG[2651] chan_sip.c: Auto destroying call '07ea23e52f9e4ae21055bfbb7bb80440@68.58.152.193'
Apr 26 19:56:39 DEBUG[2651] chan_sip.c: Auto destroying call '7ae299e8670d3ddb17faa9e451031f1e@68.58.152.193'
Apr 26 19:56:42 DEBUG[2651] acl.c: ##### Testing 172.16.9.102 with 172.16.9.0
Apr 26 19:56:42 DEBUG[2651] chan_sip.c: Setting NAT on RTP to 0
Apr 26 19:56:42 DEBUG[2651] chan_sip.c: Stopping retransmission on '0007ebcd-c4000097-071cf4f5-704c81ea@172.16.9.102' of Response 101: Match Found
Apr 26 19:56:42 DEBUG[2651] chan_sip.c: Setting NAT on RTP to 0
Apr 26 19:56:42 DEBUG[2651] chan_sip.c: Checking SIP call limits for device 1000
Apr 26 19:56:42 DEBUG[2651] chan_sip.c: build_route: Contact hop: <sip:1000@172.16.9.102:5061>
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Macro("SIP/1000-16b5", "dialout-trunk|6|393613||") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Expression result is '1'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "1?3:2") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Goto (macro-dialout-trunk,s,3)
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Macro("SIP/1000-16b5", "user-callerid") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '1000'
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '1000'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "AMPUSER=1000") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '1000'
Apr 26 19:56:42 DEBUG[7421] db.c: Unable to find key '1000/emergency_cid' in family 'DEVICE'
Apr 26 19:56:42 DEBUG[7421] func_db.c: DB: DEVICE/1000/emergency_cid not found in database.
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is ''
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "EMERGENCYCID=") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is 'Line 1'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "AMPUSERCIDNAME=Line 1") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Expression result is '0'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "0?6") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Not taking any branch
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "CALLERID(all)="Line 1" <1000>") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '"Line 1" <1000>'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing NoOp("SIP/1000-16b5", "Using CallerID "Line 1" <1000>") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '1000'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Macro("SIP/1000-16b5", "record-enable|1000|OUT") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '0'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "0 > 0?2:4") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Goto (macro-record-enable,s,4)
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing AGI("SIP/1000-16b5", "recordingcheck|20060426-195642|1146095802.125") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Apr 26 19:56:42 VERBOSE[7421] logger.c: recordingcheck|20060426-195642|1146095802.125: Outbound recording not enabled
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- AGI Script recordingcheck completed, returning 0
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing NoOp("SIP/1000-16b5", "No recording needed") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Macro("SIP/1000-16b5", "outbound-callerid|6") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '1000'
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is ''
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "USEROUTCID=") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Expression result is '0'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "0?4") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Not taking any branch
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "CALLERID(all)=767434") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Expression result is '1'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "1?6") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Goto (macro-outbound-callerid,s,6)
Apr 26 19:56:42 DEBUG[7421] pbx.c: Expression result is '1'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "1?8") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Goto (macro-outbound-callerid,s,8)
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '"" <767434>'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing NoOp("SIP/1000-16b5", "CallerID set to "" <767434>") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "GROUP()=OUT_6") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is '1'
Apr 26 19:56:42 WARNING[7421] ast_expr2.fl: ast_yyerror(): syntax error: syntax error, unexpected $end, expecting TOK_MINUS or TOK_COMPL or TOK_LP or TOKEN; Input:
1 >
^
Apr 26 19:56:42 WARNING[7421] ast_expr2.fl: If you have questions, please refer to doc/README.variables in the asterisk source.
Apr 26 19:56:42 DEBUG[7421] pbx.c: Expression result is '0'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "0?108") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Not taking any branch
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "DIAL_NUMBER=393613") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "DIAL_TRUNK=6") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing AGI("SIP/1000-16b5", "fixlocalprefix") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- AGI Script fixlocalprefix completed, returning 0
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "OUTNUM=393613") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Function result is 'SIP/fwd-sip'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Set("SIP/1000-16b5", "custom=SIP/fwd-sip") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Expression result is '0'
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing GotoIf("SIP/1000-16b5", "0?16") in new stack
Apr 26 19:56:42 DEBUG[7421] pbx.c: Not taking any branch
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Dial("SIP/1000-16b5", "SIP/fwd-sip/393613|120|W") in new stack
Apr 26 19:56:42 WARNING[7421] chan_sip.c: No such host: fwd-sip
Apr 26 19:56:42 NOTICE[7421] app_dial.c: Unable to create channel of type 'SIP' (cause 3 - No route to destination)
Apr 26 19:56:42 VERBOSE[7421] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Apr 26 19:56:42 DEBUG[7421] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Goto("SIP/1000-16b5", "s-CHANUNAVAIL|1") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing NoOp("SIP/1000-16b5", "Dial failed due to CHANUNAVAIL") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Macro("SIP/1000-16b5", "outisbusy|") in new stack
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Executing Playback("SIP/1000-16b5", "all-circuits-busy-now") in new stack
Apr 26 19:56:42 DEBUG[2639] channel.c: Avoiding initial deadlock for 'SIP/1000-16b5'
Apr 26 19:56:42 DEBUG[7421] channel.c: Scheduling timer at 160 sample intervals
Apr 26 19:56:42 VERBOSE[7421] logger.c: -- Playing 'all-circuits-busy-now' (language 'en')
Apr 26 19:56:42 DEBUG[2651] chan_sip.c: Stopping retransmission on '0007ebcd-c4000097-071cf4f5-704c81ea@172.16.9.102' of Response 102: Match Found
Apr 26 19:56:44 DEBUG[7421] channel.c: Scheduling timer at 0 sample intervals
Apr 26 19:56:44 DEBUG[7421] channel.c: Scheduling timer at 0 sample intervals
Apr 26 19:56:44 VERBOSE[7421] logger.c: -- Executing Playback("SIP/1000-16b5", "pls-try-call-later") in new stack
Apr 26 19:56:44 DEBUG[7421] channel.c: Scheduling timer at 160 sample intervals
Apr 26 19:56:44 VERBOSE[7421] logger.c: -- Playing 'pls-try-call-later' (language 'en')
Apr 26 19:56:46 DEBUG[7421] channel.c: Scheduling timer at 0 sample intervals
Apr 26 19:56:46 DEBUG[7421] channel.c: Scheduling timer at 0 sample intervals
Apr 26 19:56:46 VERBOSE[7421] logger.c: -- Executing Macro("SIP/1000-16b5", "hangupcall") in new stack
Apr 26 19:56:46 VERBOSE[7421] logger.c: -- Executing ResetCDR("SIP/1000-16b5", "w") in new stack
Apr 26 19:56:46 DEBUG[7421] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Apr 26 19:56:46 DEBUG[7421] 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-04-26 19:56:42','767434','767434','393613','from-internal', 'SIP/1000-16b5','','ResetCDR','w',4,4,'ANSWERED',3,'','1146095802.125')
Apr 26 19:56:46 VERBOSE[7421] logger.c: -- Executing NoCDR("SIP/1000-16b5", "") in new stack
Apr 26 19:56:46 WARNING[7421] cdr.c: CDR on channel 'SIP/1000-16b5' not posted
Apr 26 19:56:46 WARNING[7421] cdr.c: CDR on channel 'SIP/1000-16b5' lacks end
Apr 26 19:56:46 VERBOSE[7421] logger.c: -- Executing Wait("SIP/1000-16b5", "5") in new stack
Apr 26 19:56:47 VERBOSE[7421] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/1000-16b5' in macro 'hangupcall'
Apr 26 19:56:47 VERBOSE[7421] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/1000-16b5' in macro 'outisbusy'
Apr 26 19:56:47 VERBOSE[7421] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'SIP/1000-16b5'
Apr 26 19:56:47 DEBUG[7421] chan_sip.c: update_call_counter(1000) - decrement call limit counter