Jan 9 10:15:14 DEBUG[9123]: app_dial.c:1635 dial_exec_full: Exiting with DIALSTATUS=CANCEL.
== Spawn extension (macro-dialout-trunk, s, 21) exited non-zero on 'SIP/710001-0971cca0' in macro 'dialout-trunk'
== Spawn extension (macro-dialout-trunk, s, 21) exited non-zero on 'SIP/710001-0971cca0'
Jan 9 10:15:14 DEBUG[9123]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record.
Jan 9 10:15:14 DEBUG[9123]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES ('2007-01-09 10:13:38','sipsrv2_h323','','116770001','from-internal', 'SIP/710001-0971cca0','OOH323/10.100.1.40:1720-ad02','Dial','OOH323/[email protected]:1720|120|r',96,0,'NO ANSWER',3,'')
Jan 9 10:15:14 DEBUG[9123]: chan_sip.c:2433 sip_hangup: update_call_counter(710001) - decrement call limit counter
Jan 9 10:15:14 DEBUG[9123] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Jan 9 10:15:14 DEBUG[9123] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jan 9 10:15:14 DEBUG[9123] 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) VALUES ('2007-01-09 10:13:38','sipsrv2_h323','','116770001','from-internal', 'SIP/710001-0971cca0','OOH323/10.100.1.40:1720-ad02','Dial','OOH323/[email protected]:1720|120|r',96,0,'NO ANSWER',3,'')
Jan 9 10:15:14 DEBUG[9123] chan_sip.c: update_call_counter(710001) - decrement call limit counter
Jan 9 10:15:30 DEBUG[9074]: chan_sip.c:7174 check_user_full: Setting NAT on RTP to 0
Jan 9 10:15:30 DEBUG[9074]: chan_sip.c:1410 __sip_ack: Stopping retransmission on '3c53430dcd14-gcpg7igj0v3j@10-101-255-161' of Response 1: Match Found
Jan 9 10:15:30 DEBUG[9074]: chan_sip.c:7174 check_user_full: Setting NAT on RTP to 0
Jan 9 10:15:30 DEBUG[9074]: chan_sip.c:10530 handle_request_invite: Checking SIP call limits for device 710001
Jan 9 10:15:30 DEBUG[9074]: chan_sip.c:6152 build_route: build_route: Contact hop: <sip:[email protected]:5060;line=r79g9ktm>
-- Executing Set("SIP/710001-09726628", "EMERGENCYROUTE=YES") in new stack
-- Executing Macro("SIP/710001-09726628", "dialout-trunk|4|770001||") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '1'
-- Executing GotoIf("SIP/710001-09726628", "1?3:2") in new stack
-- Goto (macro-dialout-trunk,s,3)
-- Executing Macro("SIP/710001-09726628", "user-callerid") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0'
-- Executing GotoIf("SIP/710001-09726628", "0?report") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:6176 pbx_builtin_gotoif: Not taking any branch
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0'
-- Executing GotoIf("SIP/710001-09726628", "0?start") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:6176 pbx_builtin_gotoif: Not taking any branch
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '710001'
-- Executing Set("SIP/710001-09726628", "REALCALLERIDNUM=710001") in new stack
-- Executing NoOp("SIP/710001-09726628", "REALCALLERIDNUM is 710001") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '710001'
-- Executing Set("SIP/710001-09726628", "AMPUSER=710001") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '710001'
-- Executing Set("SIP/710001-09726628", "AMPUSERCIDNAME=710001") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0'
-- Executing GotoIf("SIP/710001-09726628", "0?report") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:6176 pbx_builtin_gotoif: Not taking any branch
-- Executing Set("SIP/710001-09726628", "CALLERID(all)=710001 <710001>") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"710001" <710001>'
-- Executing NoOp("SIP/710001-09726628", "Using CallerID "710001" <710001>") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '710001'
-- Executing Macro("SIP/710001-09726628", "record-enable|710001|OUT") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0'
-- Executing GotoIf("SIP/710001-09726628", "0 > 0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing AGI("SIP/710001-09726628", "recordingcheck|20070109-101530|1168334130.2") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
PHP Warning: Unknown(): Unable to load dynamic library '/usr/lib/php4/imap.so' - libc-client.so.0: cannot open shared object file: No such file or directory in Unknown on line 0
Jan 9 10:15:30 DEBUG[9074] chan_sip.c: Setting NAT on RTP to 0
Jan 9 10:15:30 DEBUG[9074] chan_sip.c: Stopping retransmission on '3c53430dcd14-gcpg7igj0v3j@10-101-255-161' of Response 1: Match Found
Jan 9 10:15:30 DEBUG[9074] chan_sip.c: Setting NAT on RTP to 0
Jan 9 10:15:30 DEBUG[9074] chan_sip.c: Checking SIP call limits for device 710001
Jan 9 10:15:30 DEBUG[9074] chan_sip.c: build_route: Contact hop: <sip:[email protected]:5060;line=r79g9ktm>
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '1'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '0'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Not taking any branch
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '0'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Not taking any branch
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '710001'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '710001'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '710001'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '0'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Not taking any branch
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '"710001" <710001>'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '710001'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '0'
recordingcheck|20070109-101530|1168334130.2: Outbound recording not enabled
-- AGI Script recordingcheck completed, returning 0
-- Executing NoOp("SIP/710001-09726628", "No recording needed") in new stack
-- Executing Macro("SIP/710001-09726628", "outbound-callerid|4") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '1'
-- Executing GotoIf("SIP/710001-09726628", "1?start") in new stack
-- Goto (macro-outbound-callerid,s,3)
-- Executing NoOp("SIP/710001-09726628", "REALCALLERIDNUM is 710001") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is ''
-- Executing Set("SIP/710001-09726628", "USEROUTCID=") in new stack
Jan 9 10:15:30 DEBUG[9372]: db.c:200 ast_db_get: Unable to find key '710001/emergency_cid' in family 'DEVICE'
Jan 9 10:15:30 DEBUG[9372]: func_db.c:69 function_db_read: DB: DEVICE/710001/emergency_cid not found in database.
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is ''
-- Executing Set("SIP/710001-09726628", "EMERGENCYCID=") in new stack
-- Executing Set("SIP/710001-09726628", "TRUNKOUTCID=sipsrv2_h323") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0'
-- Executing GotoIf("SIP/710001-09726628", "0?trunkcid") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:6176 pbx_builtin_gotoif: Not taking any branch
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '1'
-- Executing GotoIf("SIP/710001-09726628", "1?trunkcid") in new stack
-- Goto (macro-outbound-callerid,s,11)
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0'
-- Executing GotoIf("SIP/710001-09726628", "0?usercid") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:6176 pbx_builtin_gotoif: Not taking any branch
-- Executing Set("SIP/710001-09726628", "CALLERID(all)=sipsrv2_h323") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '1'
-- Executing GotoIf("SIP/710001-09726628", "1?report") in new stack
-- Goto (macro-outbound-callerid,s,15)
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"sipsrv2_h323" <>'
-- Executing NoOp("SIP/710001-09726628", "CallerID set to "sipsrv2_h323" <>") in new stack
-- Executing Set("SIP/710001-09726628", "GROUP()=OUT_4") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1'
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0'
-- Executing GotoIf("SIP/710001-09726628", "0?108") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:6176 pbx_builtin_gotoif: Not taking any branch
-- Executing Set("SIP/710001-09726628", "DIAL_NUMBER=770001") in new stack
-- Executing Set("SIP/710001-09726628", "DIAL_TRUNK=4") in new stack
-- Executing AGI("SIP/710001-09726628", "fixlocalprefix") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
PHP Warning: Unknown(): Unable to load dynamic library '/usr/lib/php4/imap.so' - libc-client.so.0: cannot open shared object file: No such file or directory in Unknown on line 0
Jan 9 10:15:30 DEBUG[9117]: manager.c:1249 process_message: Manager received command 'Command'
Jan 9 10:15:30 DEBUG[9117]: manager.c:1249 process_message: Manager received command 'Command'
-- AGI Script fixlocalprefix completed, returning 0
-- Executing Set("SIP/710001-09726628", "OUTNUM=+11770001") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'AMP'
-- Executing Set("SIP/710001-09726628", "custom=AMP") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '1'
-- Executing GotoIf("SIP/710001-09726628", "1?16") in new stack
-- Goto (macro-dialout-trunk,s,16)
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'AMP:OOH323/'
-- Executing Set("SIP/710001-09726628", "pre_num=AMP:OOH323/") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'OUTNUM'
-- Executing Set("SIP/710001-09726628", "the_num=OUTNUM") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '@10.100.1.40:1720'
-- Executing Set("SIP/710001-09726628", "[email protected]:1720") in new stack
Jan 9 10:15:30 DEBUG[9372]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '1'
-- Executing GotoIf("SIP/710001-09726628", "1?20:21") in new stack
-- Goto (macro-dialout-trunk,s,20)
-- Executing Set("SIP/710001-09726628", "the_num=+11770001") in new stack
[b] -- Executing Dial("SIP/710001-09726628", "OOH323/[email protected]:1720|120|r") in new stack
Jan 9 10:15:30 ERROR[9372]: src/chan_h323.c:772 ooh323_call: Failed to make call
-- Couldn't call [email protected]:1720[/b]
== Everyone is busy/congested at this time (0:0/0/0)
Jan 9 10:15:30 DEBUG[9372]: app_dial.c:1635 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL.
-- Executing Goto("SIP/710001-09726628", "s-CHANUNAVAIL|1") in new stack
-- Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
-- Executing NoOp("SIP/710001-09726628", "Dial failed due to CHANUNAVAIL") in new stack
-- Executing Macro("SIP/710001-09726628", "outisbusy|") in new stack
-- Executing Playback("SIP/710001-09726628", "all-circuits-busy-now") in new stack
-- Playing 'all-circuits-busy-now' (language 'en')
Jan 9 10:15:30 DEBUG[9074]: chan_sip.c:1410 __sip_ack: Stopping retransmission on '3c53430dcd14-gcpg7igj0v3j@10-101-255-161' of Response 2: Match Found
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '1'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is ''
Jan 9 10:15:30 DEBUG[9372] db.c: Unable to find key '710001/emergency_cid' in family 'DEVICE'
Jan 9 10:15:30 DEBUG[9372] func_db.c: DB: DEVICE/710001/emergency_cid not found in database.
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is ''
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '0'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Not taking any branch
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '1'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '0'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Not taking any branch
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '1'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '"sipsrv2_h323" <>'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '1'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '0'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Not taking any branch
Jan 9 10:15:30 DEBUG[9117] manager.c: Manager received command 'Command'
Jan 9 10:15:30 DEBUG[9117] manager.c: Manager received command 'Command'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is 'AMP'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '1'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is 'AMP:OOH323/'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is 'OUTNUM'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Function result is '@10.100.1.40:1720'
Jan 9 10:15:30 DEBUG[9372] pbx.c: Expression result is '1'
Jan 9 10:15:30 DEBUG[9372] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Jan 9 10:15:30 DEBUG[9074] chan_sip.c: Stopping retransmission on '3c53430dcd14-gcpg7igj0v3j@10-101-255-161' of Response 2: Match Found
-- Executing Playback("SIP/710001-09726628", "pls-try-call-later") in new stack
-- Playing 'pls-try-call-later' (language 'en')
Jan 9 10:15:34 WARNING[9074]: chan_sip.c:1226 retrans_pkt: Maximum retries exceeded on transmission 3c53429db239-k6t77xj1g0uc@10-101-255-161 for seqno 2 (Critical Response)
-- Executing Macro("SIP/710001-09726628", "hangupcall") in new stack
-- Executing ResetCDR("SIP/710001-09726628", "w") in new stack
Jan 9 10:15:34 DEBUG[9372]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record.
Jan 9 10:15:34 DEBUG[9372]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES ('2007-01-09 10:15:30','sipsrv2_h323','','116770001','from-internal', 'SIP/710001-09726628','OOH323/10.100.1.40:1720-a1e4','ResetCDR','w',4,4,'ANSWERED',3,'')
-- Executing NoCDR("SIP/710001-09726628", "") in new stack
Jan 9 10:15:34 WARNING[9372]: cdr.c:443 ast_cdr_free: CDR on channel 'SIP/710001-09726628' not posted
Jan 9 10:15:34 WARNING[9372]: cdr.c:445 ast_cdr_free: CDR on channel 'SIP/710001-09726628' lacks end
-- Executing Wait("SIP/710001-09726628", "5") in new stack
Jan 9 10:15:34 DEBUG[9372] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jan 9 10:15:34 DEBUG[9372] 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) VALUES ('2007-01-09 10:15:30','sipsrv2_h323','','116770001','from-internal', 'SIP/710001-09726628','OOH323/10.100.1.40:1720-a1e4','ResetCDR','w',4,4,'ANSWERED',3,'')
-- Executing Hangup("SIP/710001-09726628", "") in new stack