Hello List,
I am having a strange issue with a trixbox system we installed for a client, and
I would appreciate any help on this one. The issue is that occasionally when
they go to answer an inbound call from the Sangoma A200 - there is no one there,
and they are presented with dial tone. The calling party is hung up.
A bit of background:
The client actually has two systems install (one at each location). Both systems
are identical:
Intel Server x3250
Dual Core Xenon Processor
1GB RAM
Raid 1 160GB HDD's
Sangoma A200 to interface to 2 PSTN lines.
The odd thing is that only one of the systems is having this issue....
Making this one even more frustrating is that it only happens two or three times
a day on this production box. Testing that I have done out of hours has been
unable to re-produce the issue as of yet. I have enabled verbose debugging, and
I have included below what I believe is the relevant section of the logs for
when the issue occurs.
As a quick overview, this was an incoming call on Zaptel channel 2, which was
went to a ring group, and started to call SIP extension 203. This is when the
call hung up.
If there is any other information that I can provide to help, please let me
know. This is a very frustrating issue...
Log Output:
Dec 21 13:43:48 NOTICE[15840] chan_zap.c: Got event 18 (Ring Begin)...
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "Entering from-zaptel with DID == ") in new
stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Ringing("Zap/2-1", "") in new stack
Dec 21 13:43:48 DEBUG[15840] chan_zap.c: Requested indication 3 on channel
Zap/2-1 Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is 's'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "DID=s") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "DID is now s") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?zapok:notzap") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (from-zaptel,s,8)
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "Is a Zaptel Channel") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "CHAN=2-1") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is '2'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "CHAN=2") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Macro("Zap/2-1", "from-zaptel-2|s|1") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "Entering macro-from-zaptel-2 with DID = s")
in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Noop
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Gosub("Zap/2-1", "app-blacklist-check|s|1") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Gosub Dec 21
13:43:48 DEBUG[15840] app_macro.c: Incrementing gosub_level
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
LookupBlacklist("Zap/2-1", "") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: LookupBlacklist
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '0'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "0?blacklisted") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Not taking any branch Dec 21 13:43:48
DEBUG[15840] app_macro.c: Executed application: GotoIf
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Return("Zap/2-1", "") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Return Dec 21
13:43:48 DEBUG[15840] app_macro.c: Decrementing gosub_level
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Gosub("Zap/2-1", "cidlookup|cidlookup_1|1") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Gosub Dec 21
13:43:48 DEBUG[15840] app_macro.c: Incrementing gosub_level
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
LookupCIDName("Zap/2-1", "") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: LookupCIDName
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Return("Zap/2-1", "") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Return Dec 21
13:43:48 DEBUG[15840] app_macro.c: Decrementing gosub_level
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "__FROM_DID=s") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '0'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "0 ?cidok") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Not taking any branch Dec 21 13:43:48
DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21 13:43:48
DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "CALLERID(name)=") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] pbx.c: Function result is '"" <>'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "CallerID is "" <>") in new
stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Noop
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Goto("Zap/2-1", "timeconditions|1|1") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (timeconditions,1,1)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Goto
Dec 21 13:43:48 VERBOSE[15840] logger.c: == Channel 'Zap/2-1' jumping
out of macro 'from-zaptel-2'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIfTime("Zap/2-1",
"08:00-18:00|mon-fri|*|*?ext-group|600|1") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (ext-group,600,1)
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Macro("Zap/2-1", "user-callerid|") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "user-callerid: ") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Noop Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "AMPUSER=") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '0'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "0?report") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Not taking any branch Dec 21 13:43:48
DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21 13:43:48
DEBUG[15840] pbx.c: Expression result is '0'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "0?start") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Not taking any branch Dec 21 13:43:48
DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21 13:43:48
DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "REALCALLERIDNUM=") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "REALCALLERIDNUM is ") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: NoOp Dec 21
13:43:48 DEBUG[15840] db.c: Unable to find key '/user' in family
'DEVICE'
Dec 21 13:43:48 DEBUG[15840] func_db.c: DB: DEVICE//user not found in database.
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "AMPUSER=") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] db.c: Unable to find key '/cidname' in family
'AMPUSER'
Dec 21 13:43:48 DEBUG[15840] func_db.c: DB: AMPUSER//cidname not found in
database.
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "AMPUSERCIDNAME=") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?report") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (macro-user-callerid,s,13)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: GotoIf
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "TTL: ARG1: ") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Noop Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '0'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "0?continue") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Not taking any branch Dec 21 13:43:48
DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21 13:43:48
DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '-1'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is '64'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "__TTL=64") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?continue") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (macro-user-callerid,s,23)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21
13:43:48 DEBUG[15840] pbx.c: Function result is '"" <>'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "Using CallerID "" <>") in
new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: NoOp Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?skipdb") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (ext-group,600,4)
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "__NODEST=") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "__BLKVM_OVERRIDE=BLKVM/600/Zap/2-1") in new
stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "__BLKVM_BASE=600") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "DB(BLKVM/600/Zap/2-1)=TRUE") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "RRNODEST=") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "__NODEST=600") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?REPCID") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (ext-group,600,15)
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "CALLERID(name) is ") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "_RGPREFIX=Leongatha:") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is ''
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "CALLERID(name)=Leongatha:") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "RecordMethod=Group") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Macro("Zap/2-1",
"record-enable|203-202-200-201-208-209-206|Group") in new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is '0'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '0'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "0?2:4") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (macro-record-enable,s,4)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21
13:43:48 DEBUG[15840] pbx.c: Function result is '20071221-134348'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
AGI("Zap/2-1",
"recordingcheck|20071221-134348|1198205023.1657") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Launched AGI Script
/var/lib/asterisk/agi-bin/recordingcheck
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- AGI Script recordingcheck
completed, returning 0
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: AGI
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "No recording needed") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Noop
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "RingGroupMethod=hunt") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Macro("Zap/2-1", "dial|20||203-202-200-201-208-209-206") in
new stack
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?dial") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (macro-dial,s,3)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: GotoIf
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
AGI("Zap/2-1", "dialparties.agi") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Launched AGI Script
/var/lib/asterisk/agi-bin/dialparties.agi
Dec 21 13:43:48 VERBOSE[15840] logger.c: dialparties.agi: Starting New
Dialparties.agi
Dec 21 13:43:48 DEBUG[15847] manager.c: Manager received command 'login'
Dec 21 13:43:48 VERBOSE[15847] logger.c: == Parsing
'/etc/asterisk/manager.conf': Dec 21 13:43:48 VERBOSE[15847] logger.c:
== Parsing '/etc/asterisk/manager.conf': Found
Dec 21 13:43:48 VERBOSE[15847] logger.c: == Parsing
'/etc/asterisk/manager_custom.conf': Dec 21 13:43:48 VERBOSE[15847]
logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 21 13:43:48 DEBUG[15847] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for
peer Dec 21 13:43:48 DEBUG[15847] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0
appended to acl for peer Dec 21 13:43:48 DEBUG[15847] acl.c: ##### Testing
127.0.0.1 with 0.0.0.0 Dec 21 13:43:48 DEBUG[15847] acl.c: ##### Testing
127.0.0.1 with 127.0.0.0
Dec 21 13:43:48 VERBOSE[15847] logger.c: == Manager 'admin' logged on
from 127.0.0.1
Dec 21 13:43:48 VERBOSE[15840] logger.c: dialparties.agi: Caller ID name is
'Leongatha:' number is 'unknown'
Dec 21 13:43:48 VERBOSE[15840] logger.c: dialparties.agi: USE_CONFIRMATION:
'FALSE'
Dec 21 13:43:48 VERBOSE[15840] logger.c: dialparties.agi: RINGGROUP_INDEX:
''
Dec 21 13:43:48 VERBOSE[15840] logger.c: dialparties.agi: Methodology of ring
is 'hunt'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Added
extension 203 to extension map
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Added
extension 202 to extension map
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Added
extension 200 to extension map
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Added
extension 201 to extension map
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Added
extension 208 to extension map
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Added
extension 209 to extension map
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Added
extension 206 to extension map
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '203' in family
'CF'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 203
cf is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '202' in family
'CF'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 202
cf is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '200' in family
'CF'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 200
cf is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '201' in family
'CF'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 201
cf is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '208' in family
'CF'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 208
cf is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '209' in family
'CF'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 209
cf is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '206' in family
'CF'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 206
cf is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '203' in family
'DND'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 203
do not disturb is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '202' in family
'DND'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 202
do not disturb is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '200' in family
'DND'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 200
do not disturb is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '201' in family
'DND'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 201
do not disturb is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '208' in family
'DND'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 208
do not disturb is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '209' in family
'DND'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 209
do not disturb is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '206' in family
'DND'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- dialparties.agi: Extension 206
do not disturb is disabled
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '203' in family
'CFB'
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '203' in family
'CFU'
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: extnum
203 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '202' in family
'CFB'
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '202' in family
'CFU'
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: extnum
202 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '200' in family
'CFB'
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '200' in family
'CFU'
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: extnum
200 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '201' in family
'CFB'
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '201' in family
'CFU'
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: extnum
201 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '208' in family
'CFB'
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '208' in family
'CFU'
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: extnum
208 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '209' in family
'CFB'
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '209' in family
'CFU'
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: extnum
209 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '206' in family
'CFB'
Dec 21 13:43:48 DEBUG[15840] db.c: Unable to find key '206' in family
'CFU'
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: extnum
206 has: cw: 1; hascfb: 0 [] hascfu: 0 []
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: NODEST:
600 adding M(auto-blkvm) to dialopts: M(auto-blkvm)
Dec 21 13:43:48 VERBOSE[15840] logger.c: > dialparties.agi: NODEST:
600 blkvm enabled macro already in dialopts: M(auto-blkvm)
Dec 21 13:43:48 DEBUG[15847] manager.c: Manager received command
'Logoff'
Dec 21 13:43:48 VERBOSE[15847] logger.c: == Manager 'admin' logged off
from 127.0.0.1
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- AGI Script dialparties.agi
completed, returning 0
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: AGI
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "Returned from dialparties with hunt groups to
dial ") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: NoOp
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "HuntLoop=0") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?30 ") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (macro-dial,s,30)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: GotoIf
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "HuntMember=HuntMember0") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?32:35 ") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (macro-dial,s,32)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21
13:43:48 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:43:48 DEBUG[15840] pbx.c: Function result is '203'
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "CT_EXTEN=203") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Set("Zap/2-1", "DB(CALLTRACE/203)=unknown") in new stack
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Set
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Goto("Zap/2-1", "s|42") in new stack
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Goto (macro-dial,s,42)
Dec 21 13:43:48 DEBUG[15840] app_macro.c: Executed application: Goto
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Executing
Dial("Zap/2-1", "SIP/203|20|M(auto-blkvm) ") in new stack
Dec 21 13:43:48 DEBUG[15840] chan_sip.c: Setting NAT on RTP to 0 Dec 21 13:43:48
DEBUG[15840] chan_sip.c: Outgoing Call for 203
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- Called 203
Dec 21 13:43:48 DEBUG[3788] chan_sip.c: (Provisional) Stopping retransmission
(but retaining packet) on '64c1f5541d03656d3fe430ce00c9a4c6 at
192.168.1.6' Request 102: Found Dec 21 13:43:48 DEBUG[3788] chan_sip.c:
(Provisional) Stopping retransmission (but retaining packet) on
'64c1f5541d03656d3fe430ce00c9a4c6 at 192.168.1.6' Request 102: Found
Dec 21 13:43:48 VERBOSE[15840] logger.c: -- SIP/203-09632e30 is ringing
Dec 21 13:43:48 DEBUG[15840] chan_zap.c: Requested indication 3 on channel
Zap/2-1 Dec 21 13:43:49 DEBUG[15840] chan_zap.c: Exception on 13, channel 2 Dec
21 13:43:49 DEBUG[15840] chan_zap.c: Got event Ring/Answered(2) on channel 2
(index 0) Dec 21 13:43:49 DEBUG[15840] chan_zap.c: Setting IDLE polarity due to
ring. Old polarity was 0 Dec 21 13:43:51 DEBUG[15840] chan_zap.c: Exception on
13, channel 2 Dec 21 13:43:51 DEBUG[15840] chan_zap.c: Got event Ring Begin(18)
on channel 2 (index 0) Dec 21 13:43:52 DEBUG[15840] chan_zap.c: Exception on 13,
channel 2 Dec 21 13:43:52 DEBUG[15840] chan_zap.c: Got event Ring/Answered(2) on
channel 2 (index 0) Dec 21 13:43:52 DEBUG[15840] chan_zap.c: Setting IDLE
polarity due to ring. Old polarity was 0 Dec 21 13:43:59 DEBUG[3788] chan_sip.c:
Acked pending invite 102 Dec 21 13:43:59 DEBUG[3788] chan_sip.c: Stopping
retransmission on '64c1f5541d03656d3fe430ce00c9a4c6 at 192.168.1.6' of
Request 102: Match Found Dec 21 13:43:59 DEBUG[3788] chan_sip.c: build_route:
Contact hop: <sip:203 at 192.168.1.108:5060> Dec 21 13:43:59 DEBUG[3398]
channel.c: Avoiding initial deadlock for 'SIP/203-09632e30'
Dec 21 13:43:59 VERBOSE[15840] logger.c: -- SIP/203-09632e30 answered
Zap/2-1
Dec 21 13:43:59 VERBOSE[15840] logger.c: -- Executing
Set("SIP/203-09632e30", "__MACRO_RESULT=") in new stack
Dec 21 13:43:59 DEBUG[15840] app_macro.c: Executed application: Set
Dec 21 13:43:59 VERBOSE[15840] logger.c: -- Executing
DBdel("SIP/203-09632e30", "BLKVM/600/Zap/2-1") in new stack
Dec 21 13:43:59 VERBOSE[15840] logger.c: -- DBdel: family=BLKVM,
key=600/Zap/2-1
Dec 21 13:43:59 DEBUG[15840] app_macro.c: Executed application: DBDel Dec 21
13:43:59 DEBUG[15840] app_dial.c: Macro exited with status 0 Dec 21 13:43:59
DEBUG[15840] chan_zap.c: Requested indication -1 on channel Zap/2-1 Dec 21
13:43:59 DEBUG[3398] channel.c: Avoiding initial deadlock for 'Zap/2-1'
Dec 21 13:43:59 DEBUG[15840] chan_zap.c: Took Zap/2-1 off hook Dec 21 13:43:59
DEBUG[15840] chan_zap.c: Enabled echo cancellation on channel 2 Dec 21 13:43:59
WARNING[15840] chan_zap.c: Unable to request echo training on channel 2
Dec 21 13:44:02 DEBUG[15840] channel.c: Didn't get a frame from channel:
SIP/203-09632e30
Dec 21 13:44:02 DEBUG[15840] channel.c: Bridge stops bridging channels Zap/2-1
and SIP/203-09632e30 Dec 21 13:44:02 DEBUG[15840] chan_sip.c:
update_call_counter(203) - decrement call limit counter Dec 21 13:44:02
DEBUG[15840] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Dec 21 13:44:02 VERBOSE[15840] logger.c: == Spawn extension (macro-dial, s,
42) exited non-zero on 'Zap/2-1' in macro 'dial'
Dec 21 13:44:02 VERBOSE[15840] logger.c: == Spawn extension (macro-dial, s,
42) exited non-zero on 'Zap/2-1'
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
Macro("Zap/2-1", "hangupcall") in new stack
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
ResetCDR("Zap/2-1", "w") in new stack
Dec 21 13:44:02 DEBUG[15840] cdr_addon_mysql.c: cdr_mysql: inserting a CDR
record.
Dec 21 13:44:02 DEBUG[15840] 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 ('2007-12-21
13:43:48','Leongatha:','','600','ext-group',
'Zap/2-1','SIP/203-09632e30','ResetCDR','w',14,3,'ANSWERED',3,'','1198205023.1657')
Dec 21 13:44:02 DEBUG[15840] app_macro.c: Executed application: ResetCDR
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
NoCDR("Zap/2-1", "") in new stack
Dec 21 13:44:02 NOTICE[15840] cdr.c: CDR on channel 'Zap/2-1' not posted
Dec 21 13:44:02 NOTICE[15840] cdr.c: CDR on channel 'Zap/2-1' lacks end
Dec 21 13:44:02 DEBUG[15840] app_macro.c: Executed application: NoCDR Dec 21
13:44:02 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?skiprg") in new stack
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Goto (macro-hangupcall,s,6)
Dec 21 13:44:02 DEBUG[15840] app_macro.c: Executed application: GotoIf Dec 21
13:44:02 DEBUG[15840] pbx.c: Expression result is '0'
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "0?skipblkvm") in new stack
Dec 21 13:44:02 DEBUG[15840] pbx.c: Not taking any branch Dec 21 13:44:02
DEBUG[15840] app_macro.c: Executed application: GotoIf
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
NoOp("Zap/2-1", "Cleaning Up Block VM Flag:
BLKVM/600/Zap/2-1") in new stack
Dec 21 13:44:02 DEBUG[15840] app_macro.c: Executed application: Noop
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
DBdel("Zap/2-1", "BLKVM/600/Zap/2-1") in new stack
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- DBdel: family=BLKVM,
key=600/Zap/2-1
Dec 21 13:44:02 DEBUG[15840] db.c: Unable to find key '600/Zap/2-1' in
family 'BLKVM'
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- DBdel: Error deleting key from
database.
Dec 21 13:44:02 DEBUG[15840] app_macro.c: Executed application: DBDel Dec 21
13:44:02 DEBUG[15840] pbx.c: Expression result is '1'
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
GotoIf("Zap/2-1", "1?theend") in new stack
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Goto (macro-hangupcall,s,11)
Dec 21 13:44:02 DEBUG[15840] app_macro.c: Executed application: GotoIf
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Executing
Hangup("Zap/2-1", "") in new stack
Dec 21 13:44:02 VERBOSE[15840] logger.c: == Spawn extension (macro-hangupcall,
s, 11) exited non-zero on 'Zap/2-1' in macro 'hangupcall'
Dec 21 13:44:02 VERBOSE[15840] logger.c: == Spawn extension (macro-hangupcall,
s, 11) exited non-zero on 'Zap/2-1'
Dec 21 13:44:02 DEBUG[15840] chan_zap.c: Hangup: channel: 2 index = 0, normal =
13, callwait = -1, thirdcall = -1 Dec 21 13:44:02 DEBUG[15840] chan_zap.c:
disabled echo cancellation on channel 2 Dec 21 13:44:02 DEBUG[15840] chan_zap.c:
Set option TDD MODE, value: OFF(0) on Zap/2-1 Dec 21 13:44:02 DEBUG[15840]
chan_zap.c: Updated conferencing on 2, with 0 conference users
Dec 21 13:44:02 VERBOSE[15840] logger.c: -- Hungup 'Zap/2-1'
