Inbound Route - doesn't work for all calls

Hi all

I’ve just been put in charge of maintaining the Voip system for a company but due to my very limited knowledge of voip (and FreePBX) i have a very strange issue i hope someone can give me some clues to solving.

the company currently has a public phone number which has been set up as an inbound route. this goes through Time Condition -> Queue -> Ring Group -> Extension.

the problem i’m encountering is - if i call this public number with my mobile phone the call goes through. but when i call from a landline it doesn’t go through. it just goes into an endless ringing loop.

the even weirder thing is, it doesn’t work for ALL mobile phones - just some. and from what i can tell, it does not work for any landline whatsoever.

i hope to get very detailed troubleshooting guides (and a lot of patience) as i am completely new to this. i have been successful in adding extensions but this is totally different level for me.

thanks

you need to provide details and logs here for us to help.

What versions of things are you running (asterisk, FreePBX) distro or hand build? Distro version if it is a distro helps identify things as some limit functionality or enhance it.

how do the calls come in? trunk type and if it is SIP the provider please.

Next you’ll need to go into the asterisk CLI and type set verbose 5
this will increase the debug logging data. Next make a call that works and cut and paste the working call log.
Then make a call that does not work. and post that log also (labeling each please).

Without seeing that output and knowing what version of things you are running it is hard to help.

Without many of these details all we can do is guess, but with these we can read what is going on and help you in a good direction.

Ok here’s what i hope is enough details to get started:

I’m running FreePBX 2.5.0.1 with TrixBox. I’m not too sure if it’s a distro or handbuilt. i THINK it’s distro but is there a way i can find out?
not sure if this helps… i’ve taken this from TrixBox:
Asterisk 1.2.13 svn rev 47264 built by root @ localhost.localdomain on a i686 running Linux on 2006-12-31 19:02:30 UTC Verbosity is at least 5

can you let me know how i can find out how calls come in? I’m located in Australia so i’m not sure if the provider would be the same as what you guys get in the US.

THIS IS THE CALL LOG FOR THE CALL THAT WORKS:

FreePBX 2.5.0.1 on 10.2.16.240

