Sudden failure for more than one outbound call at a time

Asterisk Asterisk Support
1

Hi,

I have been using an asterisk server for three years without any problems, except one time I had to reboot because I ran out of disk space as a result of having verbose logging accidentally turned on! The system is great.

I have four lines being controlled by asterisk and two digium cards. Recently, we have encountered a problem that I don’t know how to troubleshoot. Incoming calls are no problem at all. Outgoing, however, is limited suddenly to one caller at a time. The second caller cannot get the line to ring.

I enabled logging and am copying it here. It looks like, to my novice eyes, the channel is unavailable. If this is the case, any idea why that may be suddenly happening? If that’s not the case, then can someone give me some pointers on how to resolve this?

The log file below was created in a controlled manner to reproduce the problem. We attempted to dial out to two numbers simultaneously. One was successful, the other wasn’t. I sincerely appreciate any input anyone may be able to provide.

Thanks,

Michael

May 12 10:31:44 NOTICE[15274] cdr.c: CDR simple logging enabled.
May 12 10:31:44 WARNING[15274] res_musiconhold.c: The old musiconhold.conf syntax has been deprecated! Please refer to the sample configuration for information on the new syntax.
May 12 10:31:45 WARNING[15274] config.c: Unknown directive ‘parkingtime’ at line 9 of features.conf
May 12 10:31:45 ERROR[15274] res_config_mysql.c: MySQL RealTime: Failed to connect database server on . Check debug for more info.
May 12 10:31:45 WARNING[15274] res_config_mysql.c: MySQL RealTime: Couldn’t establish connection. Check debug.
May 12 10:31:45 NOTICE[15274] config.c: Registered Config Engine mysql
May 12 10:31:46 WARNING[15274] pbx_config.c: The use of ‘_.’ for an extension is strongly discouraged and can have unexpected behavior. Please use ‘X.’ instead at line 28
May 12 10:31:46 WARNING[15274] pbx_config.c: The use of '.’ for an extension is strongly discouraged and can have unexpected behavior. Please use ‘X.’ instead at line 664
May 12 10:31:46 WARNING[15274] pbx_config.c: The use of '.’ for an extension is strongly discouraged and can have unexpected behavior. Please use ‘X.’ instead at line 665
May 12 10:31:46 WARNING[15274] pbx_config.c: The use of '.’ for an extension is strongly discouraged and can have unexpected behavior. Please use ‘X.’ instead at line 666
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘from-internal’ tries includes nonexistent context 'from-internal-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘from-pstn’ tries includes nonexistent context 'from-pstn-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘from-pstn’ tries includes nonexistent context 'ext-did’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘outrt-001-outside’ tries includes nonexistent context 'outrt-001-outside-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘outbound-allroutes’ tries includes nonexistent context 'outbound-allroutes-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘ext-queues’ tries includes nonexistent context 'ext-queues-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘ext-local’ tries includes nonexistent context 'ext-local-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘ext-group’ tries includes nonexistent context 'ext-group-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘aa_2’ tries includes nonexistent context 'aa_2-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘aa_1’ tries includes nonexistent context 'aa_1-custom’
May 12 10:31:46 ERROR[15274] pbx_dundi.c: Unable to load config dundi.conf
May 12 10:31:46 WARNING[15274] pbx_ael.c: Unable to open ‘/etc/asterisk/extensions.ael’: No such file or directory
May 12 10:31:46 WARNING[15274] pbx.c: Requested contexts didn’t get merged
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘from-internal’ tries includes nonexistent context 'from-internal-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘from-pstn’ tries includes nonexistent context 'from-pstn-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘from-pstn’ tries includes nonexistent context 'ext-did’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘outrt-001-outside’ tries includes nonexistent context 'outrt-001-outside-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘outbound-allroutes’ tries includes nonexistent context 'outbound-allroutes-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘ext-queues’ tries includes nonexistent context 'ext-queues-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘ext-local’ tries includes nonexistent context 'ext-local-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘ext-group’ tries includes nonexistent context 'ext-group-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘aa_2’ tries includes nonexistent context 'aa_2-custom’
May 12 10:31:46 WARNING[15274] pbx.c: Context ‘aa_1’ tries includes nonexistent context 'aa_1-custom’
May 12 10:31:47 WARNING[15274] cdr_custom.c: Failed to load configuration file. Module not activated.
May 12 10:31:47 WARNING[15274] cdr_addon_mysql.c: MySQL database sock file not specified. Using default
May 12 10:31:47 NOTICE[15274] cdr_addon_mysql.c: MySQL database table not specified. Assuming "cdr"
May 12 10:31:57 DEBUG[15283] chan_sip.c: Setting NAT on RTP to 0
May 12 10:31:57 DEBUG[15283] chan_sip.c: Stopping retransmission on ‘a07e0d30-2674b7c8@localhost’ of Response 101: Match Found
May 12 10:31:57 DEBUG[15283] chan_sip.c: Setting NAT on RTP to 0
May 12 10:31:57 DEBUG[15283] chan_sip.c: Checking SIP call limits for device 400
May 12 10:31:57 DEBUG[15283] chan_sip.c: build_route: Contact hop: Anonymous sip:400@192.168.1.215:5060
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “dialout-trunk|3|19495551212|”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?3:2)”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “user-callerid”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSER=DEVICE/400/user”) in new stack
May 12 10:31:57 WARNING[15298] app_db.c: This application has been deprecated, please use the ${DB(family/key)} function instead.
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=400/user
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSER to 400
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSERCIDNAME=AMPUSER/400/cidname”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=400/cidname
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSERCIDNAME to After Hours
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?5”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetCallerID(“SIP/400-e1da”, ““After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “Using CallerID “After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “record-enable|400|OUT”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Function result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0 > 0?2:4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “recordingcheck|20080512-103157|1210613517.0”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:31:57 VERBOSE[15298] logger.c: recordingcheck|20080512-103157|1210613517.0: Outbound recording not enabled
May 12 10:31:57 VERBOSE[15298] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “No recording needed”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “outbound-callerid|3”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “USEROUTCID=AMPUSER/400/outboundcid”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=400/outboundcid
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable USEROUTCID to
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?6”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “CallerID set to “After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetGroup(“SIP/400-e1da”, “OUT_3”) in new stack
May 12 10:31:57 WARNING[15298] app_groupcount.c: The SetGroup application has been deprecated, please use the GROUP() function.
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing CheckGroup(“SIP/400-e1da”, “”) in new stack
May 12 10:31:57 WARNING[15298] app_groupcount.c: The CheckGroup application has been deprecated, please use a combination of the GotoIf application and the GROUP_COUNT() function.
May 12 10:31:57 WARNING[15298] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_NUMBER=19495551212”) in new stack
May 12 10:31:57 WARNING[15298] pbx.c: SetVar is deprecated, please use Set instead.
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_TRUNK=3”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “fixlocalprefix”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:31:57 VERBOSE[15298] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:31:57 VERBOSE[15298] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “OUTNUM=19495551212”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Cut(“SIP/400-e1da”, “custom=OUT_3|:|1”) in new stack
May 12 10:31:57 WARNING[15298] app_cut.c: The application Cut is deprecated. Please use the CUT() function instead.
May 12 10:31:57 WARNING[15298] ast_expr2.y: non-numeric argument
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?16”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Dial(“SIP/400-e1da”, “ZAP/g3/19495551212”) in new stack
May 12 10:31:57 NOTICE[15298] app_dial.c: Unable to create channel of type ‘ZAP’ (cause 0 - Unknown)
May 12 10:31:57 VERBOSE[15298] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
May 12 10:31:57 DEBUG[15298] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Goto(“SIP/400-e1da”, “s-CHANUNAVAIL|1”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “Dial failed due to CHANUNAVAIL”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “dialout-trunk|2|19495551212|”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?3:2)”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “user-callerid”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSER=DEVICE/400/user”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=400/user
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSER to 400
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSERCIDNAME=AMPUSER/400/cidname”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=400/cidname
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSERCIDNAME to After Hours
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?5”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetCallerID(“SIP/400-e1da”, ““After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “Using CallerID “After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “record-enable|400|OUT”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Function result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0 > 0?2:4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “recordingcheck|20080512-103157|1210613517.0”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:31:57 VERBOSE[15298] logger.c: recordingcheck|20080512-103157|1210613517.0: Outbound recording not enabled
May 12 10:31:57 VERBOSE[15298] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “No recording needed”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “outbound-callerid|2”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “USEROUTCID=AMPUSER/400/outboundcid”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=400/outboundcid
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable USEROUTCID to
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?6”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “CallerID set to “After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetGroup(“SIP/400-e1da”, “OUT_2”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing CheckGroup(“SIP/400-e1da”, “”) in new stack
May 12 10:31:57 WARNING[15298] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_NUMBER=19495551212”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_TRUNK=2”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “fixlocalprefix”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:31:57 VERBOSE[15298] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:31:57 VERBOSE[15298] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “OUTNUM=19495551212”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Cut(“SIP/400-e1da”, “custom=OUT_2|:|1”) in new stack
May 12 10:31:57 WARNING[15298] ast_expr2.y: non-numeric argument
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?16”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Dial(“SIP/400-e1da”, “ZAP/g2/19495551212”) in new stack
May 12 10:31:57 NOTICE[15298] app_dial.c: Unable to create channel of type ‘ZAP’ (cause 0 - Unknown)
May 12 10:31:57 VERBOSE[15298] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
May 12 10:31:57 DEBUG[15298] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Goto(“SIP/400-e1da”, “s-CHANUNAVAIL|1”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “Dial failed due to CHANUNAVAIL”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “dialout-trunk|4|19495551212|”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?3:2)”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “user-callerid”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSER=DEVICE/400/user”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=400/user
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSER to 400
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSERCIDNAME=AMPUSER/400/cidname”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=400/cidname
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSERCIDNAME to After Hours
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?5”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetCallerID(“SIP/400-e1da”, ““After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “Using CallerID “After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “record-enable|400|OUT”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Function result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0 > 0?2:4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “recordingcheck|20080512-103157|1210613517.0”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:31:57 VERBOSE[15298] logger.c: recordingcheck|20080512-103157|1210613517.0: Outbound recording not enabled
May 12 10:31:57 VERBOSE[15298] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “No recording needed”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “outbound-callerid|4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “USEROUTCID=AMPUSER/400/outboundcid”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=400/outboundcid
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable USEROUTCID to
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?6”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “CallerID set to “After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetGroup(“SIP/400-e1da”, “OUT_4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing CheckGroup(“SIP/400-e1da”, “”) in new stack
May 12 10:31:57 WARNING[15298] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_NUMBER=19495551212”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_TRUNK=4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “fixlocalprefix”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:31:57 VERBOSE[15298] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:31:57 VERBOSE[15298] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “OUTNUM=19495551212”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Cut(“SIP/400-e1da”, “custom=OUT_4|:|1”) in new stack
May 12 10:31:57 WARNING[15298] ast_expr2.y: non-numeric argument
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?16”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Dial(“SIP/400-e1da”, “ZAP/g1/19495551212”) in new stack
May 12 10:31:57 NOTICE[15298] app_dial.c: Unable to create channel of type ‘ZAP’ (cause 0 - Unknown)
May 12 10:31:57 VERBOSE[15298] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
May 12 10:31:57 DEBUG[15298] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Goto(“SIP/400-e1da”, “s-CHANUNAVAIL|1”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “Dial failed due to CHANUNAVAIL”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “dialout-trunk|1|19495551212|”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?3:2)”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “user-callerid”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSER=DEVICE/400/user”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=400/user
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSER to 400
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “AMPUSERCIDNAME=AMPUSER/400/cidname”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=400/cidname
May 12 10:31:57 VERBOSE[15298] logger.c: – DBget: set variable AMPUSERCIDNAME to After Hours
May 12 10:31:57 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?5”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing SetCallerID(“SIP/400-e1da”, ““After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “Using CallerID “After Hours” <400>”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “record-enable|400|OUT”) in new stack
May 12 10:31:57 DEBUG[15298] pbx.c: Function result is '0’
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0 > 0?2:4”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:57 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “recordingcheck|20080512-103157|1210613517.0”) in new stack
May 12 10:31:57 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:31:58 VERBOSE[15298] logger.c: recordingcheck|20080512-103157|1210613517.0: Outbound recording not enabled
May 12 10:31:58 VERBOSE[15298] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “No recording needed”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “outbound-callerid|1”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing DBget(“SIP/400-e1da”, “USEROUTCID=AMPUSER/400/outboundcid”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=400/outboundcid
May 12 10:31:58 VERBOSE[15298] logger.c: – DBget: set variable USEROUTCID to
May 12 10:31:58 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?4”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:31:58 DEBUG[15298] pbx.c: Expression result is '1’
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “1?6”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing NoOp(“SIP/400-e1da”, “CallerID set to “After Hours” <400>”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing SetGroup(“SIP/400-e1da”, “OUT_1”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing CheckGroup(“SIP/400-e1da”, “”) in new stack
May 12 10:31:58 WARNING[15298] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_NUMBER=19495551212”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “DIAL_TRUNK=1”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing AGI(“SIP/400-e1da”, “fixlocalprefix”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:31:58 VERBOSE[15298] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:31:58 VERBOSE[15298] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing SetVar(“SIP/400-e1da”, “OUTNUM=19495551212”) in new stack
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing Cut(“SIP/400-e1da”, “custom=OUT_1|:|1”) in new stack
May 12 10:31:58 WARNING[15298] ast_expr2.y: non-numeric argument
May 12 10:31:58 DEBUG[15298] pbx.c: Expression result is '0’
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing GotoIf(“SIP/400-e1da”, “0?16”) in new stack
May 12 10:31:58 DEBUG[15298] pbx.c: Not taking any branch
May 12 10:31:58 VERBOSE[15298] logger.c: – Executing Dial(“SIP/400-e1da”, “ZAP/g0/19495551212”) in new stack
May 12 10:31:58 DEBUG[15298] chan_zap.c: Dialing '19495551212’
May 12 10:31:58 DEBUG[15298] chan_zap.c: Deferring dialing…
May 12 10:31:58 VERBOSE[15298] logger.c: – Called g0/19495551212
May 12 10:31:58 DEBUG[15298] chan_zap.c: Exception on 17, channel 1
May 12 10:31:58 DEBUG[15298] chan_zap.c: Got event Hook Transition Complete(12) on channel 1 (index 0)
May 12 10:31:59 DEBUG[15283] chan_sip.c: Setting NAT on RTP to 0
May 12 10:31:59 DEBUG[15283] chan_sip.c: Stopping retransmission on ‘19669cf9-fe47c2aa@localhost’ of Response 101: Match Found
May 12 10:31:59 DEBUG[15283] chan_sip.c: Setting NAT on RTP to 0
May 12 10:31:59 DEBUG[15283] chan_sip.c: Checking SIP call limits for device 300
May 12 10:31:59 DEBUG[15283] chan_sip.c: build_route: Contact hop: Anonymous sip:300@192.168.1.216:5060
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “dialout-trunk|3|9221212|”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?3:2)”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “user-callerid”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSER=DEVICE/300/user”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=300/user
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSER to 300
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSERCIDNAME=AMPUSER/300/cidname”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=300/cidname
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSERCIDNAME to Michael
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?5”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetCallerID(“SIP/300-1003”, ““Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “Using CallerID “Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “record-enable|300|OUT”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Function result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0 > 0?2:4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “recordingcheck|20080512-103159|1210613519.2”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:31:59 VERBOSE[15310] logger.c: recordingcheck|20080512-103159|1210613519.2: Outbound recording not enabled
May 12 10:31:59 VERBOSE[15310] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “No recording needed”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “outbound-callerid|3”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “USEROUTCID=AMPUSER/300/outboundcid”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=300/outboundcid
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable USEROUTCID to
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?6”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “CallerID set to “Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetGroup(“SIP/300-1003”, “OUT_3”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing CheckGroup(“SIP/300-1003”, “”) in new stack
May 12 10:31:59 WARNING[15310] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_NUMBER=9221212”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_TRUNK=3”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “fixlocalprefix”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:31:59 VERBOSE[15310] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:31:59 VERBOSE[15310] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “OUTNUM=9221212”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Cut(“SIP/300-1003”, “custom=OUT_3|:|1”) in new stack
May 12 10:31:59 WARNING[15310] ast_expr2.y: non-numeric argument
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?16”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Dial(“SIP/300-1003”, “ZAP/g3/9221212”) in new stack
May 12 10:31:59 NOTICE[15310] app_dial.c: Unable to create channel of type ‘ZAP’ (cause 0 - Unknown)
May 12 10:31:59 VERBOSE[15310] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
May 12 10:31:59 DEBUG[15310] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Goto(“SIP/300-1003”, “s-CHANUNAVAIL|1”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “Dial failed due to CHANUNAVAIL”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “dialout-trunk|2|9221212|”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?3:2)”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “user-callerid”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSER=DEVICE/300/user”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=300/user
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSER to 300
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSERCIDNAME=AMPUSER/300/cidname”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=300/cidname
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSERCIDNAME to Michael
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?5”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetCallerID(“SIP/300-1003”, ““Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “Using CallerID “Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “record-enable|300|OUT”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Function result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0 > 0?2:4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “recordingcheck|20080512-103159|1210613519.2”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:31:59 VERBOSE[15310] logger.c: recordingcheck|20080512-103159|1210613519.2: Outbound recording not enabled
May 12 10:31:59 VERBOSE[15310] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “No recording needed”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “outbound-callerid|2”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “USEROUTCID=AMPUSER/300/outboundcid”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=300/outboundcid
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable USEROUTCID to
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?6”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “CallerID set to “Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetGroup(“SIP/300-1003”, “OUT_2”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing CheckGroup(“SIP/300-1003”, “”) in new stack
May 12 10:31:59 WARNING[15310] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_NUMBER=9221212”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_TRUNK=2”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “fixlocalprefix”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:31:59 VERBOSE[15310] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:31:59 VERBOSE[15310] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “OUTNUM=9221212”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Cut(“SIP/300-1003”, “custom=OUT_2|:|1”) in new stack
May 12 10:31:59 WARNING[15310] ast_expr2.y: non-numeric argument
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?16”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Dial(“SIP/300-1003”, “ZAP/g2/9221212”) in new stack
May 12 10:31:59 NOTICE[15310] app_dial.c: Unable to create channel of type ‘ZAP’ (cause 0 - Unknown)
May 12 10:31:59 VERBOSE[15310] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
May 12 10:31:59 DEBUG[15310] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Goto(“SIP/300-1003”, “s-CHANUNAVAIL|1”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “Dial failed due to CHANUNAVAIL”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “dialout-trunk|4|9221212|”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?3:2)”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “user-callerid”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSER=DEVICE/300/user”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=300/user
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSER to 300
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSERCIDNAME=AMPUSER/300/cidname”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=300/cidname
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSERCIDNAME to Michael
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?5”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetCallerID(“SIP/300-1003”, ““Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “Using CallerID “Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “record-enable|300|OUT”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Function result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0 > 0?2:4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “recordingcheck|20080512-103159|1210613519.2”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:31:59 VERBOSE[15310] logger.c: recordingcheck|20080512-103159|1210613519.2: Outbound recording not enabled
May 12 10:31:59 VERBOSE[15310] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “No recording needed”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “outbound-callerid|4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “USEROUTCID=AMPUSER/300/outboundcid”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=300/outboundcid
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable USEROUTCID to
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?6”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “CallerID set to “Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetGroup(“SIP/300-1003”, “OUT_4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing CheckGroup(“SIP/300-1003”, “”) in new stack
May 12 10:31:59 WARNING[15310] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_NUMBER=9221212”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_TRUNK=4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “fixlocalprefix”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:31:59 VERBOSE[15310] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:31:59 VERBOSE[15310] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “OUTNUM=9221212”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Cut(“SIP/300-1003”, “custom=OUT_4|:|1”) in new stack
May 12 10:31:59 WARNING[15310] ast_expr2.y: non-numeric argument
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?16”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Dial(“SIP/300-1003”, “ZAP/g1/9221212”) in new stack
May 12 10:31:59 NOTICE[15310] app_dial.c: Unable to create channel of type ‘ZAP’ (cause 0 - Unknown)
May 12 10:31:59 VERBOSE[15310] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
May 12 10:31:59 DEBUG[15310] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Goto(“SIP/300-1003”, “s-CHANUNAVAIL|1”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “Dial failed due to CHANUNAVAIL”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “dialout-trunk|1|9221212|”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?3:2)”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-dialout-trunk,s,3)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “user-callerid”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSER=DEVICE/300/user”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSER, family=DEVICE, key=300/user
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSER to 300
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “AMPUSERCIDNAME=AMPUSER/300/cidname”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=300/cidname
May 12 10:31:59 VERBOSE[15310] logger.c: – DBget: set variable AMPUSERCIDNAME to Michael
May 12 10:31:59 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?5”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing SetCallerID(“SIP/300-1003”, ““Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “Using CallerID “Michael” <300>”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “record-enable|300|OUT”) in new stack
May 12 10:31:59 DEBUG[15310] pbx.c: Function result is '0’
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0 > 0?2:4”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Goto (macro-record-enable,s,4)
May 12 10:31:59 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “recordingcheck|20080512-103159|1210613519.2”) in new stack
May 12 10:31:59 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
May 12 10:32:00 VERBOSE[15310] logger.c: recordingcheck|20080512-103159|1210613519.2: Outbound recording not enabled
May 12 10:32:00 VERBOSE[15310] logger.c: – AGI Script recordingcheck completed, returning 0
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “No recording needed”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “outbound-callerid|1”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing DBget(“SIP/300-1003”, “USEROUTCID=AMPUSER/300/outboundcid”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – DBget: varname=USEROUTCID, family=AMPUSER, key=300/outboundcid
May 12 10:32:00 VERBOSE[15310] logger.c: – DBget: set variable USEROUTCID to
May 12 10:32:00 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?4”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,4)
May 12 10:32:00 DEBUG[15310] pbx.c: Expression result is '1’
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “1?6”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Goto (macro-outbound-callerid,s,6)
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing NoOp(“SIP/300-1003”, “CallerID set to “Michael” <300>”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing SetGroup(“SIP/300-1003”, “OUT_1”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing CheckGroup(“SIP/300-1003”, “”) in new stack
May 12 10:32:00 WARNING[15310] app_groupcount.c: CheckGroup requires an argument(max[@category][|options])
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_NUMBER=9221212”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “DIAL_TRUNK=1”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing AGI(“SIP/300-1003”, “fixlocalprefix”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
May 12 10:32:00 VERBOSE[15310] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf
May 12 10:32:00 VERBOSE[15310] logger.c: – AGI Script fixlocalprefix completed, returning 0
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing SetVar(“SIP/300-1003”, “OUTNUM=9221212”) in new stack
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing Cut(“SIP/300-1003”, “custom=OUT_1|:|1”) in new stack
May 12 10:32:00 WARNING[15310] ast_expr2.y: non-numeric argument
May 12 10:32:00 DEBUG[15310] pbx.c: Expression result is '0’
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing GotoIf(“SIP/300-1003”, “0?16”) in new stack
May 12 10:32:00 DEBUG[15310] pbx.c: Not taking any branch
May 12 10:32:00 VERBOSE[15310] logger.c: – Executing Dial(“SIP/300-1003”, “ZAP/g0/9221212”) in new stack
May 12 10:32:00 DEBUG[15310] chan_zap.c: Dialing ‘9221212’
May 12 10:32:00 DEBUG[15310] chan_zap.c: Deferring dialing…
May 12 10:32:00 VERBOSE[15310] logger.c: – Called g0/9221212
May 12 10:32:00 DEBUG[15298] chan_zap.c: Exception on 17, channel 1
May 12 10:32:00 DEBUG[15298] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0)
May 12 10:32:00 DEBUG[15298] chan_zap.c: No echo cancellation requested
May 12 10:32:00 DEBUG[15298] chan_zap.c: No echo training requested
May 12 10:32:00 DEBUG[15310] chan_zap.c: Exception on 19, channel 2
May 12 10:32:00 DEBUG[15310] chan_zap.c: Got event Hook Transition Complete(12) on channel 2 (index 0)
May 12 10:32:02 DEBUG[15310] chan_zap.c: Exception on 19, channel 2
May 12 10:32:02 DEBUG[15310] chan_zap.c: Got event Dial Complete(9) on channel 2 (index 0)
May 12 10:32:02 DEBUG[15310] chan_zap.c: No echo cancellation requested
May 12 10:32:02 DEBUG[15310] chan_zap.c: No echo training requested
May 12 10:32:03 DEBUG[15298] chan_zap.c: Exception on 17, channel 1
May 12 10:32:03 DEBUG[15298] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0)
May 12 10:32:03 DEBUG[15298] chan_zap.c: No echo cancellation requested
May 12 10:32:03 VERBOSE[15298] logger.c: – Zap/1-1 answered SIP/400-e1da
May 12 10:32:03 DEBUG[15283] chan_sip.c: Stopping retransmission on ‘a07e0d30-2674b7c8@localhost’ of Response 102: Match Found
May 12 10:32:03 DEBUG[15298] chan_sip.c: Oooh, format changed to 8
May 12 10:32:04 DEBUG[15310] chan_zap.c: Exception on 19, channel 2
May 12 10:32:04 DEBUG[15310] chan_zap.c: Got event Dial Complete(9) on channel 2 (index 0)
May 12 10:32:04 DEBUG[15310] chan_zap.c: No echo cancellation requested
May 12 10:32:04 VERBOSE[15310] logger.c: – Zap/2-1 answered SIP/300-1003
May 12 10:32:04 DEBUG[15283] chan_sip.c: Stopping retransmission on ‘19669cf9-fe47c2aa@localhost’ of Response 102: Match Found
May 12 10:32:04 DEBUG[15310] chan_sip.c: Oooh, format changed to 8
May 12 10:32:26 DEBUG[15310] channel.c: Didn’t get a frame from channel: SIP/300-1003
May 12 10:32:26 DEBUG[15310] channel.c: Bridge stops bridging channels SIP/300-1003 and Zap/2-1
May 12 10:32:26 DEBUG[15310] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1
May 12 10:32:26 DEBUG[15310] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1
May 12 10:32:26 DEBUG[15310] chan_zap.c: Updated conferencing on 2, with 0 conference users
May 12 10:32:26 VERBOSE[15310] logger.c: – Hungup ‘Zap/2-1’
May 12 10:32:26 DEBUG[15310] app_dial.c: Exiting with DIALSTATUS=ANSWER.
May 12 10:32:26 VERBOSE[15310] logger.c: == Spawn extension (macro-dialout-trunk, s, 14) exited non-zero on ‘SIP/300-1003’ in macro ‘dialout-trunk’
May 12 10:32:26 VERBOSE[15310] logger.c: == Spawn extension (from-internal, 9221212, 4) exited non-zero on ‘SIP/300-1003’
May 12 10:32:26 VERBOSE[15310] logger.c: – Executing Macro(“SIP/300-1003”, “hangupcall”) in new stack
May 12 10:32:26 VERBOSE[15310] logger.c: – Executing ResetCDR(“SIP/300-1003”, “w”) in new stack
May 12 10:32:26 DEBUG[15310] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
May 12 10:32:26 DEBUG[15310] 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 (‘2008-05-12 10:31:59’,’“Michael” <300>’,‘300’,‘9221212’,‘from-internal’, ‘SIP/300-1003’,‘Zap/2-1’,‘ResetCDR’,‘w’,27,22,‘ANSWERED’,3,’’)
May 12 10:32:26 VERBOSE[15310] logger.c: – Executing NoCDR(“SIP/300-1003”, “”) in new stack
May 12 10:32:26 WARNING[15310] cdr.c: CDR on channel ‘SIP/300-1003’ not posted
May 12 10:32:26 WARNING[15310] cdr.c: CDR on channel ‘SIP/300-1003’ lacks end
May 12 10:32:26 VERBOSE[15310] logger.c: – Executing Wait(“SIP/300-1003”, “5”) in new stack
May 12 10:32:26 VERBOSE[15310] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/300-1003’ in macro 'hangupcall’
May 12 10:32:26 VERBOSE[15310] logger.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/300-1003’
May 12 10:32:26 DEBUG[15310] chan_sip.c: update_call_counter(300) - decrement call limit counter
May 12 10:32:28 DEBUG[15298] channel.c: Didn’t get a frame from channel: SIP/400-e1da
May 12 10:32:28 DEBUG[15298] channel.c: Bridge stops bridging channels SIP/400-e1da and Zap/1-1
May 12 10:32:28 DEBUG[15298] chan_zap.c: Hangup: channel: 1 index = 0, normal = 17, callwait = -1, thirdcall = -1
May 12 10:32:28 DEBUG[15298] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
May 12 10:32:28 DEBUG[15298] chan_zap.c: Updated conferencing on 1, with 0 conference users
May 12 10:32:28 VERBOSE[15298] logger.c: – Hungup ‘Zap/1-1’
May 12 10:32:28 DEBUG[15298] app_dial.c: Exiting with DIALSTATUS=ANSWER.
May 12 10:32:28 VERBOSE[15298] logger.c: == Spawn extension (macro-dialout-trunk, s, 14) exited non-zero on ‘SIP/400-e1da’ in macro ‘dialout-trunk’
May 12 10:32:28 VERBOSE[15298] logger.c: == Spawn extension (from-internal, 19495551212, 4) exited non-zero on ‘SIP/400-e1da’
May 12 10:32:28 VERBOSE[15298] logger.c: – Executing Macro(“SIP/400-e1da”, “hangupcall”) in new stack
May 12 10:32:28 VERBOSE[15298] logger.c: – Executing ResetCDR(“SIP/400-e1da”, “w”) in new stack
May 12 10:32:28 DEBUG[15298] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
May 12 10:32:28 DEBUG[15298] 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 (‘2008-05-12 10:31:57’,’“After Hours” <400>’,‘400’,‘19495551212’,‘from-internal’, ‘SIP/400-e1da’,‘Zap/1-1’,‘ResetCDR’,‘w’,31,25,‘ANSWERED’,3,’’)
May 12 10:32:28 VERBOSE[15298] logger.c: – Executing NoCDR(“SIP/400-e1da”, “”) in new stack
May 12 10:32:28 WARNING[15298] cdr.c: CDR on channel ‘SIP/400-e1da’ not posted
May 12 10:32:28 WARNING[15298] cdr.c: CDR on channel ‘SIP/400-e1da’ lacks end
May 12 10:32:28 VERBOSE[15298] logger.c: – Executing Wait(“SIP/400-e1da”, “5”) in new stack
May 12 10:32:28 VERBOSE[15298] logger.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/400-e1da’ in macro 'hangupcall’
May 12 10:32:28 VERBOSE[15298] logger.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/400-e1da’
May 12 10:32:28 DEBUG[15298] chan_sip.c: update_call_counter(400) - decrement call limit counter
May 12 10:32:29 VERBOSE[15297] logger.c: Executing last minute cleanups
May 12 10:32:29 VERBOSE[15297] logger.c: == Destroying musiconhold processes
May 12 10:32:29 DEBUG[15297] res_musiconhold.c: killing 15280!
May 12 10:32:29 DEBUG[15297] res_musiconhold.c: mpg123 pid 15280 and child died after 2358784 bytes read
May 12 10:32:53 NOTICE[15344] cdr.c: CDR simple logging enabled.
May 12 10:32:53 WARNING[15344] res_musiconhold.c: The old musiconhold.conf syntax has been deprecated! Please refer to the sample configuration for information on the new syntax.
May 12 10:32:53 WARNING[15344] config.c: Unknown directive ‘parkingtime’ at line 9 of features.conf
May 12 10:32:53 ERROR[15344] res_config_mysql.c: MySQL RealTime: Failed to connect database server on . Check debug for more info.
May 12 10:32:53 WARNING[15344] res_config_mysql.c: MySQL RealTime: Couldn’t establish connection. Check debug.
May 12 10:32:53 NOTICE[15344] config.c: Registered Config Engine mysql
May 12 10:32:53 WARNING[15344] pbx_config.c: The use of '.’ for an extension is strongly discouraged and can have unexpected behavior. Please use ‘X.’ instead at line 28
May 12 10:32:53 WARNING[15344] pbx_config.c: The use of '.’ for an extension is strongly discouraged and can have un

2

Hi

im guessing you are using trix or freepbx, but what I can see is that its trying to use trung groups that are empty or dont exist.

what does the zapata.conf looklike ?

Ian

3

Hi Ian,

Thank you for your reply. I’m using AMP 1.10.010. The contents of the file requested are below. Please note that I didn’t change the configuration - one day it worked, the next day it didn’t. I never go on the box unless I have to for some reason (I’m afraid to break something that works!).

Through the AMP, I can see both trunks are defined. I am wondering if my hardware maybe went bad??

Regards,

Michael

;
; Zapata telephony interface
;
; Configuration file

[trunkgroups]

[channels]

language=en
context=from-pstn
rxwink=300 ; Atlas seems to use long (250ms) winks
;
; Whether or not to do distinctive ring detection on FXO lines
;
;usedistinctiveringdetection=yes

usecallerid=yes
hidecallerid=no
callwaiting=yes
usecallingpres=yes
callwaitingcallerid=yes
threewaycalling=yes
transfer=yes
cancallforward=yes
callreturn=yes
echocancel=no
echocancelwhenbridged=no
echotraining=800
rxgain=0.0
txgain=0.0
group=0
callgroup=1
pickupgroup=1
immediate=no

;faxdetect=both
faxdetect=incoming
;faxdetect=outgoing
;faxdetect=no

;Include genzaptelconf configs
#include zapata-auto.conf

;Include AMP configs
#include zapata_additional.conf

4

For additional info:

On Trunks, I have ZAP/g0, ZAP/g1, ZAP/g2, and ZAP/g3.

On Outbound Routing, I have “0 Outside”. Then, trunk sequence of ZAP/g0, ZAP/g1, ZAP/g2 and ZAP/g3. This is a different order from the log file because I changed it when I saw the g1/g2/g3 were failing.

I hope this helps.

Michael

5

why

by assigning a trunk to a trunk group means that for example you assign your trunks to 1,2,3,4 to group 1 then dial out via Zap/g1 then it will pick the next free trunk in the group.

6

Ian,

Not sure I understand your comment. I assume the trunks need to be in a trunk group. I only changed the ordering (which I can change back) as a measure of troubleshooting because it appeared from the log file that only g0 was being used. Again, I would hope that if g0 is used, then g1/2/3 will be attempted which is the way it worked until one magic day two weeks ago. Now, only one outbound line can be active at a time.

7

Maybe I need extra clarification. I have a normal phone hooked into the digium card (i don’t recall the fx/fo whatever terminology but I got the right cards). I then have three SIP phones in the office (for intra-company use - no SIP outside of our firewall). I have four POTS lines connected directly to the digium card. When a SIP line (e.g. ext 300 from the log file) attempts to dial out, it goes into the trunk group, then trunk group should pick available POTS line to place the call.

Regardless if I use the normal phone or the Sipura phones, when I go to dial out, only one active line at a time is being used. The phones don’t do anything (no busy signal, just dead silence). On the Sipora phones, the display says “Connected …” but this isn’t happening.

Any of the phones can work at any given time, as long as someone else isn’t already on an outbound call. If have two lines active from INBOUND calls then the first outbound caller can still get out.

Is this making sense?

Michael

8

Does anyone else have any other suggestions that I may follow or troubleshooting tips to help me isolate my problem?

Thanks,

Michael