Dynamic agent tx call from queue to ext, no vm $200 bounty

I’m really banging my head against the wall on this one.

I have an operator queue defined with no static agents. Dynamic agents log in to the queue as they are required/available. An incoming call is placed into the queue, and answered by an agent. The agent transfers the call to the appropriate person, and the extension does ring. However, if the person receiving the transferred call does not answer, no voicemail picks up and the caller is disconnected. Included below are a couple of log bits that show what’s happening.

The first is a successful transfer-with-voicemail performed by dialing into the auto-attendant IVR, direct-dialing extension 510, picking up the call on extension 510, and transferring the caller to extension 315. The second is the behavior that I’m struggling to understand, where the device rings but no voicemail picks up.

Thanks in advance for any insight/help you can give me…the learning curve is pretty steep and I’m under the gun to get this fixed ASAP.

extension conf files are:

http://pastebin.ca/212335
http://pastebin.ca/212339

EDIT: Added incentive, $100 bounty for a working fix, via PayPal.

Aaron

Oct 19 23:31:47 VERBOSE[8226] logger.c: – Starting simple switch on 'Zap/1-1’
Oct 19 23:31:51 NOTICE[8226] chan_zap.c: Got event 18 (Ring Begin)…
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “FROM_DID=s”) in new stack
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “FAX_RX=disabled”) in new stack
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing Goto(“Zap/1-1”, “timeconditions|1|1”) in new stack
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Goto (timeconditions,1,1)
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing GotoIfTime(“Zap/1-1”, “08:00-23:57|mon-fri||?ivr-2|s|1”) in new stack
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Goto (ivr-2,s,1)
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “LOOPCOUNT=0”) in new stack
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “__DIR-CONTEXT=default”) in new stack
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing Answer(“Zap/1-1”, “”) in new stack
Oct 19 23:31:51 DEBUG[8226] chan_zap.c: Took Zap/1-1 off hook
Oct 19 23:31:51 DEBUG[8226] chan_zap.c: Enabled echo cancellation on channel 1
Oct 19 23:31:51 DEBUG[8226] chan_zap.c: Engaged echo training on channel 1
Oct 19 23:31:51 VERBOSE[8226] logger.c: – Executing Wait(“Zap/1-1”, “1”) in new stack
Oct 19 23:31:51 DEBUG[8226] chan_zap.c: Exception on 15, channel 1
Oct 19 23:31:51 DEBUG[8226] chan_zap.c: Got event Ring/Answered(2) on channel 1 (index 0)
Oct 19 23:31:51 DEBUG[8226] chan_zap.c: Setting IDLE polarity due to ring. Old polarity was 0
Oct 19 23:31:51 WARNING[8226] chan_zap.c: Ring/Off-hook in strange state 6 on channel 1
Oct 19 23:31:52 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “TIMEOUT(digit)=3”) in new stack
Oct 19 23:31:52 VERBOSE[8226] logger.c: – Digit timeout set to 3
Oct 19 23:31:52 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “TIMEOUT(response)=10”) in new stack
Oct 19 23:31:52 VERBOSE[8226] logger.c: – Response timeout set to 10
Oct 19 23:31:52 VERBOSE[8226] logger.c: – Executing BackGround(“Zap/1-1”, “custom/Greeting”) in new stack
Oct 19 23:31:52 DEBUG[8226] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:31:52 VERBOSE[8226] logger.c: – Playing ‘custom/Greeting’ (language ‘en’)
Oct 19 23:31:57 DEBUG[8226] chan_zap.c: DTMF digit: 5 on Zap/1-1
Oct 19 23:31:57 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:31:57 DEBUG[8226] pbx.c: Oooh, got something to jump out with (‘5’)!
Oct 19 23:31:58 DEBUG[8226] chan_zap.c: DTMF digit: 1 on Zap/1-1
Oct 19 23:31:58 DEBUG[8226] chan_zap.c: DTMF digit: 0 on Zap/1-1
Oct 19 23:31:58 VERBOSE[8226] logger.c: == CDR updated on Zap/1-1
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “exten-vm|510|510”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “user-callerid”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?report”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:31:58 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?start”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:31:58 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “REALCALLERIDNUM=”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “REALCALLERIDNUM is “) in new stack
Oct 19 23:31:58 DEBUG[8226] db.c: Unable to find key ‘/user’ in family 'DEVICE’
Oct 19 23:31:58 DEBUG[8226] func_db.c: DB: DEVICE//user not found in database.
Oct 19 23:31:58 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “AMPUSER=”) in new stack
Oct 19 23:31:58 DEBUG[8226] db.c: Unable to find key ‘/cidname’ in family 'AMPUSER’
Oct 19 23:31:58 DEBUG[8226] func_db.c: DB: AMPUSER//cidname not found in database.
Oct 19 23:31:58 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “AMPUSERCIDNAME=”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Expression result is '1’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “1?report”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Goto (macro-user-callerid,s,9)
Oct 19 23:31:58 DEBUG[8226] pbx.c: Function result is '”” <>'
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “Using CallerID “” <>”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “FROMCONTEXT=exten-vm”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “VMBOX=510”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “EXTTOCALL=510”) in new stack
Oct 19 23:31:58 DEBUG[8226] db.c: Unable to find key ‘510’ in family 'CFU’
Oct 19 23:31:58 DEBUG[8226] func_db.c: DB: CFU/510 not found in database.
Oct 19 23:31:58 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “CFUEXT=”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Expression result is '1’
Oct 19 23:31:58 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:31:58 DEBUG[8226] pbx.c: Expression result is '1’
Oct 19 23:31:58 DEBUG[8226] pbx.c: Function result is '15’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “RT=15”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “record-enable|510|IN”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Function result is '0’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0 > 0?2:4”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Goto (macro-record-enable,s,4)
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing AGI(“Zap/1-1”, “recordingcheck|20061019-233158|1161325907.38”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Oct 19 23:31:58 VERBOSE[8226] logger.c: recordingcheck|20061019-233158|1161325907.38: Inbound recording not enabled
Oct 19 23:31:58 VERBOSE[8226] logger.c: – AGI Script recordingcheck completed, returning 0
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “No recording needed”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?dolocaldial|1”) in new stack
Oct 19 23:31:58 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “dial|15|tr|510”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing AGI(“Zap/1-1”, “dialparties.agi”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Oct 19 23:31:58 VERBOSE[8226] logger.c: dialparties.agi: Starting New Dialparties.agi
Oct 19 23:31:58 VERBOSE[8226] logger.c: – dialparties.agi: priority is 1
Oct 19 23:31:58 VERBOSE[8226] logger.c: dialparties.agi: Caller ID name is ‘unknown’ number is 'unknown’
Oct 19 23:31:58 VERBOSE[8226] logger.c: dialparties.agi: Methodology of ring is 'none’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – dialparties.agi: Added extension 510 to extension map
Oct 19 23:31:58 DEBUG[8226] db.c: Unable to find key ‘510’ in family 'CF’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – dialparties.agi: Extension 510 cf is disabled
Oct 19 23:31:58 DEBUG[8226] db.c: Unable to find key ‘510’ in family 'DND’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – dialparties.agi: Extension 510 do not disturb is disabled
Oct 19 23:31:58 DEBUG[8226] db.c: Unable to find key ‘510’ in family 'CFB’
Oct 19 23:31:58 DEBUG[8226] db.c: Unable to find key ‘510’ in family 'CFU’
Oct 19 23:31:58 VERBOSE[8226] logger.c: – dialparties.agi: DbSet CALLTRACE/510 to unknown
Oct 19 23:31:58 VERBOSE[8226] logger.c: – AGI Script dialparties.agi completed, returning 0
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Executing Dial(“Zap/1-1”, “IAX2/510|15|tr”) in new stack
Oct 19 23:31:58 VERBOSE[8226] logger.c: – Called 510
Oct 19 23:31:58 DEBUG[8226] chan_zap.c: Requested indication 3 on channel Zap/1-1
Oct 19 23:31:58 VERBOSE[2345] logger.c: – Call accepted by 71.108.227.111 (format gsm)
Oct 19 23:31:58 VERBOSE[2345] logger.c: – Format for call is gsm
Oct 19 23:31:58 VERBOSE[8226] logger.c: – IAX2/510-6 is ringing
Oct 19 23:32:02 VERBOSE[8226] logger.c: – IAX2/510-6 answered Zap/1-1
Oct 19 23:32:02 DEBUG[8226] chan_zap.c: Requested indication -1 on channel Zap/1-1
Oct 19 23:32:02 DEBUG[2345] chan_iax2.c: Ooh, voice format changed to 2
Oct 19 23:32:09 DEBUG[8226] channel.c: Got DTMF on channel (IAX2/510-6)
Oct 19 23:32:09 DEBUG[8226] channel.c: Bridge stops bridging channels Zap/1-1 and IAX2/510-6
Oct 19 23:32:09 DEBUG[8226] res_features.c: Feature interpret: chan=Zap/1-1, peer=IAX2/510-6, sense=2, features=2
Oct 19 23:32:09 DEBUG[8226] chan_zap.c: Requested indication 16 on channel Zap/1-1
Oct 19 23:32:09 VERBOSE[8226] logger.c: – Started music on hold, class ‘default’, on Zap/1-1
Oct 19 23:32:09 DEBUG[8226] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:32:09 DEBUG[8226] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:32:09 VERBOSE[8226] logger.c: – Playing ‘pbx-transfer’ (language ‘en’)
Oct 19 23:32:09 DEBUG[2658] channel.c: Generator got voice, switching to phase locked mode
Oct 19 23:32:09 DEBUG[2658] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:10 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:10 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:10 DEBUG[8226] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:32:10 DEBUG[8226] channel.c: Generator got voice, switching to phase locked mode
Oct 19 23:32:10 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:11 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:32:11 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:32:11 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:32:11 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Stopped music on hold on Zap/1-1
Oct 19 23:32:12 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:12 DEBUG[8226] chan_zap.c: Requested indication 17 on channel Zap/1-1
Oct 19 23:32:12 DEBUG[8226] chan_iax2.c: We’re hanging up IAX2/510-6 now…
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Hungup 'IAX2/510-6’
Oct 19 23:32:12 DEBUG[8226] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Oct 19 23:32:12 VERBOSE[8226] logger.c: == Channel ‘Zap/1-1’ jumping out of macro 'dial’
Oct 19 23:32:12 VERBOSE[8226] logger.c: == Channel ‘Zap/1-1’ jumping out of macro 'exten-vm’
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “exten-vm|315|315”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “user-callerid”) in new stack
Oct 19 23:32:12 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?report”) in new stack
Oct 19 23:32:12 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:32:12 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?start”) in new stack
Oct 19 23:32:12 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:32:12 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “REALCALLERIDNUM=”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “REALCALLERIDNUM is “) in new stack
Oct 19 23:32:12 DEBUG[8226] db.c: Unable to find key ‘/user’ in family 'DEVICE’
Oct 19 23:32:12 DEBUG[8226] func_db.c: DB: DEVICE//user not found in database.
Oct 19 23:32:12 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “AMPUSER=”) in new stack
Oct 19 23:32:12 DEBUG[8226] db.c: Unable to find key ‘/cidname’ in family 'AMPUSER’
Oct 19 23:32:12 DEBUG[8226] func_db.c: DB: AMPUSER//cidname not found in database.
Oct 19 23:32:12 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “AMPUSERCIDNAME=”) in new stack
Oct 19 23:32:12 DEBUG[8226] pbx.c: Expression result is '1’
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “1?report”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Goto (macro-user-callerid,s,9)
Oct 19 23:32:12 DEBUG[8226] pbx.c: Function result is '”” <>'
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “Using CallerID “” <>”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “FROMCONTEXT=exten-vm”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “VMBOX=315”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “EXTTOCALL=315”) in new stack
Oct 19 23:32:12 DEBUG[8226] db.c: Unable to find key ‘315’ in family 'CFU’
Oct 19 23:32:12 DEBUG[8226] func_db.c: DB: CFU/315 not found in database.
Oct 19 23:32:12 DEBUG[8226] pbx.c: Function result is '‘
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “CFUEXT=”) in new stack
Oct 19 23:32:12 DEBUG[8226] pbx.c: Expression result is ‘1’
Oct 19 23:32:12 DEBUG[8226] pbx.c: Expression result is ‘0’
Oct 19 23:32:12 DEBUG[8226] pbx.c: Expression result is ‘1’
Oct 19 23:32:12 DEBUG[8226] pbx.c: Function result is ‘15’
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “RT=15”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “record-enable|315|IN”) in new stack
Oct 19 23:32:12 DEBUG[8226] pbx.c: Function result is ‘10’
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “10 > 0?2:4”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Goto (macro-record-enable,s,2)
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing ResetCDR(“Zap/1-1”, “w”) in new stack
Oct 19 23:32:12 DEBUG[8226] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Oct 19 23:32:12 DEBUG[8226] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES (‘2006-10-19 23:31:51’,’’,’’,‘315’,‘from-internal’, ‘Zap/1-1’,‘IAX2/510-6’,‘ResetCDR’,‘w’,21,21,‘ANSWERED’,3,’’)
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing StopMonitor(“Zap/1-1”, “”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Executing AGI(“Zap/1-1”, “recordingcheck|20061019-233212|1161325907.38”) in new stack
Oct 19 23:32:12 VERBOSE[8226] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Oct 19 23:32:13 VERBOSE[8226] logger.c: recordingcheck|20061019-233212|1161325907.38: Inbound recording not enabled
Oct 19 23:32:13 VERBOSE[8226] logger.c: – AGI Script recordingcheck completed, returning 0
Oct 19 23:32:13 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “No recording needed”) in new stack
Oct 19 23:32:13 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:13 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?dolocaldial|1”) in new stack
Oct 19 23:32:13 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:32:13 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “dial|15|tr|315”) in new stack
Oct 19 23:32:13 VERBOSE[8226] logger.c: – Executing AGI(“Zap/1-1”, “dialparties.agi”) in new stack
Oct 19 23:32:13 VERBOSE[8226] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Oct 19 23:32:13 VERBOSE[8226] logger.c: dialparties.agi: Starting New Dialparties.agi
Oct 19 23:32:13 VERBOSE[8226] logger.c: – dialparties.agi: priority is 1
Oct 19 23:32:13 VERBOSE[8226] logger.c: dialparties.agi: Caller ID name is ‘unknown’ number is 'unknown’
Oct 19 23:32:13 VERBOSE[8226] logger.c: dialparties.agi: Methodology of ring is 'none’
Oct 19 23:32:13 VERBOSE[8226] logger.c: – dialparties.agi: Added extension 315 to extension map
Oct 19 23:32:13 DEBUG[8226] db.c: Unable to find key ‘315’ in family 'CF’
Oct 19 23:32:13 VERBOSE[8226] logger.c: – dialparties.agi: Extension 315 cf is disabled
Oct 19 23:32:13 DEBUG[8226] db.c: Unable to find key ‘315’ in family 'DND’
Oct 19 23:32:13 VERBOSE[8226] logger.c: – dialparties.agi: Extension 315 do not disturb is disabled
Oct 19 23:32:13 DEBUG[8226] db.c: Unable to find key ‘315’ in family 'CW’
Oct 19 23:32:13 DEBUG[8226] db.c: Unable to find key ‘315’ in family 'CFB’
Oct 19 23:32:13 DEBUG[8226] db.c: Unable to find key ‘315’ in family 'CFU’
Oct 19 23:32:13 DEBUG[8242] manager.c: Manager received command 'login’
Oct 19 23:32:13 VERBOSE[8242] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Oct 19 23:32:13 VERBOSE[8242] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Oct 19 23:32:13 VERBOSE[8242] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Oct 19 23:32:13 VERBOSE[8242] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Oct 19 23:32:13 DEBUG[8242] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Oct 19 23:32:13 DEBUG[8242] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Oct 19 23:32:13 DEBUG[8242] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Oct 19 23:32:13 DEBUG[8242] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Oct 19 23:32:13 VERBOSE[8242] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Oct 19 23:32:13 DEBUG[8242] manager.c: Manager received command 'ExtensionState’
Oct 19 23:32:13 DEBUG[8242] manager.c: Manager received command 'Logoff’
Oct 19 23:32:13 VERBOSE[8242] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Oct 19 23:32:13 VERBOSE[8226] logger.c: – dialparties.agi: Checking CW and CFB status for extension 315
Oct 19 23:32:13 VERBOSE[8226] logger.c: – dialparties.agi: DbSet CALLTRACE/315 to unknown
Oct 19 23:32:13 VERBOSE[8226] logger.c: – AGI Script dialparties.agi completed, returning 0
Oct 19 23:32:13 VERBOSE[8226] logger.c: – Executing Dial(“Zap/1-1”, “SIP/315|15|tr”) in new stack
Oct 19 23:32:13 DEBUG[8226] chan_sip.c: Setting NAT on RTP to 0
Oct 19 23:32:13 DEBUG[8226] chan_sip.c: Outgoing Call for 315
Oct 19 23:32:13 VERBOSE[8226] logger.c: – Called 315
Oct 19 23:32:13 DEBUG[8226] chan_zap.c: Requested indication 3 on channel Zap/1-1
Oct 19 23:32:13 DEBUG[2346] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Oct 19 23:32:13 DEBUG[2346] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Oct 19 23:32:13 DEBUG[2339] channel.c: Avoiding initial deadlock for 'SIP/315-0930ea70’
Oct 19 23:32:13 VERBOSE[8226] logger.c: – SIP/315-0930ea70 is ringing
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Nobody picked up in 15000 ms
Oct 19 23:32:28 DEBUG[8226] chan_zap.c: Requested indication -1 on channel Zap/1-1
Oct 19 23:32:28 DEBUG[8226] chan_sip.c: update_call_counter(315) - decrement call limit counter
Oct 19 23:32:28 DEBUG[8226] chan_sip.c: Acked pending invite 102
Oct 19 23:32:28 DEBUG[8226] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Oct 19 23:32:28 DEBUG[8226] app_dial.c: Exiting with DIALSTATUS=NOANSWER.
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '1’
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing GosubIf(“Zap/1-1”, “0?docfu|1”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “Voicemail is 315”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?s-NOANSWER|1”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “Sending to Voicemail box 315”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “vm|315|NOANSWER”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “user-callerid”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?report”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?start”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Not taking any branch
Oct 19 23:32:28 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “REALCALLERIDNUM=”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “REALCALLERIDNUM is “) in new stack
Oct 19 23:32:28 DEBUG[8226] db.c: Unable to find key ‘/user’ in family 'DEVICE’
Oct 19 23:32:28 DEBUG[8226] func_db.c: DB: DEVICE//user not found in database.
Oct 19 23:32:28 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “AMPUSER=”) in new stack
Oct 19 23:32:28 DEBUG[8226] db.c: Unable to find key ‘/cidname’ in family 'AMPUSER’
Oct 19 23:32:28 DEBUG[8226] func_db.c: DB: AMPUSER//cidname not found in database.
Oct 19 23:32:28 DEBUG[8226] pbx.c: Function result is ''
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “AMPUSERCIDNAME=”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '1’
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “1?report”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Goto (macro-user-callerid,s,9)
Oct 19 23:32:28 DEBUG[8226] pbx.c: Function result is '”” <>'
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “Using CallerID “” <>”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '1’
Oct 19 23:32:28 DEBUG[8226] pbx.c: Function result is 'g(2)'
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “VMGAIN=g(2)”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Goto(“Zap/1-1”, “s-NOANSWER|1”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Goto (macro-vm,s-NOANSWER,1)
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Macro(“Zap/1-1”, “get-vmcontext|315”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Function result is 'default’
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing Set(“Zap/1-1”, “VMCONTEXT=default”) in new stack
Oct 19 23:32:28 DEBUG[8226] pbx.c: Expression result is '0’
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing GotoIf(“Zap/1-1”, “0?200:300”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Goto (macro-get-vmcontext,s,300)
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing NoOp(“Zap/1-1”, “”) in new stack
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Executing VoiceMail(“Zap/1-1”, “315@default|ug(2)”) in new stack
Oct 19 23:32:28 DEBUG[8226] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:32:28 VERBOSE[8226] logger.c: – Playing ‘/var/spool/asterisk/voicemail/default/315/unavail’ (language ‘en’)
Oct 19 23:32:28 DEBUG[2346] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Oct 19 23:32:28 DEBUG[2346] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Not Found
Oct 19 23:32:29 DEBUG[2346] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Oct 19 23:32:36 DEBUG[8226] channel.c: Scheduling timer at 138 sample intervals
Oct 19 23:32:36 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:36 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:36 DEBUG[8226] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:32:36 VERBOSE[8226] logger.c: – Playing ‘vm-intro’ (language ‘en’)
Oct 19 23:32:41 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:32:41 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:32:41 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:32:42 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:42 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:42 DEBUG[8226] app.c: Locked path '/var/spool/asterisk/voicemail/default/315/INBOX’
Oct 19 23:32:42 DEBUG[8226] app.c: Unlocked path '/var/spool/asterisk/voicemail/default/315/INBOX’
Oct 19 23:32:42 DEBUG[8226] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:32:42 VERBOSE[8226] logger.c: – Playing ‘beep’ (language ‘en’)
Oct 19 23:32:42 DEBUG[2346] chan_sip.c: Auto destroying call '[email protected]
Oct 19 23:32:42 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:42 DEBUG[8226] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:32:42 VERBOSE[8226] logger.c: – Recording the message
Oct 19 23:32:42 DEBUG[8226] chan_zap.c: Setting actual rx gain on Zap/1-1 to 10.200000
Oct 19 23:32:42 DEBUG[8226] app.c: play_and_record: , /var/spool/asterisk/voicemail/default/315/tmp/URS6KE, 'wav49|wav’
Oct 19 23:32:42 DEBUG[8226] app.c: Recording Formats: sfmts=wav49
Oct 19 23:32:42 VERBOSE[8226] logger.c: – x=0, open writing: /var/spool/asterisk/voicemail/default/315/tmp/URS6KE format: wav49, 0x928e990
Oct 19 23:32:42 VERBOSE[8226] logger.c: – x=1, open writing: /var/spool/asterisk/voicemail/default/315/tmp/URS6KE format: wav, 0x92969c8
Oct 19 23:32:42 DEBUG[8226] chan_zap.c: Requested indication 18 on channel Zap/1-1
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: Exception on 15, channel 1
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: Got event On hook(1) on channel 1 (index 0)
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: disabled echo cancellation on channel 1
Oct 19 23:32:47 VERBOSE[8226] logger.c: – User hung up
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: Setting actual rx gain on Zap/1-1 to 8.200000
Oct 19 23:32:47 DEBUG[8226] app.c: Locked path ‘/var/spool/asterisk/voicemail/default/315/INBOX’
Oct 19 23:32:47 DEBUG[8226] app.c: Unlocked path ‘/var/spool/asterisk/voicemail/default/315/INBOX’
Oct 19 23:32:47 DEBUG[8226] app_voicemail.c: Attaching file ‘/var/spool/asterisk/voicemail/default/315/INBOX/msg0003’, format ‘WAV’, uservm is ‘2048’, global is 2048
Oct 19 23:32:47 DEBUG[8226] app_voicemail.c: Sent mail to [email protected] with command ‘/usr/sbin/sendmail -t’
Oct 19 23:32:47 VERBOSE[8226] logger.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘Zap/1-1’ in macro ‘vm’
Oct 19 23:32:47 VERBOSE[8226] logger.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘Zap/1-1’ in macro ‘exten-vm’
Oct 19 23:32:47 VERBOSE[8226] logger.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘Zap/1-1’
Oct 19 23:32:47 DEBUG[8226] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Oct 19 23:32:47 DEBUG[8226] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES (‘2006-10-19 23:32:12’,’’,’’,‘315’,‘from-internal’, ‘Zap/1-1’,‘SIP/315-0930ea70’,‘VoiceMail’,‘315@default|ug(2)’,35,0,‘NO ANSWER’,3,’’)
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: Hangup: channel: 1 index = 0, normal = 15, callwait = -1, thirdcall = -1
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: disabled echo cancellation on channel 1
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Oct 19 23:32:47 DEBUG[8226] chan_zap.c: Updated conferencing on 1, with 0 conference users
Oct 19 23:32:47 VERBOSE[8226] logger.c: – Hungup ‘Zap/1-1’

Oct 19 23:33:03 VERBOSE[8267] logger.c: – Starting simple switch on 'Zap/1-1’
Oct 19 23:33:07 NOTICE[8267] chan_zap.c: Got event 18 (Ring Begin)…
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “FROM_DID=s”) in new stack
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “FAX_RX=disabled”) in new stack
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing Goto(“Zap/1-1”, “timeconditions|1|1”) in new stack
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Goto (timeconditions,1,1)
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing GotoIfTime(“Zap/1-1”, “08:00-23:57|mon-fri||?ivr-2|s|1”) in new stack
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Goto (ivr-2,s,1)
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “LOOPCOUNT=0”) in new stack
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “__DIR-CONTEXT=default”) in new stack
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing Answer(“Zap/1-1”, “”) in new stack
Oct 19 23:33:07 DEBUG[8267] chan_zap.c: Took Zap/1-1 off hook
Oct 19 23:33:07 DEBUG[8267] chan_zap.c: Enabled echo cancellation on channel 1
Oct 19 23:33:07 DEBUG[8267] chan_zap.c: Engaged echo training on channel 1
Oct 19 23:33:07 VERBOSE[8267] logger.c: – Executing Wait(“Zap/1-1”, “1”) in new stack
Oct 19 23:33:07 DEBUG[8267] chan_zap.c: Exception on 15, channel 1
Oct 19 23:33:07 DEBUG[8267] chan_zap.c: Got event Ring/Answered(2) on channel 1 (index 0)
Oct 19 23:33:07 DEBUG[8267] chan_zap.c: Setting IDLE polarity due to ring. Old polarity was 0
Oct 19 23:33:07 WARNING[8267] chan_zap.c: Ring/Off-hook in strange state 6 on channel 1
Oct 19 23:33:08 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “TIMEOUT(digit)=3”) in new stack
Oct 19 23:33:08 VERBOSE[8267] logger.c: – Digit timeout set to 3
Oct 19 23:33:08 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “TIMEOUT(response)=10”) in new stack
Oct 19 23:33:08 VERBOSE[8267] logger.c: – Response timeout set to 10
Oct 19 23:33:08 VERBOSE[8267] logger.c: – Executing BackGround(“Zap/1-1”, “custom/Greeting”) in new stack
Oct 19 23:33:08 DEBUG[8267] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:33:08 VERBOSE[8267] logger.c: – Playing ‘custom/Greeting’ (language ‘en’)
Oct 19 23:33:11 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:33:11 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:33:11 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:33:13 DEBUG[8267] chan_zap.c: DTMF digit: 0 on Zap/1-1
Oct 19 23:33:13 DEBUG[8267] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:13 DEBUG[8267] pbx.c: Oooh, got something to jump out with (‘0’)!
Oct 19 23:33:13 VERBOSE[8267] logger.c: == CDR updated on Zap/1-1
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Executing Goto(“Zap/1-1”, “ext-queues|100|1”) in new stack
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Goto (ext-queues,100,1)
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Executing Answer(“Zap/1-1”, “”) in new stack
Oct 19 23:33:13 DEBUG[8267] pbx.c: Expression result is '0’
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Executing GotoIf(“Zap/1-1”, “0?USERCID:SETCID”) in new stack
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Goto (ext-queues,100,4)
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “CALLERID(name)=OPQueue”) in new stack
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Executing Set(“Zap/1-1”, “MONITOR_FILENAME=/var/spool/asterisk/monitor/q100-20061019-233313-1161325983.43”) in new stack
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Executing Playback(“Zap/1-1”, “custom/OPQueueInitial”) in new stack
Oct 19 23:33:13 DEBUG[8267] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:33:13 VERBOSE[8267] logger.c: – Playing ‘custom/OPQueueInitial’ (language ‘en’)
Oct 19 23:33:18 DEBUG[8267] channel.c: Scheduling timer at 30 sample intervals
Oct 19 23:33:18 DEBUG[8267] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:18 DEBUG[8267] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:18 VERBOSE[8267] logger.c: – Executing Queue(“Zap/1-1”, “100|t||custom/OPQueueCall”) in new stack
Oct 19 23:33:18 VERBOSE[8267] logger.c: – Started music on hold, class ‘default’, on Zap/1-1
Oct 19 23:33:18 DEBUG[8267] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:33:18 VERBOSE[8267] logger.c: – Called Local/510@from-internal/n
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “exten-vm|510|510”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “user-callerid”) in new stack
Oct 19 23:33:18 DEBUG[8276] pbx.c: Expression result is '1’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing GotoIf(“Local/510@from-internal-aef9,2”, “1?report”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Goto (macro-user-callerid,s,9)
Oct 19 23:33:18 DEBUG[8276] pbx.c: Function result is '“OPQueue” <>'
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing NoOp(“Local/510@from-internal-aef9,2”, “Using CallerID “OPQueue” <>”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “FROMCONTEXT=exten-vm”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “VMBOX=510”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “EXTTOCALL=510”) in new stack
Oct 19 23:33:18 DEBUG[8276] db.c: Unable to find key ‘510’ in family 'CFU’
Oct 19 23:33:18 DEBUG[8276] func_db.c: DB: CFU/510 not found in database.
Oct 19 23:33:18 DEBUG[8276] pbx.c: Function result is ''
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “CFUEXT=”) in new stack
Oct 19 23:33:18 DEBUG[8276] pbx.c: Expression result is '1’
Oct 19 23:33:18 DEBUG[8276] pbx.c: Expression result is '0’
Oct 19 23:33:18 DEBUG[8276] pbx.c: Expression result is '1’
Oct 19 23:33:18 DEBUG[8276] pbx.c: Function result is '15’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “RT=15”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “record-enable|510|IN”) in new stack
Oct 19 23:33:18 DEBUG[8276] pbx.c: Function result is '0’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing GotoIf(“Local/510@from-internal-aef9,2”, “0 > 0?2:4”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Goto (macro-record-enable,s,4)
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing AGI(“Local/510@from-internal-aef9,2”, “recordingcheck|20061019-233318|1161325998.45”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Oct 19 23:33:18 DEBUG[8267] channel.c: Generator got voice, switching to phase locked mode
Oct 19 23:33:18 DEBUG[8267] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:18 VERBOSE[8276] logger.c: recordingcheck|20061019-233318|1161325998.45: Inbound recording not enabled
Oct 19 23:33:18 VERBOSE[8276] logger.c: – AGI Script recordingcheck completed, returning 0
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing NoOp(“Local/510@from-internal-aef9,2”, “No recording needed”) in new stack
Oct 19 23:33:18 DEBUG[8276] pbx.c: Expression result is '1’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing GotoIf(“Local/510@from-internal-aef9,2”, “1?dolocaldial|1”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Goto (macro-exten-vm,dolocaldial,1)
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “dial||tr|510”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing AGI(“Local/510@from-internal-aef9,2”, “dialparties.agi”) in new stack
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Oct 19 23:33:18 VERBOSE[8276] logger.c: dialparties.agi: Starting New Dialparties.agi
Oct 19 23:33:18 VERBOSE[8276] logger.c: – dialparties.agi: priority is 1
Oct 19 23:33:18 VERBOSE[8276] logger.c: dialparties.agi: Caller ID name is ‘OPQueue’ number is 'unknown’
Oct 19 23:33:18 VERBOSE[8276] logger.c: dialparties.agi: Methodology of ring is 'none’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – dialparties.agi: Added extension 510 to extension map
Oct 19 23:33:18 DEBUG[8276] db.c: Unable to find key ‘510’ in family 'CF’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – dialparties.agi: Extension 510 cf is disabled
Oct 19 23:33:18 DEBUG[8276] db.c: Unable to find key ‘510’ in family 'DND’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – dialparties.agi: Extension 510 do not disturb is disabled
Oct 19 23:33:18 DEBUG[8276] db.c: Unable to find key ‘510’ in family 'CFB’
Oct 19 23:33:18 DEBUG[8276] db.c: Unable to find key ‘510’ in family 'CFU’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – dialparties.agi: DbSet CALLTRACE/510 to unknown
Oct 19 23:33:18 VERBOSE[8276] logger.c: – AGI Script dialparties.agi completed, returning 0
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Executing Dial(“Local/510@from-internal-aef9,2”, “IAX2/510||tr”) in new stack
Oct 19 23:33:18 DEBUG[2339] channel.c: Avoiding initial deadlock for 'IAX2/510-6’
Oct 19 23:33:18 VERBOSE[8276] logger.c: – Called 510
Oct 19 23:33:18 VERBOSE[8267] logger.c: – Local/510@from-internal-aef9,1 is ringing
Oct 19 23:33:18 VERBOSE[2345] logger.c: – Call accepted by 71.108.227.111 (format gsm)
Oct 19 23:33:18 VERBOSE[2345] logger.c: – Format for call is gsm
Oct 19 23:33:18 VERBOSE[8276] logger.c: – IAX2/510-6 is ringing
Oct 19 23:33:20 DEBUG[2339] channel.c: Avoiding initial deadlock for 'IAX2/510-6’
Oct 19 23:33:20 VERBOSE[8276] logger.c: – IAX2/510-6 answered Local/510@from-internal-aef9,2
Oct 19 23:33:20 DEBUG[8267] app_queue.c: Dunno what to do with control type -1
Oct 19 23:33:20 VERBOSE[8267] logger.c: – Local/510@from-internal-aef9,1 answered Zap/1-1
Oct 19 23:33:20 DEBUG[8267] chan_zap.c: Set option TONE VERIFY, mode: MUTECONF(1) on Zap/1-1
Oct 19 23:33:20 DEBUG[8267] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:33:20 VERBOSE[8267] logger.c: – Playing ‘custom/OPQueueCall’ (language ‘en’)
Oct 19 23:33:20 DEBUG[2345] chan_iax2.c: Ooh, voice format changed to 2
Oct 19 23:33:22 DEBUG[8267] channel.c: Scheduling timer at 125 sample intervals
Oct 19 23:33:22 DEBUG[8267] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:22 DEBUG[8267] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:22 VERBOSE[8267] logger.c: – Stopped music on hold on Zap/1-1
Oct 19 23:33:22 DEBUG[8267] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:26 DEBUG[8276] channel.c: Got DTMF on channel (IAX2/510-6)
Oct 19 23:33:26 DEBUG[8276] channel.c: Bridge stops bridging channels Local/510@from-internal-aef9,2 and IAX2/510-6
Oct 19 23:33:26 DEBUG[8276] res_features.c: Feature interpret: chan=Local/510@from-internal-aef9,2, peer=IAX2/510-6, sense=2, features=2
Oct 19 23:33:26 VERBOSE[8276] logger.c: – Started music on hold, class ‘default’, on Local/510@from-internal-aef9,2
Oct 19 23:33:26 DEBUG[8276] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:33:26 DEBUG[8276] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:33:26 VERBOSE[8276] logger.c: – Playing ‘pbx-transfer’ (language ‘en’)
Oct 19 23:33:26 DEBUG[8267] chan_zap.c: Requested indication 16 on channel Zap/1-1
Oct 19 23:33:26 DEBUG[2658] channel.c: Generator got voice, switching to phase locked mode
Oct 19 23:33:26 DEBUG[2658] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:27 DEBUG[8276] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:27 DEBUG[8276] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:27 DEBUG[8276] channel.c: Scheduling timer at 160 sample intervals
Oct 19 23:33:27 DEBUG[8276] channel.c: Generator got voice, switching to phase locked mode
Oct 19 23:33:27 DEBUG[8276] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:28 DEBUG[8276] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Stopped music on hold on Local/510@from-internal-aef9,2
Oct 19 23:33:31 DEBUG[8276] channel.c: Scheduling timer at 0 sample intervals
Oct 19 23:33:31 DEBUG[8276] chan_iax2.c: We’re hanging up IAX2/510-6 now…
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Hungup 'IAX2/510-6’
Oct 19 23:33:31 DEBUG[8276] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Oct 19 23:33:31 VERBOSE[8276] logger.c: == Channel ‘Local/510@from-internal-aef9,2’ jumping out of macro 'dial’
Oct 19 23:33:31 VERBOSE[8276] logger.c: == Channel ‘Local/510@from-internal-aef9,2’ jumping out of macro 'exten-vm’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “exten-vm|315|315”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “user-callerid”) in new stack
Oct 19 23:33:31 DEBUG[8276] pbx.c: Expression result is '1’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing GotoIf(“Local/510@from-internal-aef9,2”, “1?report”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Goto (macro-user-callerid,s,9)
Oct 19 23:33:31 DEBUG[8276] pbx.c: Function result is '“OPQueue” <>'
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing NoOp(“Local/510@from-internal-aef9,2”, “Using CallerID “OPQueue” <>”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “FROMCONTEXT=exten-vm”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “VMBOX=315”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “EXTTOCALL=315”) in new stack
Oct 19 23:33:31 DEBUG[8276] db.c: Unable to find key ‘315’ in family 'CFU’
Oct 19 23:33:31 DEBUG[8276] func_db.c: DB: CFU/315 not found in database.
Oct 19 23:33:31 DEBUG[8276] pbx.c: Function result is ''
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “CFUEXT=”) in new stack
Oct 19 23:33:31 DEBUG[8276] pbx.c: Expression result is '1’
Oct 19 23:33:31 DEBUG[8276] pbx.c: Expression result is ‘0’
Oct 19 23:33:31 DEBUG[8276] pbx.c: Expression result is ‘1’
Oct 19 23:33:31 DEBUG[8276] pbx.c: Function result is ‘15’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Set(“Local/510@from-internal-aef9,2”, “RT=15”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “record-enable|315|IN”) in new stack
Oct 19 23:33:31 DEBUG[8276] pbx.c: Function result is ‘10’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing GotoIf(“Local/510@from-internal-aef9,2”, “10 > 0?2:4”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Goto (macro-record-enable,s,2)
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing ResetCDR(“Local/510@from-internal-aef9,2”, “w”) in new stack
Oct 19 23:33:31 DEBUG[8267] chan_zap.c: Requested indication 17 on channel Zap/1-1
Oct 19 23:33:31 DEBUG[8276] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Oct 19 23:33:31 DEBUG[8276] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES (‘2006-10-19 23:33:18’,‘OPQueue’,’’,‘315’,‘from-internal’, ‘Local/510@from-internal-aef9,2’,‘IAX2/510-6’,‘ResetCDR’,‘w’,13,11,‘ANSWERED’,3,’’)
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing StopMonitor(“Local/510@from-internal-aef9,2”, “”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing AGI(“Local/510@from-internal-aef9,2”, “recordingcheck|20061019-233331|1161325998.45”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Oct 19 23:33:31 VERBOSE[8276] logger.c: recordingcheck|20061019-233331|1161325998.45: Inbound recording not enabled
Oct 19 23:33:31 VERBOSE[8276] logger.c: – AGI Script recordingcheck completed, returning 0
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing NoOp(“Local/510@from-internal-aef9,2”, “No recording needed”) in new stack
Oct 19 23:33:31 DEBUG[8276] pbx.c: Expression result is '1’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing GotoIf(“Local/510@from-internal-aef9,2”, “1?dolocaldial|1”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Goto (macro-exten-vm,dolocaldial,1)
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “dial||tr|315”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing AGI(“Local/510@from-internal-aef9,2”, “dialparties.agi”) in new stack
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Oct 19 23:33:31 VERBOSE[8276] logger.c: dialparties.agi: Starting New Dialparties.agi
Oct 19 23:33:31 VERBOSE[8276] logger.c: – dialparties.agi: priority is 1
Oct 19 23:33:31 VERBOSE[8276] logger.c: dialparties.agi: Caller ID name is ‘OPQueue’ number is 'unknown’
Oct 19 23:33:31 VERBOSE[8276] logger.c: dialparties.agi: Methodology of ring is 'none’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – dialparties.agi: Added extension 315 to extension map
Oct 19 23:33:31 DEBUG[8276] db.c: Unable to find key ‘315’ in family 'CF’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – dialparties.agi: Extension 315 cf is disabled
Oct 19 23:33:31 DEBUG[8276] db.c: Unable to find key ‘315’ in family 'DND’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – dialparties.agi: Extension 315 do not disturb is disabled
Oct 19 23:33:31 DEBUG[8276] db.c: Unable to find key ‘315’ in family 'CW’
Oct 19 23:33:31 DEBUG[8276] db.c: Unable to find key ‘315’ in family 'CFB’
Oct 19 23:33:31 DEBUG[8276] db.c: Unable to find key ‘315’ in family 'CFU’
Oct 19 23:33:31 DEBUG[8289] manager.c: Manager received command 'login’
Oct 19 23:33:31 VERBOSE[8289] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Oct 19 23:33:31 VERBOSE[8289] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: Found
Oct 19 23:33:31 VERBOSE[8289] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Oct 19 23:33:31 VERBOSE[8289] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: Found
Oct 19 23:33:31 DEBUG[8289] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Oct 19 23:33:31 DEBUG[8289] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Oct 19 23:33:31 DEBUG[8289] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Oct 19 23:33:31 DEBUG[8289] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Oct 19 23:33:31 VERBOSE[8289] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
Oct 19 23:33:31 DEBUG[8289] manager.c: Manager received command 'ExtensionState’
Oct 19 23:33:31 DEBUG[8289] manager.c: Manager received command 'Logoff’
Oct 19 23:33:31 VERBOSE[8289] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
Oct 19 23:33:31 VERBOSE[8276] logger.c: – dialparties.agi: Checking CW and CFB status for extension 315
Oct 19 23:33:31 VERBOSE[8276] logger.c: – dialparties.agi: DbSet CALLTRACE/315 to unknown
Oct 19 23:33:31 VERBOSE[8276] logger.c: – AGI Script dialparties.agi completed, returning 0
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Executing Dial(“Local/510@from-internal-aef9,2”, “SIP/315||tr”) in new stack
Oct 19 23:33:31 DEBUG[8276] chan_sip.c: Setting NAT on RTP to 0
Oct 19 23:33:31 DEBUG[8276] chan_sip.c: Outgoing Call for 315
Oct 19 23:33:31 VERBOSE[8276] logger.c: – Called 315
Oct 19 23:33:31 DEBUG[8267] channel.c: Got a FRAME_CONTROL (3) frame on channel Local/510@from-internal-aef9,1
Oct 19 23:33:31 DEBUG[8267] channel.c: Bridge stops bridging channels Zap/1-1 and Local/510@from-internal-aef9,1
Oct 19 23:33:31 DEBUG[8267] chan_zap.c: Requested indication 3 on channel Zap/1-1
Oct 19 23:33:31 DEBUG[2346] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Oct 19 23:33:31 DEBUG[2346] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Oct 19 23:33:31 DEBUG[2339] channel.c: Avoiding initial deadlock for 'SIP/315-0930ea70’
Oct 19 23:33:31 VERBOSE[8276] logger.c: – SIP/315-0930ea70 is ringing
Oct 19 23:33:39 DEBUG[2346] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Oct 19 23:33:39 DEBUG[2346] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Oct 19 23:33:41 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:33:41 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:33:41 DEBUG[8056] manager.c: Manager received command 'Command’
Oct 19 23:33:45 DEBUG[2346] chan_sip.c: Auto destroying call '[email protected]
Oct 19 23:33:45 DEBUG[2346] chan_sip.c: Auto destroying call ‘[email protected]
Oct 19 23:34:11 DEBUG[8056] manager.c: Manager received command ‘Command’
Oct 19 23:34:11 DEBUG[8056] manager.c: Manager received command ‘Command’
Oct 19 23:34:11 DEBUG[8056] manager.c: Manager received command ‘Command’
Oct 19 23:34:31 DEBUG[2346] chan_sip.c: Acked pending invite 102
Oct 19 23:34:31 DEBUG[2346] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Oct 19 23:34:31 VERBOSE[2346] logger.c: – Got SIP response 603 “Decline” back from 192.168.2.94
Oct 19 23:34:31 VERBOSE[8276] logger.c: – SIP/315-0930ea70 is busy
Oct 19 23:34:31 DEBUG[8276] chan_sip.c: update_call_counter(315) - decrement call limit counter
Oct 19 23:34:31 VERBOSE[8276] logger.c: == Everyone is busy/congested at this time (1:1/0/0)
Oct 19 23:34:31 DEBUG[8276] app_dial.c: Exiting with DIALSTATUS=BUSY.
Oct 19 23:34:31 VERBOSE[8276] logger.c: – Executing NoOp(“Local/510@from-internal-aef9,2”, “Returned to dolocaldial with DIALSTATUS BUSY”) in new stack
Oct 19 23:34:31 VERBOSE[8276] logger.c: – Executing Hangup(“Local/510@from-internal-aef9,2”, “”) in new stack
Oct 19 23:34:31 VERBOSE[8276] logger.c: == Spawn extension (from-internal, 315, 2) exited non-zero on ‘Local/510@from-internal-aef9,2’
Oct 19 23:34:31 VERBOSE[8276] logger.c: – Executing Macro(“Local/510@from-internal-aef9,2”, “hangupcall”) in new stack
Oct 19 23:34:31 VERBOSE[8276] logger.c: – Executing ResetCDR(“Local/510@from-internal-aef9,2”, “w”) in new stack
Oct 19 23:34:31 DEBUG[8267] channel.c: Got a FRAME_CONTROL (-1) frame on channel Local/510@from-internal-aef9,1
Oct 19 23:34:31 DEBUG[8267] channel.c: Bridge stops bridging channels Zap/1-1 and Local/510@from-internal-aef9,1
Oct 19 23:34:31 DEBUG[8267] chan_zap.c: Requested indication -1 on channel Zap/1-1
Oct 19 23:34:31 DEBUG[8276] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Oct 19 23:34:31 DEBUG[8276] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES (‘2006-10-19 23:33:31’,‘OPQueue’,’’,‘315’,‘from-internal’, ‘Local/510@from-internal-aef9,2’,‘SIP/315-0930ea70’,‘ResetCDR’,‘w’,60,0,‘BUSY’,3,’’)
Oct 19 23:34:31 VERBOSE[8276] logger.c: – Executing NoCDR(“Local/510@from-internal-aef9,2”, “”) in new stack
Oct 19 23:34:31 WARNING[8276] cdr.c: CDR on channel ‘Local/510@from-internal-aef9,2’ not posted
Oct 19 23:34:31 WARNING[8276] cdr.c: CDR on channel ‘Local/510@from-internal-aef9,2’ lacks end
Oct 19 23:34:31 VERBOSE[8276] logger.c: – Executing Wait(“Local/510@from-internal-aef9,2”, “5”) in new stack
Oct 19 23:34:36 VERBOSE[8276] logger.c: – Executing Hangup(“Local/510@from-internal-aef9,2”, “”) in new stack
Oct 19 23:34:36 VERBOSE[8276] logger.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘Local/510@from-internal-aef9,2’ in macro ‘hangupcall’
Oct 19 23:34:36 VERBOSE[8276] logger.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘Local/510@from-internal-aef9,2’
Oct 19 23:34:36 DEBUG[8267] channel.c: Didn’t get a frame from channel: Local/510@from-internal-aef9,1
Oct 19 23:34:36 DEBUG[8267] channel.c: Bridge stops bridging channels Zap/1-1 and Local/510@from-internal-aef9,1
Oct 19 23:34:36 VERBOSE[8267] logger.c: == Spawn extension (ext-queues, 100, 7) exited non-zero on ‘Zap/1-1’
Oct 19 23:34:36 DEBUG[8267] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Oct 19 23:34:36 DEBUG[8267] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES (‘2006-10-19 23:33:07’,‘OPQueue’,’’,‘100’,‘ext-queues’, ‘Zap/1-1’,‘Local/510@from-internal-aef9,1’,‘Queue’,‘100|t||custom/OPQueueCall’,89,89,‘ANSWERED’,3,’’)
Oct 19 23:34:36 DEBUG[8267] chan_zap.c: Hangup: channel: 1 index = 0, normal = 15, callwait = -1, thirdcall = -1
Oct 19 23:34:36 DEBUG[8267] chan_zap.c: disabled echo cancellation on channel 1
Oct 19 23:34:36 DEBUG[8267] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Oct 19 23:34:36 DEBUG[8267] chan_zap.c: Updated conferencing on 1, with 0 conference users
Oct 19 23:34:36 VERBOSE[8267] logger.c: – Hungup ‘Zap/1-1’

bump…$150USD for a solution.

$200.

update: Kerry_G has posted a bug report. I’ll update this thread as info comes in.

BTW, I am getting by the issue, temporarily, by using FollowMe. I have the user’s extension listed only, and VM as a fall-back location.

The same problem exists with dynamic agents (like Agent/2004) doing external attended transfers.

Agent logs on dynamically.
Receives queue call.
Does attended transfer and talks to third party before disconnecting.
Completes transfer.

Now the original caller gets disconnected, while the third party remains connected. The agent has hung up. This leaves the third party connected but with dead air.

This is a BIG problem for my call center customer!