Nov 12 09:27:05 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:05 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:06 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:06 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:07 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3081: Match Found
Nov 12 09:27:07 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:07 DEBUG[3518] chan_sip.c: Auto destroying call '10c3176eca8dc84a’
Nov 12 09:27:07 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:07 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 1640: Match Found
Nov 12 09:27:08 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:09 DEBUG[3518] chan_sip.c: Auto destroying call 'd2811151f982d81e’
Nov 12 09:27:09 VERBOSE[3522] logger.c: – Accepting call from ‘0433496396’ to ‘0292813999’ on channel 0/2, span 1
Nov 12 09:27:09 DEBUG[3522] chan_zap.c: Enabled echo cancellation on channel 2
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “__FROM_DID=0292813999”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Gosub(“Zap/2-1”, “app-blacklist-check|s|1”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing LookupBlacklist(“Zap/2-1”, “”) in new stack
Nov 12 09:27:09 DEBUG[6212] db.c: Unable to find key ‘0433496396’ in family 'blacklist’
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '0’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIf(“Zap/2-1”, “0?blacklisted”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Not taking any branch
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Return(“Zap/2-1”, “”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is ''
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '0’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIf(“Zap/2-1”, “0 ?cidok”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Not taking any branch
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “CALLERID(name)=0433496396”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '“0433496396” <0433496396>'
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing NoOp(“Zap/2-1”, “CallerID is “0433496396” <0433496396>”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “__CALLINGPRES_SV=allowed”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing SetCallerPres(“Zap/2-1”, “allowed_not_screened”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Goto(“Zap/2-1”, “timeconditions|4|1”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Goto (timeconditions,4,1)
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIfTime(“Zap/2-1”, “21:00-10:00|||*?ext-queues|400|1”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Goto (ext-queues,400,1)
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Macro(“Zap/2-1”, “user-callerid|”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '1’
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '0’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIf(“Zap/2-1”, “0?report”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Not taking any branch
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '1’
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing ExecIf(“Zap/2-1”, “1|Set|REALCALLERIDNUM=0433496396”) in new stack
Nov 12 09:27:09 DEBUG[6212] db.c: Unable to find key ‘0433496396/user’ in family 'DEVICE’
Nov 12 09:27:09 DEBUG[6212] func_db.c: DB: DEVICE/0433496396/user not found in database.
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is ''
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “AMPUSER=”) in new stack
Nov 12 09:27:09 DEBUG[6212] db.c: Unable to find key ‘/cidname’ in family 'AMPUSER’
Nov 12 09:27:09 DEBUG[6212] func_db.c: DB: AMPUSER//cidname not found in database.
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is ''
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “AMPUSERCIDNAME=”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '1’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIf(“Zap/2-1”, “1?report”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '0’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIf(“Zap/2-1”, “0?continue”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Not taking any branch
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '1’
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '-1’
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '64’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “__TTL=64”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '1’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIf(“Zap/2-1”, “1?continue”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '“0433496396” <0433496396>'
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing NoOp(“Zap/2-1”, “Using CallerID “0433496396” <0433496396>”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Answer(“Zap/2-1”, “”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “__BLKVM_OVERRIDE=BLKVM/400/Zap/2-1”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “__BLKVM_BASE=400”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “DB(BLKVM/400/Zap/2-1)=TRUE”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '0’
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '1’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing ExecIf(“Zap/2-1”, “1|Set|_DIAL_OPTIONS=trM(auto-blkvm)”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “__NODEST=400”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Expression result is '1’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing GotoIf(“Zap/2-1”, “1?REPCID”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Goto (ext-queues,400,13)
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing NoOp(“Zap/2-1”, “CALLERID(name) is 0433496396”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “_RGPREFIX=HS INFO”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “CALLERID(name)=HS INFO0433496396”) in new stack
Nov 12 09:27:09 DEBUG[6212] pbx.c: Function result is '20081111-222709’
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “MONITOR_FILENAME=/var/spool/asterisk/monitor/q400-20081111-222709-1226442429.26508”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Set(“Zap/2-1”, “__MOHCLASS=Harbourside”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Executing Queue(“Zap/2-1”, “400|t||”) in new stack
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Started music on hold, class ‘Harbourside’, on Zap/2-1
Nov 12 09:27:09 DEBUG[6212] channel.c: Scheduling timer at 160 sample intervals
Nov 12 09:27:09 VERBOSE[6212] logger.c: – Called Local/[email protected]/n
Nov 12 09:27:09 DEBUG[6212] channel.c: Generator got voice, switching to phase locked mode
Nov 12 09:27:09 DEBUG[6212] channel.c: Scheduling timer at 0 sample intervals
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Macro(“Local/[email protected],2”, “exten-vm|40|40”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is '0433496396’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?continue”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Not taking any branch
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '63’
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is '63’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “__TTL=63”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “RingGroupMethod=none”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “VMBOX=40”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “EXTTOCALL=40”) in new stack
Nov 12 09:27:09 DEBUG[6215] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:09 DEBUG[6215] func_db.c: DB: CFU/40 not found in database.
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is ''
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “CFUEXT=”) in new stack
Nov 12 09:27:09 DEBUG[6215] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:09 DEBUG[6215] func_db.c: DB: CFB/40 not found in database.
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is ''
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “CFBEXT=”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is '15’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “RT=15”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Macro(“Local/[email protected],2”, “record-enable|40|IN”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?check”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Goto (macro-record-enable,s,4)
Nov 12 09:27:09 DEBUG[6215] pbx.c: Function result is '20081111-222709’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing AGI(“Local/[email protected],2”, “recordingcheck|20081111-222709|1226442429.26510”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 12 09:27:09 VERBOSE[6215] logger.c: recordingcheck|20081111-222709|1226442429.26510: Inbound recording not enabled
Nov 12 09:27:09 VERBOSE[6215] logger.c: – AGI Script recordingcheck completed, returning 0
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing MacroExit(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing Macro(“Local/[email protected],2”, “dial|15|trM(auto-blkvm)|40”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?dial”) in new stack
Nov 12 09:27:09 DEBUG[6215] pbx.c: Not taking any branch
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing SetMusicOnHold(“Local/[email protected],2”, “Harbourside”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Executing AGI(“Local/[email protected],2”, “dialparties.agi”) in new stack
Nov 12 09:27:09 VERBOSE[6215] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Nov 12 09:27:10 VERBOSE[6215] logger.c: dialparties.agi: Starting New Dialparties.agi
Nov 12 09:27:10 DEBUG[6219] manager.c: Manager received command 'login’
Nov 12 09:27:10 VERBOSE[6219] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:10 VERBOSE[6219] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:10 VERBOSE[6219] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:10 VERBOSE[6219] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:10 VERBOSE[6219] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:10 VERBOSE[6219] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:10 DEBUG[6219] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:10 DEBUG[6219] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:10 DEBUG[6219] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:10 DEBUG[6219] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:10 VERBOSE[6219] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:10 VERBOSE[6215] logger.c: dialparties.agi: Caller ID name is ‘HS INFO0433496396’ number is '0433496396’
Nov 12 09:27:10 VERBOSE[6215] logger.c: dialparties.agi: USE_CONFIRMATION: 'FALSE’
Nov 12 09:27:10 VERBOSE[6215] logger.c: dialparties.agi: RINGGROUP_INDEX: ''
Nov 12 09:27:10 VERBOSE[6215] logger.c: dialparties.agi: Methodology of ring is 'none’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – dialparties.agi: Added extension 40 to extension map
Nov 12 09:27:10 DEBUG[6215] db.c: Unable to find key ‘40/screen’ in family 'AMPUSER’
Nov 12 09:27:10 VERBOSE[6215] logger.c: > dialparties.agi: Extension 40 has call screening off
Nov 12 09:27:10 DEBUG[6215] db.c: Unable to find key ‘40’ in family 'CF’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – dialparties.agi: Extension 40 cf is disabled
Nov 12 09:27:10 DEBUG[6215] db.c: Unable to find key ‘40’ in family 'DND’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – dialparties.agi: Extension 40 do not disturb is disabled
Nov 12 09:27:10 DEBUG[6215] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:10 DEBUG[6215] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:10 VERBOSE[6215] logger.c: > dialparties.agi: extnum 40 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Nov 12 09:27:10 DEBUG[6219] manager.c: Manager received command 'ExtensionState’
Nov 12 09:27:10 VERBOSE[6215] logger.c: > dialparties.agi: ExtensionState: 4
Nov 12 09:27:10 VERBOSE[6215] logger.c: – dialparties.agi: dbset CALLTRACE/40 to 0433496396
Nov 12 09:27:10 VERBOSE[6215] logger.c: – dialparties.agi: Filtered ARG3: 40
Nov 12 09:27:10 VERBOSE[6215] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:10 VERBOSE[6215] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:10 DEBUG[6219] manager.c: Manager received command 'Logoff’
Nov 12 09:27:10 VERBOSE[6219] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:10 VERBOSE[6215] logger.c: – AGI Script dialparties.agi completed, returning 0
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Dial(“Local/[email protected],2”, “SIP/40|15|trM(auto-blkvm)”) in new stack
Nov 12 09:27:10 NOTICE[6215] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
Nov 12 09:27:10 VERBOSE[6215] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Nov 12 09:27:10 DEBUG[6215] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Function result is 'CHANUNAVAIL’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?CHANUNAVAIL|1”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?exit|return”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Not taking any branch
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfu|1”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfb|1”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing NoOp(“Local/[email protected],2”, “Voicemail is 40”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?s-CHANUNAVAIL|1”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Not taking any branch
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing NoOp(“Local/[email protected],2”, “Sending to Voicemail box 40”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Macro(“Local/[email protected],2”, “vm|40|CHANUNAVAIL|”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid|SKIPTTL”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Function result is '0433496396’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Function result is '0433496396’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected]nternal-f2db,2”, “1?continue”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:10 DEBUG[6215] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '0’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Function result is ''
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Set(“Local/[email protected],2”, “VMGAIN=”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Function result is ‘TRUE’
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is ‘0’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?vmx|1”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Not taking any branch
Nov 12 09:27:10 WARNING[6215] func_db.c: DB requires an argument, DB(/)
Nov 12 09:27:10 DEBUG[6215] pbx.c: Function result is ‘‘
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing NoOp(“Local/[email protected],2”, "CAME FROM: 400 - Blocking VM cause of key: ") in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Goto(“Local/[email protected],2”, “vmret|1”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Goto (from-internal,vmret,1)
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is ‘0’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?playret”) in new stack
Nov 12 09:27:10 DEBUG[6215] pbx.c: Not taking any branch
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: == Spawn extension (from-internal, vmret, 2) exited non-zero on ‘Local/[email protected],2’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Macro(“Local/[email protected],2”, “hangupcall”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing ResetCDR(“Local/[email protected],2”, “w”) in new stack
Nov 12 09:27:10 DEBUG[6215] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:27:10 DEBUG[6215] 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 (‘2008-11-12 09:27:09’,’“HS INFO0433496396” <0433496396>’,‘0433496396’,‘vmret’,‘from-internal’, ‘Local/[email protected],2’,’’,‘ResetCDR’,‘w’,1,0,‘FAILED’,3,’’,‘1226442429.26510’)
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing NoCDR(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:10 WARNING[6215] cdr.c: CDR on channel ‘Local/[email protected],2’ not posted
Nov 12 09:27:10 WARNING[6215] cdr.c: CDR on channel ‘Local/[email protected],2’ lacks end
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skiprg”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skipblkvm”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:27:10 DEBUG[6215] pbx.c: Expression result is '1’
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?theend”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:27:10 VERBOSE[6215] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:10 VERBOSE[6215] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’ in macro 'hangupcall’
Nov 12 09:27:10 VERBOSE[6215] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/[email protected],2’
Nov 12 09:27:10 NOTICE[6212] app_queue.c: No one is answering queue ‘400’ (1/0/0)
Nov 12 09:27:10 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:11 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:11 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:12 VERBOSE[6212] logger.c: – Called Local/[email protected]/n
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Macro(“Local/[email protected],2”, “exten-vm|40|40”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '0433496396’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '0433496396’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?continue”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Not taking any branch
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '63’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '63’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “__TTL=63”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “RingGroupMethod=none”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “VMBOX=40”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “EXTTOCALL=40”) in new stack
Nov 12 09:27:12 DEBUG[6225] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:12 DEBUG[6225] func_db.c: DB: CFU/40 not found in database.
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is ''
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “CFUEXT=”) in new stack
Nov 12 09:27:12 DEBUG[6225] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:12 DEBUG[6225] func_db.c: DB: CFB/40 not found in database.
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is ''
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “CFBEXT=”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '15’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “RT=15”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Macro(“Local/[email protected],2”, “record-enable|40|IN”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?check”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-record-enable,s,4)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '20081111-222712’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing AGI(“Local/[email protected],2”, “recordingcheck|20081111-222712|1226442432.26512”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 12 09:27:12 VERBOSE[6225] logger.c: recordingcheck|20081111-222712|1226442432.26512: Inbound recording not enabled
Nov 12 09:27:12 VERBOSE[6225] logger.c: – AGI Script recordingcheck completed, returning 0
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing MacroExit(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Macro(“Local/[email protected],2”, “dial|15|trM(auto-blkvm)|40”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?dial”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Not taking any branch
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing SetMusicOnHold(“Local/[email protected],2”, “Harbourside”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing AGI(“Local/[email protected],2”, “dialparties.agi”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Nov 12 09:27:12 VERBOSE[6225] logger.c: dialparties.agi: Starting New Dialparties.agi
Nov 12 09:27:12 DEBUG[6228] manager.c: Manager received command 'login’
Nov 12 09:27:12 VERBOSE[6228] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:12 VERBOSE[6228] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:12 VERBOSE[6228] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:12 VERBOSE[6228] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:12 VERBOSE[6228] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:12 VERBOSE[6228] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:12 DEBUG[6228] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:12 DEBUG[6228] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:12 DEBUG[6228] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:12 DEBUG[6228] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:12 VERBOSE[6228] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:12 VERBOSE[6225] logger.c: dialparties.agi: Caller ID name is ‘HS INFO0433496396’ number is '0433496396’
Nov 12 09:27:12 VERBOSE[6225] logger.c: dialparties.agi: USE_CONFIRMATION: 'FALSE’
Nov 12 09:27:12 VERBOSE[6225] logger.c: dialparties.agi: RINGGROUP_INDEX: ''
Nov 12 09:27:12 VERBOSE[6225] logger.c: dialparties.agi: Methodology of ring is 'none’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – dialparties.agi: Added extension 40 to extension map
Nov 12 09:27:12 DEBUG[6225] db.c: Unable to find key ‘40/screen’ in family 'AMPUSER’
Nov 12 09:27:12 VERBOSE[6225] logger.c: > dialparties.agi: Extension 40 has call screening off
Nov 12 09:27:12 DEBUG[6225] db.c: Unable to find key ‘40’ in family 'CF’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – dialparties.agi: Extension 40 cf is disabled
Nov 12 09:27:12 DEBUG[6225] db.c: Unable to find key ‘40’ in family 'DND’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – dialparties.agi: Extension 40 do not disturb is disabled
Nov 12 09:27:12 DEBUG[6225] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:12 DEBUG[6225] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:12 VERBOSE[6225] logger.c: > dialparties.agi: extnum 40 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Nov 12 09:27:12 DEBUG[6228] manager.c: Manager received command 'ExtensionState’
Nov 12 09:27:12 VERBOSE[6225] logger.c: > dialparties.agi: ExtensionState: 4
Nov 12 09:27:12 VERBOSE[6225] logger.c: – dialparties.agi: dbset CALLTRACE/40 to 0433496396
Nov 12 09:27:12 VERBOSE[6225] logger.c: – dialparties.agi: Filtered ARG3: 40
Nov 12 09:27:12 VERBOSE[6225] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:12 VERBOSE[6225] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:12 DEBUG[6228] manager.c: Manager received command 'Logoff’
Nov 12 09:27:12 VERBOSE[6228] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:12 VERBOSE[6225] logger.c: – AGI Script dialparties.agi completed, returning 0
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Dial(“Local/[email protected],2”, “SIP/40|15|trM(auto-blkvm)”) in new stack
Nov 12 09:27:12 NOTICE[6225] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
Nov 12 09:27:12 VERBOSE[6225] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Nov 12 09:27:12 DEBUG[6225] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is 'CHANUNAVAIL’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?CHANUNAVAIL|1”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?exit|return”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Not taking any branch
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfu|1”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfb|1”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing NoOp(“Local/[email protected]from-internal-5137,2”, “Voicemail is 40”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?s-CHANUNAVAIL|1”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Not taking any branch
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing NoOp(“Local/[email protected],2”, “Sending to Voicemail box 40”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Macro(“Local/[email protected],2”, “vm|40|CHANUNAVAIL|”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid|SKIPTTL”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '0433496396’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '0433496396’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '0’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is ''
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Set(“Local/[email protected],2”, “VMGAIN=”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is ‘TRUE’
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is ‘0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?vmx|1”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Not taking any branch
Nov 12 09:27:12 WARNING[6225] func_db.c: DB requires an argument, DB(/)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Function result is ‘‘
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing NoOp(“Local/[email protected],2”, "CAME FROM: 400 - Blocking VM cause of key: ") in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Goto(“Local/[email protected],2”, “vmret|1”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (from-internal,vmret,1)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is ‘0’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?playret”) in new stack
Nov 12 09:27:12 DEBUG[6225] pbx.c: Not taking any branch
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: == Spawn extension (from-internal, vmret, 2) exited non-zero on ‘Local/[email protected],2’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Macro(“Local/[email protected],2”, “hangupcall”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing ResetCDR(“Local/[email protected],2”, “w”) in new stack
Nov 12 09:27:12 DEBUG[6225] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:27:12 DEBUG[6225] 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 (‘2008-11-12 09:27:12’,’“HS INFO0433496396” <0433496396>’,‘0433496396’,‘vmret’,‘from-internal’, ‘Local/[email protected],2’,’’,‘ResetCDR’,‘w’,0,0,‘FAILED’,3,’’,‘1226442432.26512’)
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing NoCDR(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:12 WARNING[6225] cdr.c: CDR on channel ‘Local/[email protected],2’ not posted
Nov 12 09:27:12 WARNING[6225] cdr.c: CDR on channel ‘Local/[email protected],2’ lacks end
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skiprg”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skipblkvm”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:27:12 DEBUG[6225] pbx.c: Expression result is '1’
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?theend”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:27:12 VERBOSE[6225] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:12 VERBOSE[6225] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’ in macro 'hangupcall’
Nov 12 09:27:12 VERBOSE[6225] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/[email protected],2’
Nov 12 09:27:12 NOTICE[6212] app_queue.c: No one is answering queue ‘400’ (1/0/0)
Nov 12 09:27:12 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:12 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:14 VERBOSE[6212] logger.c: – Called Local/[email protected]/n
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Macro(“Local/[email protected],2”, “exten-vm|40|40”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '0433496396’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '0433496396’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?continue”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Not taking any branch
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '63’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '63’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “__TTL=63”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “RingGroupMethod=none”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “VMBOX=40”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “EXTTOCALL=40”) in new stack
Nov 12 09:27:14 DEBUG[6231] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:14 DEBUG[6231] func_db.c: DB: CFU/40 not found in database.
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is ''
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “CFUEXT=”) in new stack
Nov 12 09:27:14 DEBUG[6231] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:14 DEBUG[6231] func_db.c: DB: CFB/40 not found in database.
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is ''
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “CFBEXT=”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '15’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “RT=15”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Macro(“Local/[email protected],2”, “record-enable|40|IN”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?check”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-record-enable,s,4)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '20081111-222714’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing AGI(“Local/[email protected],2”, “recordingcheck|20081111-222714|1226442434.26514”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 12 09:27:14 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:14 VERBOSE[6231] logger.c: recordingcheck|20081111-222714|1226442434.26514: Inbound recording not enabled
Nov 12 09:27:14 VERBOSE[6231] logger.c: – AGI Script recordingcheck completed, returning 0
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing MacroExit(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Macro(“Local/[email protected],2”, “dial|15|trM(auto-blkvm)|40”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?dial”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Not taking any branch
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing SetMusicOnHold(“Local/[email protected],2”, “Harbourside”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing AGI(“Local/[email protected],2”, “dialparties.agi”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Nov 12 09:27:14 VERBOSE[6231] logger.c: dialparties.agi: Starting New Dialparties.agi
Nov 12 09:27:14 DEBUG[6235] manager.c: Manager received command 'login’
Nov 12 09:27:14 VERBOSE[6235] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:14 VERBOSE[6235] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:14 VERBOSE[6235] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:14 VERBOSE[6235] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:14 VERBOSE[6235] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:14 VERBOSE[6235] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:14 DEBUG[6235] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:14 DEBUG[6235] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:14 DEBUG[6235] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:14 DEBUG[6235] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:14 VERBOSE[6235] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:14 VERBOSE[6231] logger.c: dialparties.agi: Caller ID name is ‘HS INFO0433496396’ number is '0433496396’
Nov 12 09:27:14 VERBOSE[6231] logger.c: dialparties.agi: USE_CONFIRMATION: 'FALSE’
Nov 12 09:27:14 VERBOSE[6231] logger.c: dialparties.agi: RINGGROUP_INDEX: ''
Nov 12 09:27:14 VERBOSE[6231] logger.c: dialparties.agi: Methodology of ring is 'none’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – dialparties.agi: Added extension 40 to extension map
Nov 12 09:27:14 DEBUG[6231] db.c: Unable to find key ‘40/screen’ in family 'AMPUSER’
Nov 12 09:27:14 VERBOSE[6231] logger.c: > dialparties.agi: Extension 40 has call screening off
Nov 12 09:27:14 DEBUG[6231] db.c: Unable to find key ‘40’ in family 'CF’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – dialparties.agi: Extension 40 cf is disabled
Nov 12 09:27:14 DEBUG[6231] db.c: Unable to find key ‘40’ in family 'DND’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – dialparties.agi: Extension 40 do not disturb is disabled
Nov 12 09:27:14 DEBUG[6231] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:14 DEBUG[6231] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:14 VERBOSE[6231] logger.c: > dialparties.agi: extnum 40 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Nov 12 09:27:14 DEBUG[6235] manager.c: Manager received command 'ExtensionState’
Nov 12 09:27:14 VERBOSE[6231] logger.c: > dialparties.agi: ExtensionState: 4
Nov 12 09:27:14 VERBOSE[6231] logger.c: – dialparties.agi: dbset CALLTRACE/40 to 0433496396
Nov 12 09:27:14 VERBOSE[6231] logger.c: – dialparties.agi: Filtered ARG3: 40
Nov 12 09:27:14 VERBOSE[6231] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:14 VERBOSE[6231] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:14 DEBUG[6235] manager.c: Manager received command 'Logoff’
Nov 12 09:27:14 VERBOSE[6235] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:14 VERBOSE[6231] logger.c: – AGI Script dialparties.agi completed, returning 0
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Dial(“Local/[email protected],2”, “SIP/40|15|trM(auto-blkvm)”) in new stack
Nov 12 09:27:14 NOTICE[6231] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
Nov 12 09:27:14 VERBOSE[6231] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Nov 12 09:27:14 DEBUG[6231] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is 'CHANUNAVAIL’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?CHANUNAVAIL|1”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?exit|return”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Not taking any branch
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfu|1”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfb|1”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing NoOp(“Local/[email protected],2”, “Voicemail is 40”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?s-CHANUNAVAIL|1”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Not taking any branch
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing NoOp(“Local/[email protected],2”, “Sending to Voicemail box 40”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Macro(“Local/[email protected],2”, “vm|40|CHANUNAVAIL|”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid|SKIPTTL”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '0433496396’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '0433496396’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '0’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is ''
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Set(“Local/[email protected],2”, “VMGAIN=”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is ‘TRUE’
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is ‘0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?vmx|1”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Not taking any branch
Nov 12 09:27:14 WARNING[6231] func_db.c: DB requires an argument, DB(/)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Function result is ‘‘
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing NoOp(“Local/[email protected],2”, "CAME FROM: 400 - Blocking VM cause of key: ") in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Goto(“Local/[email protected],2”, “vmret|1”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (from-internal,vmret,1)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is ‘0’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?playret”) in new stack
Nov 12 09:27:14 DEBUG[6231] pbx.c: Not taking any branch
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: == Spawn extension (from-internal, vmret, 2) exited non-zero on ‘Local/[email protected],2’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Macro(“Local/[email protected],2”, “hangupcall”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing ResetCDR(“Local/[email protected],2”, “w”) in new stack
Nov 12 09:27:14 DEBUG[6231] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:27:14 DEBUG[6231] 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 (‘2008-11-12 09:27:14’,’“HS INFO0433496396” <0433496396>’,‘0433496396’,‘vmret’,‘from-internal’, ‘Local/[email protected],2’,’’,‘ResetCDR’,‘w’,0,0,‘FAILED’,3,’’,‘1226442434.26514’)
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing NoCDR(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:14 WARNING[6231] cdr.c: CDR on channel ‘Local/[email protected],2’ not posted
Nov 12 09:27:14 WARNING[6231] cdr.c: CDR on channel ‘Local/[email protected],2’ lacks end
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skiprg”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skipblkvm”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:27:14 DEBUG[6231] pbx.c: Expression result is '1’
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?theend”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:27:14 VERBOSE[6231] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:14 VERBOSE[6231] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’ in macro 'hangupcall’
Nov 12 09:27:14 VERBOSE[6231] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/[email protected],2’
Nov 12 09:27:14 NOTICE[6212] app_queue.c: No one is answering queue ‘400’ (1/0/0)
Nov 12 09:27:16 VERBOSE[6212] logger.c: – Called Local/[email protected]/n
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Macro(“Local/[email protected],2”, “exten-vm|40|40”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is '0433496396’
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is '0433496396’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?continue”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Not taking any branch
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '63’
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is '63’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “__TTL=63”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “RingGroupMethod=none”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “VMBOX=40”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “EXTTOCALL=40”) in new stack
Nov 12 09:27:16 DEBUG[6241] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:16 DEBUG[6241] func_db.c: DB: CFU/40 not found in database.
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is ''
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “CFUEXT=”) in new stack
Nov 12 09:27:16 DEBUG[6241] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:16 DEBUG[6241] func_db.c: DB: CFB/40 not found in database.
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is ''
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “CFBEXT=”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is '15’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “RT=15”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Macro(“Local/[email protected],2”, “record-enable|40|IN”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?check”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Goto (macro-record-enable,s,4)
Nov 12 09:27:16 DEBUG[6241] pbx.c: Function result is '20081111-222716’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing AGI(“Local/[email protected],2”, “recordingcheck|20081111-222716|1226442436.26516”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 12 09:27:16 VERBOSE[6241] logger.c: recordingcheck|20081111-222716|1226442436.26516: Inbound recording not enabled
Nov 12 09:27:16 VERBOSE[6241] logger.c: – AGI Script recordingcheck completed, returning 0
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing MacroExit(“Local/[email protected]1f2,2”, “”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing Macro(“Local/[email protected],2”, “dial|15|trM(auto-blkvm)|40”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?dial”) in new stack
Nov 12 09:27:16 DEBUG[6241] pbx.c: Not taking any branch
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing SetMusicOnHold(“Local/[email protected],2”, “Harbourside”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Executing AGI(“Local/[email protected],2”, “dialparties.agi”) in new stack
Nov 12 09:27:16 VERBOSE[6241] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Nov 12 09:27:16 VERBOSE[6241] logger.c: dialparties.agi: Starting New Dialparties.agi
Nov 12 09:27:16 DEBUG[6245] manager.c: Manager received command 'login’
Nov 12 09:27:16 VERBOSE[6245] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:16 VERBOSE[6245] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:16 VERBOSE[6245] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:16 VERBOSE[6245] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:16 VERBOSE[6245] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:16 VERBOSE[6245] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:16 DEBUG[6245] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:16 DEBUG[6245] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:16 DEBUG[6245] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:16 DEBUG[6245] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:16 VERBOSE[6245] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:16 VERBOSE[6241] logger.c: dialparties.agi: Caller ID name is ‘HS INFO0433496396’ number is '0433496396’
Nov 12 09:27:16 VERBOSE[6241] logger.c: dialparties.agi: USE_CONFIRMATION: 'FALSE’
Nov 12 09:27:16 VERBOSE[6241] logger.c: dialparties.agi: RINGGROUP_INDEX: ''
Nov 12 09:27:16 VERBOSE[6241] logger.c: dialparties.agi: Methodology of ring is 'none’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – dialparties.agi: Added extension 40 to extension map
Nov 12 09:27:16 DEBUG[6241] db.c: Unable to find key ‘40/screen’ in family 'AMPUSER’
Nov 12 09:27:16 VERBOSE[6241] logger.c: > dialparties.agi: Extension 40 has call screening off
Nov 12 09:27:16 DEBUG[6241] db.c: Unable to find key ‘40’ in family 'CF’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – dialparties.agi: Extension 40 cf is disabled
Nov 12 09:27:16 DEBUG[6241] db.c: Unable to find key ‘40’ in family 'DND’
Nov 12 09:27:16 VERBOSE[6241] logger.c: – dialparties.agi: Extension 40 do not disturb is disabled
Nov 12 09:27:16 DEBUG[6241] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:16 DEBUG[6241] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:16 VERBOSE[6241] logger.c: > dialparties.agi: extnum 40 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Nov 12 09:27:16 DEBUG[6245] manager.c: Manager received command 'ExtensionState’
Nov 12 09:27:16 VERBOSE[6241] logger.c: > dialparties.agi: ExtensionState: 4
Nov 12 09:27:16 VERBOSE[6241] logger.c: – dialparties.agi: dbset CALLTRACE/40 to 0433496396
Nov 12 09:27:16 VERBOSE[6241] logger.c: – dialparties.agi: Filtered ARG3: 40
Nov 12 09:27:16 VERBOSE[6241] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:16 VERBOSE[6241] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:16 DEBUG[6245] manager.c: Manager received command 'Logoff’
Nov 12 09:27:16 VERBOSE[6245] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:17 VERBOSE[6241] logger.c: – AGI Script dialparties.agi completed, returning 0
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Dial(“Local/[email protected],2”, “SIP/40|15|trM(auto-blkvm)”) in new stack
Nov 12 09:27:17 NOTICE[6241] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
Nov 12 09:27:17 VERBOSE[6241] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Nov 12 09:27:17 DEBUG[6241] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Function result is 'CHANUNAVAIL’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?CHANUNAVAIL|1”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?exit|return”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Not taking any branch
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfu|1”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfb|1”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing NoOp(“Local/[email protected],2”, “Voicemail is 40”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?s-CHANUNAVAIL|1”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Not taking any branch
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing NoOp(“Local/[email protected],2”, “Sending to Voicemail box 40”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Macro(“Local/[email protected],2”, “vm|40|CHANUNAVAIL|”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid|SKIPTTL”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Function result is '0433496396’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Function result is '0433496396’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:17 DEBUG[6241] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '0’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Function result is ''
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Set(“Local/[email protected],2”, “VMGAIN=”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Function result is ‘TRUE’
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is ‘0’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?vmx|1”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Not taking any branch
Nov 12 09:27:17 WARNING[6241] func_db.c: DB requires an argument, DB(/)
Nov 12 09:27:17 DEBUG[6241] pbx.c: Function result is ‘‘
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing NoOp(“Local/[email protected],2”, "CAME FROM: 400 - Blocking VM cause of key: ") in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Goto(“Local/[email protected],2”, “vmret|1”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Goto (from-internal,vmret,1)
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is ‘0’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?playret”) in new stack
Nov 12 09:27:17 DEBUG[6241] pbx.c: Not taking any branch
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: == Spawn extension (from-internal, vmret, 2) exited non-zero on ‘Local/[email protected],2’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Macro(“Local/[email protected],2”, “hangupcall”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing ResetCDR(“Local/[email protected],2”, “w”) in new stack
Nov 12 09:27:17 DEBUG[6241] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:27:17 DEBUG[6241] 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 (‘2008-11-12 09:27:16’,’“HS INFO0433496396” <0433496396>’,‘0433496396’,‘vmret’,‘from-internal’, ‘Local/[email protected],2’,’’,‘ResetCDR’,‘w’,1,0,‘FAILED’,3,’’,‘1226442436.26516’)
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing NoCDR(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:17 WARNING[6241] cdr.c: CDR on channel ‘Local/[email protected],2’ not posted
Nov 12 09:27:17 WARNING[6241] cdr.c: CDR on channel ‘Local/[email protected],2’ lacks end
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skiprg”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skipblkvm”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:27:17 DEBUG[6241] pbx.c: Expression result is '1’
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?theend”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:27:17 VERBOSE[6241] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:17 VERBOSE[6241] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’ in macro 'hangupcall’
Nov 12 09:27:17 VERBOSE[6241] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/[email protected],2’
Nov 12 09:27:17 NOTICE[6212] app_queue.c: No one is answering queue ‘400’ (1/0/0)
Nov 12 09:27:18 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:18 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:18 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:18 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:18 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:18 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:19 VERBOSE[6212] logger.c: – Called Local/[email protected]/n
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Macro(“Local/[email protected],2”, “exten-vm|40|40”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '0433496396’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '0433496396’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?continue”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Not taking any branch
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '63’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '63’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “__TTL=63”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “RingGroupMethod=none”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “VMBOX=40”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “EXTTOCALL=40”) in new stack
Nov 12 09:27:19 DEBUG[6249] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:19 DEBUG[6249] func_db.c: DB: CFU/40 not found in database.
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is ''
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “CFUEXT=”) in new stack
Nov 12 09:27:19 DEBUG[6249] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:19 DEBUG[6249] func_db.c: DB: CFB/40 not found in database.
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is ''
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “CFBEXT=”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '15’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “RT=15”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Macro(“Local/[email protected],2”, “record-enable|40|IN”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?check”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-record-enable,s,4)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '20081111-222719’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing AGI(“Local/[email protected],2”, “recordingcheck|20081111-222719|1226442439.26518”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 12 09:27:19 VERBOSE[6249] logger.c: recordingcheck|20081111-222719|1226442439.26518: Inbound recording not enabled
Nov 12 09:27:19 VERBOSE[6249] logger.c: – AGI Script recordingcheck completed, returning 0
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing MacroExit(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Macro(“Local/[email protected],2”, “dial|15|trM(auto-blkvm)|40”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?dial”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Not taking any branch
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing SetMusicOnHold(“Local/[email protected],2”, “Harbourside”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing AGI(“Local/[email protected],2”, “dialparties.agi”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Nov 12 09:27:19 VERBOSE[6249] logger.c: dialparties.agi: Starting New Dialparties.agi
Nov 12 09:27:19 DEBUG[6253] manager.c: Manager received command 'login’
Nov 12 09:27:19 VERBOSE[6253] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:19 VERBOSE[6253] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:19 VERBOSE[6253] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:19 VERBOSE[6253] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:19 VERBOSE[6253] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:19 VERBOSE[6253] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:19 DEBUG[6253] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:19 DEBUG[6253] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:19 DEBUG[6253] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:19 DEBUG[6253] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:19 VERBOSE[6253] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:19 VERBOSE[6249] logger.c: dialparties.agi: Caller ID name is ‘HS INFO0433496396’ number is '0433496396’
Nov 12 09:27:19 VERBOSE[6249] logger.c: dialparties.agi: USE_CONFIRMATION: 'FALSE’
Nov 12 09:27:19 VERBOSE[6249] logger.c: dialparties.agi: RINGGROUP_INDEX: ''
Nov 12 09:27:19 VERBOSE[6249] logger.c: dialparties.agi: Methodology of ring is 'none’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – dialparties.agi: Added extension 40 to extension map
Nov 12 09:27:19 DEBUG[6249] db.c: Unable to find key ‘40/screen’ in family 'AMPUSER’
Nov 12 09:27:19 VERBOSE[6249] logger.c: > dialparties.agi: Extension 40 has call screening off
Nov 12 09:27:19 DEBUG[6249] db.c: Unable to find key ‘40’ in family 'CF’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – dialparties.agi: Extension 40 cf is disabled
Nov 12 09:27:19 DEBUG[6249] db.c: Unable to find key ‘40’ in family 'DND’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – dialparties.agi: Extension 40 do not disturb is disabled
Nov 12 09:27:19 DEBUG[6249] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:19 DEBUG[6249] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:19 VERBOSE[6249] logger.c: > dialparties.agi: extnum 40 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Nov 12 09:27:19 DEBUG[6253] manager.c: Manager received command 'ExtensionState’
Nov 12 09:27:19 VERBOSE[6249] logger.c: > dialparties.agi: ExtensionState: 4
Nov 12 09:27:19 VERBOSE[6249] logger.c: – dialparties.agi: dbset CALLTRACE/40 to 0433496396
Nov 12 09:27:19 VERBOSE[6249] logger.c: – dialparties.agi: Filtered ARG3: 40
Nov 12 09:27:19 VERBOSE[6249] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:19 VERBOSE[6249] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:19 DEBUG[6253] manager.c: Manager received command 'Logoff’
Nov 12 09:27:19 VERBOSE[6253] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:19 VERBOSE[6249] logger.c: – AGI Script dialparties.agi completed, returning 0
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Dial(“Local/[email protected],2”, “SIP/40|15|trM(auto-blkvm)”) in new stack
Nov 12 09:27:19 NOTICE[6249] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
Nov 12 09:27:19 VERBOSE[6249] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Nov 12 09:27:19 DEBUG[6249] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is 'CHANUNAVAIL’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?CHANUNAVAIL|1”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?exit|return”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Not taking any branch
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfu|1”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfb|1”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing NoOp(“Local/[email protected],2”, “Voicemail is 40”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?s-CHANUNAVAIL|1”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Not taking any branch
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing NoOp(“Local/[email protected],2”, “Sending to Voicemail box 40”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Macro(“Local/[email protected],2”, “vm|40|CHANUNAVAIL|”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid|SKIPTTL”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '0433496396’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '0433496396’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '0’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is ''
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Set(“Local/[email protected],2”, “VMGAIN=”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is ‘TRUE’
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is ‘0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?vmx|1”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Not taking any branch
Nov 12 09:27:19 WARNING[6249] func_db.c: DB requires an argument, DB(/)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Function result is ‘‘
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing NoOp(“Local/[email protected],2”, "CAME FROM: 400 - Blocking VM cause of key: ") in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Goto(“Local/[email protected],2”, “vmret|1”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (from-internal,vmret,1)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is ‘0’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?playret”) in new stack
Nov 12 09:27:19 DEBUG[6249] pbx.c: Not taking any branch
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: == Spawn extension (from-internal, vmret, 2) exited non-zero on ‘Local/[email protected],2’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Macro(“Local/[email protected],2”, “hangupcall”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing ResetCDR(“Local/[email protected],2”, “w”) in new stack
Nov 12 09:27:19 DEBUG[6249] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:27:19 DEBUG[6249] 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 (‘2008-11-12 09:27:19’,’“HS INFO0433496396” <0433496396>’,‘0433496396’,‘vmret’,‘from-internal’, ‘Local/[email protected],2’,’’,‘ResetCDR’,‘w’,0,0,‘FAILED’,3,’’,‘1226442439.26518’)
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing NoCDR(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:19 WARNING[6249] cdr.c: CDR on channel ‘Local/[email protected],2’ not posted
Nov 12 09:27:19 WARNING[6249] cdr.c: CDR on channel ‘Local/[email protected],2’ lacks end
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skiprg”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skipblkvm”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:27:19 DEBUG[6249] pbx.c: Expression result is '1’
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?theend”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:27:19 VERBOSE[6249] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:19 VERBOSE[6249] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’ in macro 'hangupcall’
Nov 12 09:27:19 VERBOSE[6249] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/[email protected],2’
Nov 12 09:27:19 NOTICE[6212] app_queue.c: No one is answering queue ‘400’ (1/0/0)
Nov 12 09:27:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:20 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:21 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:21 VERBOSE[6212] logger.c: – Called Local/[email protected]/n
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Macro(“Local/[email protected],2”, “exten-vm|40|40”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '0433496396’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '0433496396’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?continue”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Not taking any branch
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '63’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '63’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “__TTL=63”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “RingGroupMethod=none”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “VMBOX=40”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “EXTTOCALL=40”) in new stack
Nov 12 09:27:21 DEBUG[6258] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:21 DEBUG[6258] func_db.c: DB: CFU/40 not found in database.
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is ''
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “CFUEXT=”) in new stack
Nov 12 09:27:21 DEBUG[6258] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:21 DEBUG[6258] func_db.c: DB: CFB/40 not found in database.
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is ''
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “CFBEXT=”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '15’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “RT=15”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Macro(“Local/[email protected],2”, “record-enable|40|IN”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?check”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-record-enable,s,4)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '20081111-222721’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing AGI(“Local/[email protected],2”, “recordingcheck|20081111-222721|1226442441.26520”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 12 09:27:21 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:21 VERBOSE[6258] logger.c: recordingcheck|20081111-222721|1226442441.26520: Inbound recording not enabled
Nov 12 09:27:21 VERBOSE[6258] logger.c: – AGI Script recordingcheck completed, returning 0
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing MacroExit(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Macro(“Local/[email protected],2”, “dial|15|trM(auto-blkvm)|40”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?dial”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Not taking any branch
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing SetMusicOnHold(“Local/[email protected],2”, “Harbourside”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing AGI(“Local/[email protected],2”, “dialparties.agi”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Nov 12 09:27:21 DEBUG[3518] chan_sip.c: Auto destroying call 'c1486035ea2c919a’
Nov 12 09:27:21 VERBOSE[6258] logger.c: dialparties.agi: Starting New Dialparties.agi
Nov 12 09:27:21 DEBUG[6262] manager.c: Manager received command 'login’
Nov 12 09:27:21 VERBOSE[6262] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:21 VERBOSE[6262] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:21 VERBOSE[6262] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:21 VERBOSE[6262] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:21 VERBOSE[6262] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:21 VERBOSE[6262] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:21 DEBUG[6262] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:21 DEBUG[6262] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:21 DEBUG[6262] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:21 DEBUG[6262] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:21 VERBOSE[6262] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:21 VERBOSE[6258] logger.c: dialparties.agi: Caller ID name is ‘HS INFO0433496396’ number is '0433496396’
Nov 12 09:27:21 VERBOSE[6258] logger.c: dialparties.agi: USE_CONFIRMATION: 'FALSE’
Nov 12 09:27:21 VERBOSE[6258] logger.c: dialparties.agi: RINGGROUP_INDEX: ''
Nov 12 09:27:21 VERBOSE[6258] logger.c: dialparties.agi: Methodology of ring is 'none’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – dialparties.agi: Added extension 40 to extension map
Nov 12 09:27:21 DEBUG[6258] db.c: Unable to find key ‘40/screen’ in family 'AMPUSER’
Nov 12 09:27:21 VERBOSE[6258] logger.c: > dialparties.agi: Extension 40 has call screening off
Nov 12 09:27:21 DEBUG[6258] db.c: Unable to find key ‘40’ in family 'CF’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – dialparties.agi: Extension 40 cf is disabled
Nov 12 09:27:21 DEBUG[6258] db.c: Unable to find key ‘40’ in family 'DND’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – dialparties.agi: Extension 40 do not disturb is disabled
Nov 12 09:27:21 DEBUG[6258] db.c: Unable to find key ‘40’ in family 'CFB’
Nov 12 09:27:21 DEBUG[6258] db.c: Unable to find key ‘40’ in family 'CFU’
Nov 12 09:27:21 VERBOSE[6258] logger.c: > dialparties.agi: extnum 40 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Nov 12 09:27:21 DEBUG[6262] manager.c: Manager received command 'ExtensionState’
Nov 12 09:27:21 VERBOSE[6258] logger.c: > dialparties.agi: ExtensionState: 4
Nov 12 09:27:21 VERBOSE[6258] logger.c: – dialparties.agi: dbset CALLTRACE/40 to 0433496396
Nov 12 09:27:21 VERBOSE[6258] logger.c: – dialparties.agi: Filtered ARG3: 40
Nov 12 09:27:21 VERBOSE[6258] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:21 VERBOSE[6258] logger.c: > dialparties.agi: NODEST: 400 blkvm enabled macro already in dialopts: trM(auto-blkvm)
Nov 12 09:27:21 DEBUG[6262] manager.c: Manager received command 'Logoff’
Nov 12 09:27:21 VERBOSE[6262] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:21 VERBOSE[6258] logger.c: – AGI Script dialparties.agi completed, returning 0
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Dial(“Local/[email protected],2”, “SIP/40|15|trM(auto-blkvm)”) in new stack
Nov 12 09:27:21 NOTICE[6258] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
Nov 12 09:27:21 VERBOSE[6258] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Nov 12 09:27:21 DEBUG[6258] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is 'CHANUNAVAIL’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?CHANUNAVAIL|1”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?exit|return”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Not taking any branch
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfu|1”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GosubIf(“Local/[email protected],2”, “0?docfb|1”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “DIALSTATUS=CHANUNAVAIL”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing NoOp(“Local/[email protected],2”, “Voicemail is 40”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?s-CHANUNAVAIL|1”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Not taking any branch
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing NoOp(“Local/[email protected],2”, “Sending to Voicemail box 40”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Macro(“Local/[email protected],2”, “vm|40|CHANUNAVAIL|”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Macro(“Local/[email protected],2”, “user-callerid|SKIPTTL”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '0433496396’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '0433496396’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “AMPUSER=0433496396”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?report”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-user-callerid,s,10)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?continue”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is '“HS INFO0433496396” <0433496396>'
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing NoOp(“Local/[email protected],2”, “Using CallerID “HS INFO0433496396” <0433496396>”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is '0’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is ''
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Set(“Local/[email protected],2”, “VMGAIN=”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is ‘TRUE’
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is ‘0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?vmx|1”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Not taking any branch
Nov 12 09:27:21 WARNING[6258] func_db.c: DB requires an argument, DB(/)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Function result is ‘‘
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing NoOp(“Local/[email protected],2”, "CAME FROM: 400 - Blocking VM cause of key: ") in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Goto(“Local/[email protected],2”, “vmret|1”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (from-internal,vmret,1)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is ‘0’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “0?playret”) in new stack
Nov 12 09:27:21 DEBUG[6258] pbx.c: Not taking any branch
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: == Spawn extension (from-internal, vmret, 2) exited non-zero on ‘Local/[email protected],2’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Macro(“Local/[email protected],2”, “hangupcall”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing ResetCDR(“Local/[email protected],2”, “w”) in new stack
Nov 12 09:27:21 DEBUG[6258] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:27:21 DEBUG[6258] 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 (‘2008-11-12 09:27:21’,’“HS INFO0433496396” <0433496396>’,‘0433496396’,‘vmret’,‘from-internal’, ‘Local/[email protected],2’,’’,‘ResetCDR’,‘w’,0,0,‘FAILED’,3,’’,‘1226442441.26520’)
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing NoCDR(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:21 WARNING[6258] cdr.c: CDR on channel ‘Local/[email protected],2’ not posted
Nov 12 09:27:21 WARNING[6258] cdr.c: CDR on channel ‘Local/[email protected],2’ lacks end
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is ‘1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skiprg”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is ‘1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?skipblkvm”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:27:21 DEBUG[6258] pbx.c: Expression result is ‘1’
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing GotoIf(“Local/[email protected],2”, “1?theend”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:27:21 VERBOSE[6258] logger.c: – Executing Hangup(“Local/[email protected],2”, “”) in new stack
Nov 12 09:27:21 VERBOSE[6258] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’ in macro ‘hangupcall’
Nov 12 09:27:21 VERBOSE[6258] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/[email protected],2’
Nov 12 09:27:21 NOTICE[6212] app_queue.c: No one is answering queue ‘400’ (1/0/0)
Nov 12 09:27:22 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:22 VERBOSE[3522] logger.c: – Channel 0/2, span 1 got hangup request
Nov 12 09:27:22 VERBOSE[6212] logger.c: – Stopped music on hold on Zap/2-1
Nov 12 09:27:22 DEBUG[6212] channel.c: Scheduling timer at 0 sample intervals
Nov 12 09:27:22 VERBOSE[6212] logger.c: – User disconnected from queue 400 when they almost made it
Nov 12 09:27:22 VERBOSE[6212] logger.c: == Spawn extension (ext-queues, 400, 18) exited non-zero on ‘Zap/2-1’
Nov 12 09:27:22 DEBUG[6212] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:27:22 DEBUG[6212] 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 (‘2008-11-12 09:27:09’,’“HS INFO0433496396” <0433496396>’,‘0433496396’,‘400’,‘ext-queues’, ‘Zap/2-1’,’’,‘Queue’,‘400|t||’,13,13,‘ANSWERED’,3,’’,‘1226442429.26508’)
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: disabled echo cancellation on channel 2
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: Updated conferencing on 2, with 0 conference users
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1
Nov 12 09:27:22 DEBUG[6212] chan_zap.c: disabled echo cancellation on channel 2
Nov 12 09:27:22 VERBOSE[6212] logger.c: – Hungup 'Zap/2-1’
Nov 12 09:27:23 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:23 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:24 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:24 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:26 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:27 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:30 DEBUG[3518] chan_sip.c: Auto destroying call 'ed770a731d2eb839’
Nov 12 09:27:31 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:32 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:33 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘5dc605941496da[email protected]’ of Request 102: Match Found
Nov 12 09:27:35 DEBUG[6278] manager.c: Manager received command 'login’
Nov 12 09:27:35 VERBOSE[6278] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:35 VERBOSE[6278] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:35 VERBOSE[6278] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:35 VERBOSE[6278] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:35 VERBOSE[6278] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:35 VERBOSE[6278] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:35 DEBUG[6278] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:35 DEBUG[6278] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:35 DEBUG[6278] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:35 DEBUG[6278] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:35 VERBOSE[6278] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:35 VERBOSE[6278] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:35 DEBUG[6281] manager.c: Manager received command 'login’
Nov 12 09:27:35 VERBOSE[6281] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:35 VERBOSE[6281] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:35 VERBOSE[6281] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:35 VERBOSE[6281] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:35 VERBOSE[6281] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:35 VERBOSE[6281] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:35 DEBUG[6281] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:35 DEBUG[6281] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:35 DEBUG[6281] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:35 DEBUG[6281] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:35 VERBOSE[6281] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:37 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:38 DEBUG[6285] manager.c: Manager received command 'login’
Nov 12 09:27:38 VERBOSE[6285] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:38 VERBOSE[6285] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:38 VERBOSE[6285] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:38 VERBOSE[6285] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:38 VERBOSE[6285] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:38 VERBOSE[6285] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:38 DEBUG[6285] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:38 DEBUG[6285] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:38 DEBUG[6285] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:38 DEBUG[6285] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:38 VERBOSE[6285] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:39 VERBOSE[6281] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:39 VERBOSE[6285] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:39 DEBUG[6287] manager.c: Manager received command 'login’
Nov 12 09:27:39 VERBOSE[6287] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:39 VERBOSE[6287] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:39 VERBOSE[6287] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:39 VERBOSE[6287] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:39 VERBOSE[6287] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:39 VERBOSE[6287] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:39 DEBUG[6287] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:39 DEBUG[6287] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:39 DEBUG[6287] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:39 DEBUG[6287] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:39 VERBOSE[6287] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:39 VERBOSE[6287] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:39 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:39 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:41 VERBOSE[3518] logger.c: – Registered SIP ‘95’ at 10.5.9.13 port 5060 expires 120
Nov 12 09:27:41 VERBOSE[3518] logger.c: – Saved useragent “Aastra 55i/2.1.2.30” for peer 95
Nov 12 09:27:41 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:45 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:48 DEBUG[19088] manager.c: Manager received command 'Command’
Nov 12 09:27:48 DEBUG[19088] manager.c: Manager received command 'Command’
Nov 12 09:27:48 DEBUG[19088] manager.c: Manager received command 'Command’
Nov 12 09:27:48 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:48 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:49 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:50 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:50 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:50 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:53 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:56 DEBUG[6303] manager.c: Manager received command 'login’
Nov 12 09:27:56 VERBOSE[6303] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:56 VERBOSE[6303] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:56 VERBOSE[6303] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:56 VERBOSE[6303] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:56 VERBOSE[6303] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:56 VERBOSE[6303] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:56 DEBUG[6303] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:56 DEBUG[6303] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:56 DEBUG[6303] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:56 DEBUG[6303] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:56 VERBOSE[6303] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:56 DEBUG[3518] chan_sip.c: Auto destroying call '89b5b82b49c69cf0’
Nov 12 09:27:56 VERBOSE[6303] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Nov 12 09:27:56 DEBUG[6305] manager.c: Manager received command 'login’
Nov 12 09:27:56 VERBOSE[6305] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:27:56 VERBOSE[6305] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:27:56 VERBOSE[6305] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:27:56 VERBOSE[6305] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:27:56 VERBOSE[6305] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:27:56 VERBOSE[6305] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:27:56 DEBUG[6305] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:27:56 DEBUG[6305] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:27:56 DEBUG[6305] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:27:56 DEBUG[6305] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:27:56 VERBOSE[6305] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:27:56 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:57 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:57 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:57 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:27:58 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:27:59 VERBOSE[6305] logger.c: == Manager ‘admin’ logged off from 127.0.0.1


Freedom to Connect®
FreePBX is a registered trademark of Atengo, LLC.
FreePBX 2.5.0 is licensed under GPL

NOW THIS IS THE CALL LOG OF THE CALL THE DIDN’T WORK:
PLEASE NOTE THAT I DON’T EVEN KNOW IF THE CALL ACTUALLY GOES THROUGH:

FreePBX 2.5.0.1 on 10.2.16.240


Nov 12 09:42:01 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:02 DEBUG[8055] channel.c: Didn’t get a frame from channel: SIP/34-09e72918
Nov 12 09:42:02 DEBUG[8055] channel.c: Bridge stops bridging channels SIP/34-09e72918 and Zap/2-1
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: disabled echo cancellation on channel 2
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: Updated conferencing on 2, with 0 conference users
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1
Nov 12 09:42:02 DEBUG[8055] chan_zap.c: disabled echo cancellation on channel 2
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Hungup 'Zap/2-1’
Nov 12 09:42:02 DEBUG[8055] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Nov 12 09:42:02 VERBOSE[8055] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/34-09e72918’ in macro ‘dialout-trunk’
Nov 12 09:42:02 VERBOSE[8055] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/34-09e72918’
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Executing Macro(“SIP/34-09e72918”, “hangupcall|”) in new stack
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Executing ResetCDR(“SIP/34-09e72918”, “w”) in new stack
Nov 12 09:42:02 DEBUG[8055] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:42:02 DEBUG[8055] 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 (‘2008-11-12 09:38:32’,‘0289865330’,‘0289865330’,‘49114900’,‘from-internal’, ‘SIP/34-09e72918’,‘Zap/2-1’,‘ResetCDR’,‘w’,210,202,‘ANSWERED’,3,’’,‘1226443112.26539’)
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Executing NoCDR(“SIP/34-09e72918”, “”) in new stack
Nov 12 09:42:02 WARNING[8055] cdr.c: CDR on channel ‘SIP/34-09e72918’ not posted
Nov 12 09:42:02 WARNING[8055] cdr.c: CDR on channel ‘SIP/34-09e72918’ lacks end
Nov 12 09:42:02 DEBUG[8055] pbx.c: Expression result is '1’
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Executing GotoIf(“SIP/34-09e72918”, “1?skiprg”) in new stack
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:42:02 DEBUG[8055] pbx.c: Expression result is '1’
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Executing GotoIf(“SIP/34-09e72918”, “1?skipblkvm”) in new stack
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:42:02 DEBUG[8055] pbx.c: Expression result is '1’
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Executing GotoIf(“SIP/34-09e72918”, “1?theend”) in new stack
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:42:02 VERBOSE[8055] logger.c: – Executing Hangup(“SIP/34-09e72918”, “”) in new stack
Nov 12 09:42:02 VERBOSE[8055] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/34-09e72918’ in macro 'hangupcall’
Nov 12 09:42:02 VERBOSE[8055] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/34-09e72918’
Nov 12 09:42:02 DEBUG[8055] chan_sip.c: update_call_counter(34) - decrement call limit counter
Nov 12 09:42:02 VERBOSE[3510] logger.c: Extension Changed 34 new state Idle for Notify User 32
Nov 12 09:42:02 VERBOSE[3510] logger.c: Extension Changed 34 new state Idle for Notify User 34
Nov 12 09:42:02 VERBOSE[3510] logger.c: Extension Changed 34 new state Idle for Notify User 35
Nov 12 09:42:02 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:02 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2018: Match Found
Nov 12 09:42:02 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2022: Match Found
Nov 12 09:42:02 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2019: Match Found
Nov 12 09:42:02 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:03 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:03 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:05 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:06 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:06 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:07 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:07 DEBUG[3518] chan_sip.c: Setting NAT on RTP to 524288
Nov 12 09:42:07 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘bd0a8e668513cc9ac[email protected]’ of Response 1166626403: Match Found
Nov 12 09:42:07 DEBUG[3518] chan_sip.c: Setting NAT on RTP to 524288
Nov 12 09:42:07 DEBUG[3518] chan_sip.c: Checking SIP call limits for device 34
Nov 12 09:42:07 DEBUG[3518] chan_sip.c: build_route: Contact hop: Leah Mathews sip:[email protected];transport=udp
Nov 12 09:42:07 VERBOSE[3510] logger.c: Extension Changed 34 new state InUse for Notify User 32
Nov 12 09:42:07 VERBOSE[3510] logger.c: Extension Changed 34 new state InUse for Notify User 34
Nov 12 09:42:07 VERBOSE[3510] logger.c: Extension Changed 34 new state InUse for Notify User 35
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “EMERGENCYROUTE=YES”) in new stack
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Macro(“SIP/34-09faf7e0”, “user-callerid|SKIPTTL|”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '34’
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '34’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “AMPUSER=34”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “0?report”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Not taking any branch
Nov 12 09:42:07 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '34’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing ExecIf(“SIP/34-09faf7e0”, “1|Set|REALCALLERIDNUM=34”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '34’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “AMPUSER=34”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is 'Leah Mathews’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “AMPUSERCIDNAME=Leah Mathews”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “0?report”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Not taking any branch
Nov 12 09:42:07 DEBUG[8556] db.c: Unable to find key ‘34/cidnum’ in family 'AMPUSER’
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '0’
Nov 12 09:42:07 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '34’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “AMPUSERCID=34”) in new stack
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “CALLERID(all)=“Leah Mathews” <34>”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '34’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “REALCALLERIDNUM=34”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?continue”) in new stack
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Goto (macro-user-callerid,s,19)
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '“Leah Mathews” <34>'
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing NoOp(“SIP/34-09faf7e0”, “Using CallerID “Leah Mathews” <34>”) in new stack
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “_NODEST=”) in new stack
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing Macro(“SIP/34-09faf7e0”, “record-enable|34|OUT|”) in new stack
Nov 12 09:42:07 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?check”) in new stack
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Goto (macro-record-enable,s,4)
Nov 12 09:42:07 DEBUG[8556] pbx.c: Function result is '20081111-224207’
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Executing AGI(“SIP/34-09faf7e0”, “recordingcheck|20081111-224207|1226443327.26545”) in new stack
Nov 12 09:42:07 VERBOSE[8556] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Nov 12 09:42:08 VERBOSE[8556] logger.c: recordingcheck|20081111-224207|1226443327.26545: Outbound recording not enabled
Nov 12 09:42:08 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2019: Match Found
Nov 12 09:42:08 VERBOSE[8556] logger.c: – AGI Script recordingcheck completed, returning 0
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing MacroExit(“SIP/34-09faf7e0”, “”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Macro(“SIP/34-09faf7e0”, “dialout-trunk|1|0414238448||”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “DIAL_TRUNK=1”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 DEBUG[8556] db.c: Unable to find key ‘34/pinless’ in family 'AMPUSER’
Nov 12 09:42:08 DEBUG[8556] func_db.c: DB: AMPUSER/34/pinless not found in database.
Nov 12 09:42:08 DEBUG[8556] pbx.c: Function result is ''
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GosubIf(“SIP/34-09faf7e0”, “0?sub-pincheck|s|1”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “0?disabletrunk|1”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Not taking any branch
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “DIAL_NUMBER=0414238448”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “OUTBOUND_GROUP=OUT_1”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?nomax”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Goto (macro-dialout-trunk,s,9)
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “0?skipoutcid”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Not taking any branch
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “DIAL_TRUNK_OPTIONS=r”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Macro(“SIP/34-09faf7e0”, “outbound-callerid|1”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing ExecIf(“SIP/34-09faf7e0”, “0|SetCallerPres|”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Function result is '34’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing ExecIf(“SIP/34-09faf7e0”, “0|Set|REALCALLERIDNUM=34”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?normcid”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Goto (macro-outbound-callerid,s,6)
Nov 12 09:42:08 DEBUG[8556] pbx.c: Function result is '0289865330’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “USEROUTCID=0289865330”) in new stack
Nov 12 09:42:08 DEBUG[8556] db.c: Unable to find key ‘34/emergency_cid’ in family 'DEVICE’
Nov 12 09:42:08 DEBUG[8556] func_db.c: DB: DEVICE/34/emergency_cid not found in database.
Nov 12 09:42:08 DEBUG[8556] pbx.c: Function result is ''
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “EMERGENCYCID=”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “TRUNKOUTCID=hidden”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?trunkcid”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Goto (macro-outbound-callerid,s,12)
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing ExecIf(“SIP/34-09faf7e0”, “1|Set|CALLERID(all)=hidden”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “0?exit”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Not taking any branch
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “CALLERID(all)=0289865330”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Function result is ''
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing ExecIf(“SIP/34-09faf7e0”, “0|SetCallerPres|prohib_passed_screen”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing ExecIf(“SIP/34-09faf7e0”, “0|AGI|fixlocalprefix”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “OUTNUM=0414238448”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Function result is 'ZAP/g0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Set(“SIP/34-09faf7e0”, “custom=ZAP/g0”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing ExecIf(“SIP/34-09faf7e0”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)r”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Macro(“SIP/34-09faf7e0”, “dialout-trunk-predial-hook|”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing MacroExit(“SIP/34-09faf7e0”, “”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “0?bypass|1”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Not taking any branch
Nov 12 09:42:08 DEBUG[8556] pbx.c: Expression result is '0’
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “0?customtrunk”) in new stack
Nov 12 09:42:08 DEBUG[8556] pbx.c: Not taking any branch
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Executing Dial(“SIP/34-09faf7e0”, “ZAP/g0/0414238448|300|r”) in new stack
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Requested transfer capability: 0x00 - SPEECH
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Called g0/0414238448
Nov 12 09:42:08 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2023: Match Found
Nov 12 09:42:08 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2020: Match Found
Nov 12 09:42:08 DEBUG[3522] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/2 span 1
Nov 12 09:42:08 VERBOSE[8556] logger.c: – Zap/2-1 is proceeding passing it to SIP/34-09faf7e0
Nov 12 09:42:09 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:09 DEBUG[3518] chan_sip.c: Auto destroying call ‘[email protected]
Nov 12 09:42:10 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:10 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:10 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:10 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:11 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:11 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:11 DEBUG[3522] chan_zap.c: Queuing frame from PRI_EVENT_PROGRESS on channel 0/2 span 1
Nov 12 09:42:11 VERBOSE[8556] logger.c: – Zap/2-1 is making progress passing it to SIP/34-09faf7e0
Nov 12 09:42:11 DEBUG[3522] chan_zap.c: Enabled echo cancellation on channel 2
Nov 12 09:42:11 VERBOSE[8556] logger.c: – Zap/2-1 is ringing
Nov 12 09:42:12 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:12 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:13 DEBUG[7949] channel.c: Didn’t get a frame from channel: SIP/09-0a530b40
Nov 12 09:42:13 DEBUG[7949] channel.c: Bridge stops bridging channels Zap/1-1 and SIP/09-0a530b40
Nov 12 09:42:13 DEBUG[7949] chan_sip.c: update_call_counter(09) - decrement call limit counter
Nov 12 09:42:13 DEBUG[7949] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Nov 12 09:42:13 VERBOSE[7949] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Zap/1-1’ in macro ‘dial’
Nov 12 09:42:13 VERBOSE[7949] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Zap/1-1’ in macro ‘exten-vm’
Nov 12 09:42:13 VERBOSE[7949] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Zap/1-1’
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing Macro(“Zap/1-1”, “hangupcall”) in new stack
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing ResetCDR(“Zap/1-1”, “w”) in new stack
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 71
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 10
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 95
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 52
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 01
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 33
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 31
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 09
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 32
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 08
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 02
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 34
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 61
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 12
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 37
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 35
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 03
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 04
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 63
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 59
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 57
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 58
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 53
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 66
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 67
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 62
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 05
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 65
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 55
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 69
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 06
Nov 12 09:42:13 VERBOSE[3510] logger.c: Extension Changed 09 new state Idle for Notify User 38
Nov 12 09:42:13 DEBUG[7949] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:42:13 DEBUG[7949] 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 (‘2008-11-12 09:38:10’,’“BEVILLE MAIN LINE0295174726” <0295174726>’,‘0295174726’,‘302’,‘ext-group’, ‘Zap/1-1’,‘SIP/09-0a530b40’,‘ResetCDR’,‘w’,243,235,‘ANSWERED’,3,’’,‘1226443045.26525’)
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing NoCDR(“Zap/1-1”, “”) in new stack
Nov 12 09:42:13 WARNING[7949] cdr.c: CDR on channel ‘Zap/1-1’ not posted
Nov 12 09:42:13 WARNING[7949] cdr.c: CDR on channel ‘Zap/1-1’ lacks end
Nov 12 09:42:13 DEBUG[7949] pbx.c: Expression result is '1’
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing GotoIf(“Zap/1-1”, “1?skiprg”) in new stack
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:42:13 DEBUG[7949] pbx.c: Expression result is '0’
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing GotoIf(“Zap/1-1”, “0?skipblkvm”) in new stack
Nov 12 09:42:13 DEBUG[7949] pbx.c: Not taking any branch
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing NoOp(“Zap/1-1”, “Cleaning Up Block VM Flag: BLKVM/302/Zap/1-1”) in new stack
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing DBdel(“Zap/1-1”, “BLKVM/302/Zap/1-1”) in new stack
Nov 12 09:42:13 VERBOSE[7949] logger.c: – DBdel: family=BLKVM, key=302/Zap/1-1
Nov 12 09:42:13 DEBUG[7949] db.c: Unable to find key ‘302/Zap/1-1’ in family 'BLKVM’
Nov 12 09:42:13 VERBOSE[7949] logger.c: – DBdel: Error deleting key from database.
Nov 12 09:42:13 DEBUG[7949] pbx.c: Expression result is '1’
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing GotoIf(“Zap/1-1”, “1?theend”) in new stack
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Executing Hangup(“Zap/1-1”, “”) in new stack
Nov 12 09:42:13 VERBOSE[7949] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Zap/1-1’ in macro 'hangupcall’
Nov 12 09:42:13 VERBOSE[7949] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Zap/1-1’
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: Hangup: channel: 1 index = 0, normal = 18, callwait = -1, thirdcall = -1
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: disabled echo cancellation on channel 1
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: Updated conferencing on 1, with 0 conference users
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
Nov 12 09:42:13 DEBUG[7949] chan_zap.c: disabled echo cancellation on channel 1
Nov 12 09:42:13 VERBOSE[7949] logger.c: – Hungup 'Zap/1-1’
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3171: Match Found
Nov 12 09:42:13 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.100
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3171: Match Found
Nov 12 09:42:13 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.131
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3171: Match Found
Nov 12 09:42:13 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.137
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3171: Match Found
Nov 12 09:42:13 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.115
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3171: Match Found
Nov 12 09:42:13 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.136
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3172: Match Found
Nov 12 09:42:13 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.105
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2569: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3171: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3171: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘d9f57764142c3a0d’ of Request 691: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘a8b64bd51368eb9f’ of Request 3171: Match Found
Nov 12 09:42:13 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 500 “CSeq Number Out of order” back from 10.2.16.143
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 787: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘2f295efa4332de7d’ of Request 3171: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘b887e23ba58c12a8’ of Request 3171: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3078: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3082: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘da51085b47e55058’ of Request 3171: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3081: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3082: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3083: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3082: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘5f0ad3b852c78e54’ of Request 3079: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3082: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3084: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3083: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3086: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3082: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3085: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘2aa42b82a45f86de’ of Request 1021: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3085: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 3173: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘71dfaa0396681f40’ of Request 3172: Match Found
Nov 12 09:42:13 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:16 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:16 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:16 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:17 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:18 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:19 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:20 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:20 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘76af1ec63deb3a9701704d0946[email protected]’ of Request 102: Match Found
Nov 12 09:42:20 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:20 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:20 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:21 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:22 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:22 DEBUG[3518] chan_sip.c: Auto destroying call '1d9de58f650343a2’
Nov 12 09:42:22 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:23 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:23 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:23 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:24 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:24 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:25 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:25 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:25 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:28 DEBUG[3522] chan_zap.c: Echo cancellation already on
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Zap/2-1 answered SIP/34-09faf7e0
Nov 12 09:42:28 VERBOSE[3518] logger.c: – Registered SIP ‘95’ at 10.2.15.107 port 5060 expires 120
Nov 12 09:42:28 VERBOSE[3518] logger.c: – Saved useragent “Aastra 480i/1.4.2.3000 Brcm Callctrl/1.5.1.0 MxSF/v3.2.8.45” for peer 95
Nov 12 09:42:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 1166626404: Match Found
Nov 12 09:42:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:28 DEBUG[8556] channel.c: Didn’t get a frame from channel: SIP/34-09faf7e0
Nov 12 09:42:28 DEBUG[8556] channel.c: Bridge stops bridging channels SIP/34-09faf7e0 and Zap/2-1
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: Hangup: channel: 2 index = 0, normal = 19, callwait = -1, thirdcall = -1
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: disabled echo cancellation on channel 2
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: Updated conferencing on 2, with 0 conference users
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1
Nov 12 09:42:28 DEBUG[8556] chan_zap.c: disabled echo cancellation on channel 2
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Hungup 'Zap/2-1’
Nov 12 09:42:28 DEBUG[8556] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Nov 12 09:42:28 VERBOSE[8556] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/34-09faf7e0’ in macro ‘dialout-trunk’
Nov 12 09:42:28 VERBOSE[8556] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/34-09faf7e0’
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Executing Macro(“SIP/34-09faf7e0”, “hangupcall|”) in new stack
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Executing ResetCDR(“SIP/34-09faf7e0”, “w”) in new stack
Nov 12 09:42:28 DEBUG[8556] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Nov 12 09:42:28 DEBUG[8556] 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 (‘2008-11-12 09:42:07’,‘0289865330’,‘0289865330’,‘0414238448’,‘from-internal’, ‘SIP/34-09faf7e0’,‘Zap/2-1’,‘ResetCDR’,‘w’,21,0,‘ANSWERED’,3,’’,‘1226443327.26545’)
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Executing NoCDR(“SIP/34-09faf7e0”, “”) in new stack
Nov 12 09:42:28 WARNING[8556] cdr.c: CDR on channel ‘SIP/34-09faf7e0’ not posted
Nov 12 09:42:28 WARNING[8556] cdr.c: CDR on channel ‘SIP/34-09faf7e0’ lacks end
Nov 12 09:42:28 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?skiprg”) in new stack
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:42:28 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?skipblkvm”) in new stack
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:42:28 DEBUG[8556] pbx.c: Expression result is '1’
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Executing GotoIf(“SIP/34-09faf7e0”, “1?theend”) in new stack
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:42:28 VERBOSE[8556] logger.c: – Executing Hangup(“SIP/34-09faf7e0”, “”) in new stack
Nov 12 09:42:28 VERBOSE[8556] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/34-09faf7e0’ in macro 'hangupcall’
Nov 12 09:42:28 VERBOSE[8556] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/34-09faf7e0’
Nov 12 09:42:28 DEBUG[8556] chan_sip.c: update_call_counter(34) - decrement call limit counter
Nov 12 09:42:28 VERBOSE[3510] logger.c: Extension Changed 34 new state Idle for Notify User 32
Nov 12 09:42:28 VERBOSE[3510] logger.c: Extension Changed 34 new state Idle for Notify User 34
Nov 12 09:42:28 VERBOSE[3510] logger.c: Extension Changed 34 new state Idle for Notify User 35
Nov 12 09:42:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2020: Match Found
Nov 12 09:42:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2024: Match Found
Nov 12 09:42:28 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2021: Match Found
Nov 12 09:42:29 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:30 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:31 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:31 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]16.240’ of Request 102: Match Found
Nov 12 09:42:32 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:32 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:32 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:35 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:35 DEBUG[3518] chan_sip.c: Auto destroying call 'd5c21612c18f7307’
Nov 12 09:42:35 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:39 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:39 DEBUG[3518] chan_sip.c: Auto destroying call '8692bec08e1060c2’
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Setting NAT on RTP to 524288
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Auto destroying call 'bcf5f1f8f28eb4c9’
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 885073422: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Setting NAT on RTP to 524288
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Checking SIP call limits for device 31
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: build_route: Contact hop: HS Reception sip:[email protected];transport=udp
Nov 12 09:42:41 DEBUG[3510] channel.c: Avoiding initial deadlock for 'SIP/31-0a349590’
Nov 12 09:42:41 VERBOSE[8604] logger.c: – Executing ResetCDR(“SIP/31-0a349590”, “”) in new stack
Nov 12 09:42:41 VERBOSE[8604] logger.c: – Executing NoCDR(“SIP/31-0a349590”, “”) in new stack
Nov 12 09:42:41 WARNING[8604] cdr.c: CDR on channel ‘SIP/31-0a349590’ not posted
Nov 12 09:42:41 WARNING[8604] cdr.c: CDR on channel ‘SIP/31-0a349590’ lacks end
Nov 12 09:42:41 VERBOSE[8604] logger.c: – Executing Wait(“SIP/31-0a349590”, “1”) in new stack
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 35
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 32
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 34
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 71
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 10
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 95
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 52
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 01
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 37
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 33
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 31
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 09
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 02
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 12
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 61
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 08
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 03
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 04
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 63
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 59
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 57
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 58
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 53
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 66
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 67
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 05
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 62
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 65
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 55
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 69
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 06
Nov 12 09:42:41 VERBOSE[3510] logger.c: Extension Changed 31 new state InUse for Notify User 38
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.100
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.131
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.116
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.115
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.105
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.137
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.136
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.134
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2022: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘4cce1a14b9c9e412’ of Request 517: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 103: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 192.168.20.132
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘b54cc3200749d874’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 500 “CSeq Number Out of order” back from 10.2.16.149
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 112: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 192.168.20.124
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘d9d3d9637e746572’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 500 “CSeq Number Out of order” back from 10.2.16.150
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘4e8101375d31941e’ of Request 2532: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 500 “CSeq Number Out of order” back from 10.2.16.143
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 112: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 192.168.20.129
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 556: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘e66ad0c617ec4515’ of Request 2532: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2415: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2417: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2421: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2421: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:41 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.15.100
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2425: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2425: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2428: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2434: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘80bbe5db210c2797’ of Request 2413: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2434: Match Found
Nov 12 09:42:41 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘b80a50280332a2fd’ of Request 808: Match Found
Nov 12 09:42:42 VERBOSE[8604] logger.c: == Spawn extension (from-internal, 396, 3) exited non-zero on 'SIP/31-0a349590’
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Executing Macro(“SIP/31-0a349590”, “hangupcall”) in new stack
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Executing ResetCDR(“SIP/31-0a349590”, “w”) in new stack
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Executing NoCDR(“SIP/31-0a349590”, “”) in new stack
Nov 12 09:42:42 DEBUG[8604] pbx.c: Expression result is '1’
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Executing GotoIf(“SIP/31-0a349590”, “1?skiprg”) in new stack
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Goto (macro-hangupcall,s,6)
Nov 12 09:42:42 DEBUG[8604] pbx.c: Expression result is '1’
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Executing GotoIf(“SIP/31-0a349590”, “1?skipblkvm”) in new stack
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Goto (macro-hangupcall,s,9)
Nov 12 09:42:42 DEBUG[8604] pbx.c: Expression result is '1’
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Executing GotoIf(“SIP/31-0a349590”, “1?theend”) in new stack
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Goto (macro-hangupcall,s,11)
Nov 12 09:42:42 VERBOSE[8604] logger.c: – Executing Hangup(“SIP/31-0a349590”, “”) in new stack
Nov 12 09:42:42 VERBOSE[8604] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/31-0a349590’ in macro 'hangupcall’
Nov 12 09:42:42 VERBOSE[8604] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/31-0a349590’
Nov 12 09:42:42 DEBUG[8604] chan_sip.c: update_call_counter(31) - decrement call limit counter
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘ad41409fb2367af8’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 35
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 32
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 34
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 71
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 10
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 95
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 52
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 01
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 37
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 33
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 31
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 09
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 02
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 12
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 61
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 08
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 03
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 04
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 63
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 59
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 57
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 58
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 53
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 66
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 67
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 05
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 62
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 65
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 55
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 69
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 06
Nov 12 09:42:42 VERBOSE[3510] logger.c: Extension Changed 31 new state Idle for Notify User 38
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2420: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.100
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.116
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.137
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.115
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.136
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.134
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2534: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.105
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2023: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 104: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 192.168.20.132
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 113: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 192.168.20.124
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘b54cc3200749d874’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 500 “CSeq Number Out of order” back from 10.2.16.149
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘4cce1a14b9c9e412’ of Request 518: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 113: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 192.168.20.129
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘d9d3d9637e746572’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 500 “CSeq Number Out of order” back from 10.2.16.150
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘4e8101375d31941e’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 500 “CSeq Number Out of order” back from 10.2.16.143
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 557: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘e66ad0c617ec4515’ of Request 2533: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2416: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2533: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.16.131
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2422: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2422: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2418: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2534: Match Found
Nov 12 09:42:42 VERBOSE[3518] logger.c: – Incoming call: Got SIP response 400 “Out Of Order” back from 10.2.15.100
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2426: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2426: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2429: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2435: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘80bbe5db210c2797’ of Request 2414: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2435: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘b80a50280332a2fd’ of Request 809: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 885073423: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘ad41409fb2367af8’ of Request 2534: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 2421: Match Found
Nov 12 09:42:42 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:43 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:43 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:44 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:45 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:45 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:45 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:45 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:45 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:48 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:49 DEBUG[3518] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Nov 12 09:42:50 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:50 DEBUG[3518] chan_sip.c: Auto destroying call '[email protected]
Nov 12 09:42:50 DEBUG[8614] manager.c: Manager received command 'login’
Nov 12 09:42:50 VERBOSE[8614] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Nov 12 09:42:50 VERBOSE[8614] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Nov 12 09:42:50 VERBOSE[8614] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Nov 12 09:42:50 VERBOSE[8614] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: Found
Nov 12 09:42:50 VERBOSE[8614] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Nov 12 09:42:50 VERBOSE[8614] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Nov 12 09:42:50 DEBUG[8614] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Nov 12 09:42:50 DEBUG[8614] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Nov 12 09:42:50 DEBUG[8614] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Nov 12 09:42:50 DEBUG[8614] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Nov 12 09:42:50 VERBOSE[8614] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Nov 12 09:42:51 DEBUG[3518] chan_sip.c: Auto destroying call ‘[email protected]


Freedom to Connect®
FreePBX is a registered trademark of Atengo, LLC.
FreePBX 2.5.0 is licensed under GPL