...Previous Successful call
[Jan 28 11:01:31] DEBUG[18583] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 28 11:01:31] DEBUG[18583] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 28 11:01:31] DEBUG[18583] devicestate.c: device 'DAHDI/29-1' state '2'
[Jan 28 11:01:31] DEBUG[18580] app_queue.c: Device 'DAHDI/29-1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Goto'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [9100@incoming:1] Goto("DAHDI/29-1", "ivr2-bdt-main,s,1") in new stack
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Goto (ivr2-bdt-main,s,1)
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is 'Thu Jan 28 11:01:31 2010'
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Verbose'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:1] Verbose("DAHDI/29-1", "0,Time=Thu Jan 28 11:01:31 2010") in new stack
[Jan 28 11:01:31] VERBOSE[28137] app_verbose.c: Time=Thu Jan 28 11:01:31 2010
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is '9100'
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Verbose'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:2] Verbose("DAHDI/29-1", "0,'' IVR Main called '9100' IAXVAR='' ") in new stack
[Jan 28 11:01:31] VERBOSE[28137] app_verbose.c: '' IVR Main called '9100' IAXVAR='' 
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Ringing'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:3] Ringing("DAHDI/29-1", "") in new stack
[Jan 28 11:01:31] VERBOSE[18583] chan_dahdi.c:     -- Accepting call from '' to '9100' on channel 0/29, span 1
[Jan 28 11:01:31] DEBUG[18583] chan_dahdi.c: Enabled echo cancellation on channel 29
[Jan 28 11:01:31] DEBUG[28137] chan_dahdi.c: Requested indication 3 on channel DAHDI/29-1
[Jan 28 11:01:31] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:31] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:31] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:31] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:31] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:31] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:31] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'MYSQL'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:4] MYSQL("DAHDI/29-1", "Connect connid localhost database user password") in new stack
[Jan 28 11:01:31] DEBUG[18573] devicestate.c: Changing state for DAHDI/29 - state 6 (Ringing)
[Jan 28 11:01:31] DEBUG[18573] devicestate.c: device 'DAHDI/29' state '6'
[Jan 28 11:01:31] DEBUG[18580] app_queue.c: Device 'DAHDI/29' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'MYSQL'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:5] MYSQL("DAHDI/29-1", "Query resultid 1 SELECT number, name, staff FROM mobiles WHERE number='0'") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'MYSQL'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:6] MYSQL("DAHDI/29-1", "Fetch fetchid 2 in-number in-name staff") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'MYSQL'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:7] MYSQL("DAHDI/29-1", "Clear 2") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'MYSQL'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:8] MYSQL("DAHDI/29-1", "Disconnect 1") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:9] Set("DAHDI/29-1", "CALLERID(name)=") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Verbose'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:10] Verbose("DAHDI/29-1", "0,'' Caller name= number= staff=") in new stack
[Jan 28 11:01:31] VERBOSE[28137] app_verbose.c: '' Caller name= number= staff=
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is '9100'
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:11] Set("DAHDI/29-1", "caller_dnid=9100") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:12] Set("DAHDI/29-1", "queue_reception=5066") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:13] Set("DAHDI/29-1", "queue_sales_product=5053") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:14] Set("DAHDI/29-1", "queue_spare_parts=5833") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:15] Set("DAHDI/29-1", "queue_technical_support=5023") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:16] Set("DAHDI/29-1", "queue_night_bell=4925") in new stack
[Jan 28 11:01:31] DEBUG[28137] pbx.c: Launching 'Wait'
[Jan 28 11:01:31] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:17] Wait("DAHDI/29-1", "3") in new stack
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'Answer'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:18] Answer("DAHDI/29-1", "") in new stack
[Jan 28 11:01:34] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:34] DEBUG[28137] chan_dahdi.c: Requested indication -1 on channel DAHDI/29-1
[Jan 28 11:01:34] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:34] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:34] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c65ea8'
[Jan 28 11:01:34] DEBUG[18573] devicestate.c: Changing state for DAHDI/29 - state 2 (In use)
[Jan 28 11:01:34] DEBUG[18573] devicestate.c: device 'DAHDI/29' state '2'
[Jan 28 11:01:34] DEBUG[18580] app_queue.c: Device 'DAHDI/29' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:19] Set("DAHDI/29-1", "CDR(userfield)=9100") in new stack
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:20] GotoIfTime("DAHDI/29-1", "8:30-17:00,mon-fri,,?:ivr2-bdt-night,s,1") in new stack
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Not taking any branch
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:21] GotoIfTime("DAHDI/29-1", ",,25-28,dec,?ivr2-bdt-holiday,s,1") in new stack
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Not taking any branch
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:22] GotoIfTime("DAHDI/29-1", ",,1-4,jan,?ivr2-bdt-holiday,s,1") in new stack
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Not taking any branch
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:23] GotoIfTime("DAHDI/29-1", ",,25,jan,?ivr2-bdt-holiday,s,1") in new stack
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Not taking any branch
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-main:24] GotoIfTime("DAHDI/29-1", ",,26-31,jan,?ivr2-bdt-day-noreception,s,1") in new stack
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Goto (ivr2-bdt-day-noreception,s,1)
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-day-noreception:1] Set("DAHDI/29-1", "queue_reception=5053") in new stack
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'Goto'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-day-noreception:2] Goto("DAHDI/29-1", "ivr2-bdt-day,s,1") in new stack
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Goto (ivr2-bdt-day,s,1)
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'Verbose'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-day:1] Verbose("DAHDI/29-1", "0,'' IVR MAIN-DAY") in new stack
[Jan 28 11:01:34] VERBOSE[28137] app_verbose.c: '' IVR MAIN-DAY
[Jan 28 11:01:34] DEBUG[28137] pbx.c: Launching 'BackGround'
[Jan 28 11:01:34] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-day:2] BackGround("DAHDI/29-1", "silence/1") in new stack
[Jan 28 11:01:34] DEBUG[28137] channel.c: Set channel DAHDI/29-1 to write format gsm
[Jan 28 11:01:34] DEBUG[28137] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jan 28 11:01:34] VERBOSE[28137] file.c:     -- <DAHDI/29-1> Playing 'silence/1.gsm' (language 'en')
[Jan 28 11:01:35] DEBUG[28137] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:01:35] DEBUG[28137] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:01:35] DEBUG[28137] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:01:35] DEBUG[28137] channel.c: Set channel DAHDI/29-1 to write format alaw
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Function result is '9100'
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Expression result is '0'
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Launching 'GotoIf'
[Jan 28 11:01:35] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-day:3] GotoIf("DAHDI/29-1", "0?staff") in new stack
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Not taking any branch
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Expression result is '0'
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Launching 'GotoIf'
[Jan 28 11:01:35] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-day:4] GotoIf("DAHDI/29-1", "0?staff") in new stack
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Not taking any branch
[Jan 28 11:01:35] DEBUG[28137] pbx.c: Launching 'BackGround'
[Jan 28 11:01:35] VERBOSE[28137] pbx.c:     -- Executing [s@ivr2-bdt-day:5] BackGround("DAHDI/29-1", "bdt/mainbdt-day") in new stack
[Jan 28 11:01:35] DEBUG[28137] channel.c: Set channel DAHDI/29-1 to write format gsm
[Jan 28 11:01:35] DEBUG[28137] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jan 28 11:01:35] VERBOSE[28137] file.c:     -- <DAHDI/29-1> Playing 'bdt/mainbdt-day.gsm' (language 'en')
[Jan 28 11:01:45] DEBUG[28137] chan_dahdi.c: DTMF digit: 2 on DAHDI/29-1
[Jan 28 11:01:45] DEBUG[28137] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:01:45] DEBUG[28137] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:01:45] DEBUG[28137] channel.c: Set channel DAHDI/29-1 to write format alaw
[Jan 28 11:01:45] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:01:45] DEBUG[28137] pbx.c: Launching 'Verbose'
[Jan 28 11:01:45] VERBOSE[28137] pbx.c:     -- Executing [2@ivr2-bdt-day:1] Verbose("DAHDI/29-1", "0,'' Pressed 2, Product Sales and Enquiry") in new stack
[Jan 28 11:01:45] VERBOSE[28137] app_verbose.c: '' Pressed 2, Product Sales and Enquiry
[Jan 28 11:01:45] DEBUG[28137] pbx.c: Launching 'Set'
[Jan 28 11:01:45] VERBOSE[28137] pbx.c:     -- Executing [2@ivr2-bdt-day:2] Set("DAHDI/29-1", "CDR(userfield)=9100-PRODUCT_SALES") in new stack
[Jan 28 11:01:45] DEBUG[28137] pbx.c: Launching 'Dial'
[Jan 28 11:01:45] VERBOSE[28137] pbx.c:     -- Executing [2@ivr2-bdt-day:3] Dial("DAHDI/29-1", "DAHDI/g0/5053") in new stack
[Jan 28 11:01:45] DEBUG[28137] chan_dahdi.c: Using channel 3
[Jan 28 11:01:45] DEBUG[28137] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 28 11:01:45] DEBUG[28137] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 28 11:01:45] DEBUG[28137] devicestate.c: device 'DAHDI/3-1' state '2'
[Jan 28 11:01:45] DEBUG[28137] rtp.c: Channel 'DAHDI/3-1' has no RTP, not doing anything
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable DIALEDTIME.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable ANSWEREDTIME.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable DIALEDPEERNAME.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable DIALEDPEERNUMBER.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable DIALSTATUS.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable BACKGROUNDSTATUS.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable queue_reception.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable queue_night_bell.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable queue_technical_support.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable queue_spare_parts.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable queue_sales_product.
[Jan 28 11:01:45] DEBUG[18580] app_queue.c: Device 'DAHDI/3-1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable caller_dnid.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable MYSQL_STATUS.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable fetchid.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable resultid.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable connid.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable CALLEDTON.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable PRIREDIRECTREASON.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable ANI2.
[Jan 28 11:01:45] DEBUG[28137] channel.c: Not copying variable TRANSFERCAPABILITY.
[Jan 28 11:01:45] VERBOSE[28137] chan_dahdi.c:     -- Requested transfer capability: 0x00 - SPEECH
[Jan 28 11:01:45] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb640da38'
[Jan 28 11:01:45] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb640da38'
[Jan 28 11:01:45] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb640da38'
[Jan 28 11:01:45] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb640da38'
...... approx 1200 of these pruned for sanity!
[Jan 28 11:01:45] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb640da38'
[Jan 28 11:01:45] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb640da38'
[Jan 28 11:01:45] VERBOSE[28137] app_dial.c:     -- Called g0/5053
[Jan 28 11:01:45] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:45] DEBUG[18573] devicestate.c: Changing state for DAHDI/3 - state 2 (In use)
[Jan 28 11:01:45] DEBUG[18573] devicestate.c: device 'DAHDI/3' state '2'
[Jan 28 11:01:45] DEBUG[18580] app_queue.c: Device 'DAHDI/3' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan 28 11:01:45] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:45] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
....pruned for sanity!
[Jan 28 11:01:46] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:46] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:46] DEBUG[18583] chan_dahdi.c: Enabled echo cancellation on channel 3
[Jan 28 11:01:46] VERBOSE[28137] app_dial.c:     -- DAHDI/3-1 is ringing
[Jan 28 11:01:46] DEBUG[28137] chan_dahdi.c: Requested indication 3 on channel DAHDI/29-1
[Jan 28 11:01:46] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:46] DEBUG[18573] devicestate.c: Changing state for DAHDI/3 - state 6 (Ringing)
[Jan 28 11:01:46] DEBUG[18573] devicestate.c: device 'DAHDI/3' state '6'
[Jan 28 11:01:46] DEBUG[18580] app_queue.c: Device 'DAHDI/3' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Jan 28 11:01:46] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:46] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:46] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
....pruned for sanity!
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Dropping frame since I'm still dialing on DAHDI/3-1...
[Jan 28 11:01:53] DEBUG[18583] chan_dahdi.c: Echo cancellation already on
[Jan 28 11:01:53] VERBOSE[28137] app_dial.c:     -- DAHDI/3-1 answered DAHDI/29-1
[Jan 28 11:01:53] DEBUG[18573] devicestate.c: Changing state for DAHDI/3 - state 2 (In use)
[Jan 28 11:01:53] DEBUG[18573] devicestate.c: device 'DAHDI/3' state '2'
[Jan 28 11:01:53] DEBUG[18580] app_queue.c: Device 'DAHDI/3' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Requested indication 20 on channel DAHDI/29-1
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Requested indication 20 on channel DAHDI/3-1
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: master: 29, slave: 3, nothingok: 0
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Stopping tones on 29/0 talking to 3/0
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Stopping tones on 3/0 talking to 29/0
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Disabled echo cancellation on channel 29
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Disabled echo cancellation on channel 3
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Making 3 slave to master 29 at 0
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Added 15 to conference 9/29
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Added 40 to conference 9/3
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Updated conferencing on 29, with 0 conference users
[Jan 28 11:01:53] DEBUG[28137] chan_dahdi.c: Updated conferencing on 3, with 0 conference users
[Jan 28 11:01:53] VERBOSE[28137] chan_dahdi.c:     -- Native bridging DAHDI/29-1 and DAHDI/3-1
[Jan 28 11:02:23] VERBOSE[18583] chan_dahdi.c:     -- Channel 0/29, span 1 got hangup request, cause 16
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Enabled echo cancellation on channel 29
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Enabled echo cancellation on channel 3
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Unlinking slave 3 from 29
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Removed 15 from conference 9/29
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Removed 40 from conference 9/3
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Updated conferencing on 29, with 0 conference users
[Jan 28 11:02:23] DEBUG[28137] channel.c: Returning from native bridge, channels: DAHDI/29-1, DAHDI/3-1
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is ''
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Launching 'Verbose'
[Jan 28 11:02:23] VERBOSE[28137] pbx.c:     -- Executing [h@ivr2-bdt-day:1] Verbose("DAHDI/29-1", "0,'' IVR MAIN-DAY Hungup") in new stack
[Jan 28 11:02:23] VERBOSE[28137] app_verbose.c: '' IVR MAIN-DAY Hungup
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'Thu Jan 28 11:02:23 2010'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Launching 'Verbose'
[Jan 28 11:02:23] VERBOSE[28137] pbx.c:     -- Executing [h@ivr2-bdt-day:2] Verbose("DAHDI/29-1", "0,Time=Thu Jan 28 11:02:23 2010") in new stack
[Jan 28 11:02:23] VERBOSE[28137] app_verbose.c: Time=Thu Jan 28 11:02:23 2010
[Jan 28 11:02:23] DEBUG[28137] cdr_addon_mysql.c: Inserting a CDR record.
[Jan 28 11:02:23] DEBUG[28137] cdr_addon_mysql.c: SQL command as follows: INSERT INTO cdr (calldate,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,userfield,uniqueid,dnid) VALUES ('2010-01-28 11:01:31','2','ivr2-bdt-day','DAHDI/29-1','DAHDI/3-1','Dial','DAHDI/g0/5053','52','30','ANSWERED','3','9100-PRODUCT_SALES','1264629691.213','9100')
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '(null)'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '(null)'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '2'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'ivr2-bdt-day'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'DAHDI/29-1'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'DAHDI/3-1'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'Dial'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'DAHDI/g0/5053'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '2010-01-28 11:01:31'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '2010-01-28 11:01:53'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '2010-01-28 11:02:23'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '52'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '30'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'ANSWERED'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is 'DOCUMENTATION'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '(null)'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '1264629691.213'
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Function result is '9100-PRODUCT_SALES'
[Jan 28 11:02:23] DEBUG[28137] channel.c: Hanging up channel 'DAHDI/3-1'
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: dahdi_hangup(DAHDI/3-1)
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/3-1
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Hangup: channel: 3 index = 0, normal = 15, callwait = -1, thirdcall = -1
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Not yet hungup...  Calling hangup once with icause, and clearing call
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Disabled echo cancellation on channel 3
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/3-1
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Updated conferencing on 3, with 0 conference users
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/3-1
[Jan 28 11:02:23] VERBOSE[28137] chan_dahdi.c:     -- Hungup 'DAHDI/3-1'
[Jan 28 11:02:23] DEBUG[18573] devicestate.c: Changing state for DAHDI/3 - state 0 (Unknown)
[Jan 28 11:02:23] DEBUG[18573] devicestate.c: device 'DAHDI/3' state '0'
[Jan 28 11:02:23] DEBUG[28137] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Jan 28 11:02:23] DEBUG[18580] app_queue.c: Device 'DAHDI/3' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
[Jan 28 11:02:23] DEBUG[28137] pbx.c: Spawn extension (ivr2-bdt-day,2,3) exited non-zero on 'DAHDI/29-1'
[Jan 28 11:02:23] VERBOSE[28137] pbx.c:   == Spawn extension (ivr2-bdt-day, 2, 3) exited non-zero on 'DAHDI/29-1'
[Jan 28 11:02:23] DEBUG[28137] channel.c: Soft-Hanging up channel 'DAHDI/29-1'
[Jan 28 11:02:23] DEBUG[28137] channel.c: Hanging up channel 'DAHDI/29-1'
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: dahdi_hangup(DAHDI/29-1)
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/29-1
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Hangup: channel: 29 index = 0, normal = 40, callwait = -1, thirdcall = -1
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Not yet hungup...  Calling hangup once with icause, and clearing call
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Disabled echo cancellation on channel 29
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/29-1
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Updated conferencing on 29, with 0 conference users
[Jan 28 11:02:23] DEBUG[28137] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/29-1
[Jan 28 11:02:23] VERBOSE[28137] chan_dahdi.c:     -- Hungup 'DAHDI/29-1'
[Jan 28 11:02:23] DEBUG[18573] devicestate.c: Changing state for DAHDI/29 - state 0 (Unknown)
[Jan 28 11:02:23] DEBUG[18573] devicestate.c: device 'DAHDI/29' state '0'
[Jan 28 11:02:23] DEBUG[18580] app_queue.c: Device 'DAHDI/29' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.

.... These releases have not seen a setup yet.
... outside Caller experienced congestion tone, but had only rung once.
[Jan 28 11:03:28] WARNING[18583] chan_dahdi.c: Call specified, but not found?
[Jan 28 11:03:28] WARNING[18583] chan_dahdi.c: Hangup on bad channel 0/29 on span 1
[Jan 28 11:03:33] WARNING[18583] chan_dahdi.c: Call specified, but not found?
[Jan 28 11:03:33] WARNING[18583] chan_dahdi.c: Hangup on bad channel 0/29 on span 1

..... Next successful call on same channel - 29.
[Jan 28 11:03:46] DEBUG[18583] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 28 11:03:46] DEBUG[18583] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 28 11:03:46] DEBUG[18583] devicestate.c: device 'DAHDI/29-1' state '2'
[Jan 28 11:03:46] DEBUG[18580] app_queue.c: Device 'DAHDI/29-1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Goto'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [9100@incoming:1] Goto("DAHDI/29-1", "ivr2-bdt-main,s,1") in new stack
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Goto (ivr2-bdt-main,s,1)
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is 'Thu Jan 28 11:03:46 2010'
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Verbose'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:1] Verbose("DAHDI/29-1", "0,Time=Thu Jan 28 11:03:46 2010") in new stack
[Jan 28 11:03:46] VERBOSE[28154] app_verbose.c: Time=Thu Jan 28 11:03:46 2010
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is '9100'
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Verbose'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:2] Verbose("DAHDI/29-1", "0,'' IVR Main called '9100' IAXVAR='' ") in new stack
[Jan 28 11:03:46] VERBOSE[28154] app_verbose.c: '' IVR Main called '9100' IAXVAR='' 
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Ringing'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:3] Ringing("DAHDI/29-1", "") in new stack
[Jan 28 11:03:46] VERBOSE[18583] chan_dahdi.c:     -- Accepting call from '' to '9100' on channel 0/29, span 1
[Jan 28 11:03:46] DEBUG[18583] chan_dahdi.c: Enabled echo cancellation on channel 29
[Jan 28 11:03:46] DEBUG[28154] chan_dahdi.c: Requested indication 3 on channel DAHDI/29-1
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:4] MYSQL("DAHDI/29-1", "Connect connid localhost database user password") in new stack
[Jan 28 11:03:46] DEBUG[18573] devicestate.c: Changing state for DAHDI/29 - state 6 (Ringing)
[Jan 28 11:03:46] DEBUG[18573] devicestate.c: device 'DAHDI/29' state '6'
[Jan 28 11:03:46] DEBUG[18580] app_queue.c: Device 'DAHDI/29' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:5] MYSQL("DAHDI/29-1", "Query resultid 1 SELECT number, name, staff FROM mobiles WHERE number='0'") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:6] MYSQL("DAHDI/29-1", "Fetch fetchid 2 in-number in-name staff") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:7] MYSQL("DAHDI/29-1", "Clear 2") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:8] MYSQL("DAHDI/29-1", "Disconnect 1") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:9] Set("DAHDI/29-1", "CALLERID(name)=") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Verbose'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:10] Verbose("DAHDI/29-1", "0,'' Caller name= number= staff=") in new stack
[Jan 28 11:03:46] VERBOSE[28154] app_verbose.c: '' Caller name= number= staff=
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is '9100'
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:11] Set("DAHDI/29-1", "caller_dnid=9100") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:12] Set("DAHDI/29-1", "queue_reception=5066") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:13] Set("DAHDI/29-1", "queue_sales_product=5053") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:14] Set("DAHDI/29-1", "queue_spare_parts=5833") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:15] Set("DAHDI/29-1", "queue_technical_support=5023") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:16] Set("DAHDI/29-1", "queue_night_bell=4925") in new stack
[Jan 28 11:03:46] DEBUG[28154] pbx.c: Launching 'Wait'
[Jan 28 11:03:46] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:17] Wait("DAHDI/29-1", "3") in new stack
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'Answer'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:18] Answer("DAHDI/29-1", "") in new stack
[Jan 28 11:03:49] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c67ba8'
..... 350 pruned for sanity!
[Jan 28 11:03:49] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c67ba8'
[Jan 28 11:03:49] DEBUG[18573] channel.c: Avoiding initial deadlock for channel '0xb6c67ba8'
[Jan 28 11:03:49] DEBUG[18573] devicestate.c: Changing state for DAHDI/29 - state 2 (In use)
[Jan 28 11:03:49] DEBUG[18573] devicestate.c: device 'DAHDI/29' state '2'
[Jan 28 11:03:49] DEBUG[18580] app_queue.c: Device 'DAHDI/29' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan 28 11:03:49] DEBUG[28154] chan_dahdi.c: Requested indication -1 on channel DAHDI/29-1
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:19] Set("DAHDI/29-1", "CDR(userfield)=9100") in new stack
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:20] GotoIfTime("DAHDI/29-1", "8:30-17:00,mon-fri,,?:ivr2-bdt-night,s,1") in new stack
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Not taking any branch
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:21] GotoIfTime("DAHDI/29-1", ",,25-28,dec,?ivr2-bdt-holiday,s,1") in new stack
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Not taking any branch
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:22] GotoIfTime("DAHDI/29-1", ",,1-4,jan,?ivr2-bdt-holiday,s,1") in new stack
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Not taking any branch
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:23] GotoIfTime("DAHDI/29-1", ",,25,jan,?ivr2-bdt-holiday,s,1") in new stack
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Not taking any branch
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'GotoIfTime'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-main:24] GotoIfTime("DAHDI/29-1", ",,26-31,jan,?ivr2-bdt-day-noreception,s,1") in new stack
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Goto (ivr2-bdt-day-noreception,s,1)
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-day-noreception:1] Set("DAHDI/29-1", "queue_reception=5053") in new stack
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'Goto'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-day-noreception:2] Goto("DAHDI/29-1", "ivr2-bdt-day,s,1") in new stack
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Goto (ivr2-bdt-day,s,1)
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'Verbose'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-day:1] Verbose("DAHDI/29-1", "0,'' IVR MAIN-DAY") in new stack
[Jan 28 11:03:49] VERBOSE[28154] app_verbose.c: '' IVR MAIN-DAY
[Jan 28 11:03:49] DEBUG[28154] pbx.c: Launching 'BackGround'
[Jan 28 11:03:49] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-day:2] BackGround("DAHDI/29-1", "silence/1") in new stack
[Jan 28 11:03:49] DEBUG[28154] channel.c: Set channel DAHDI/29-1 to write format gsm
[Jan 28 11:03:49] DEBUG[28154] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jan 28 11:03:49] VERBOSE[28154] file.c:     -- <DAHDI/29-1> Playing 'silence/1.gsm' (language 'en')
[Jan 28 11:03:50] DEBUG[28154] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:03:50] DEBUG[28154] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:03:50] DEBUG[28154] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:03:50] DEBUG[28154] channel.c: Set channel DAHDI/29-1 to write format alaw
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Function result is '9100'
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Expression result is '0'
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Launching 'GotoIf'
[Jan 28 11:03:50] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-day:3] GotoIf("DAHDI/29-1", "0?staff") in new stack
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Not taking any branch
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Expression result is '0'
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Launching 'GotoIf'
[Jan 28 11:03:50] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-day:4] GotoIf("DAHDI/29-1", "0?staff") in new stack
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Not taking any branch
[Jan 28 11:03:50] DEBUG[28154] pbx.c: Launching 'BackGround'
[Jan 28 11:03:50] VERBOSE[28154] pbx.c:     -- Executing [s@ivr2-bdt-day:5] BackGround("DAHDI/29-1", "bdt/mainbdt-day") in new stack
[Jan 28 11:03:50] DEBUG[28154] channel.c: Set channel DAHDI/29-1 to write format gsm
[Jan 28 11:03:50] DEBUG[28154] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jan 28 11:03:50] VERBOSE[28154] file.c:     -- <DAHDI/29-1> Playing 'bdt/mainbdt-day.gsm' (language 'en')
[Jan 28 11:03:56] DEBUG[28154] chan_dahdi.c: DTMF digit: 8 on DAHDI/29-1
[Jan 28 11:03:56] DEBUG[28154] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:03:56] DEBUG[28154] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jan 28 11:03:56] DEBUG[28154] channel.c: Set channel DAHDI/29-1 to write format alaw
[Jan 28 11:03:56] DEBUG[28154] pbx.c: Oooh, got something to jump out with ('8')!
[Jan 28 11:03:56] DEBUG[28154] chan_dahdi.c: DTMF digit: 5 on DAHDI/29-1
[Jan 28 11:03:57] DEBUG[28154] chan_dahdi.c: DTMF digit: 1 on DAHDI/29-1
[Jan 28 11:03:57] DEBUG[28154] chan_dahdi.c: DTMF digit: 2 on DAHDI/29-1
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:   == CDR updated on DAHDI/29-1
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'Verbose'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-day:1] Verbose("DAHDI/29-1", "0,'' Dialled By Extension") in new stack
[Jan 28 11:03:57] VERBOSE[28154] app_verbose.c: '' Dialled By Extension
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'Goto'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-day:2] Goto("DAHDI/29-1", "ivr2-bdt-dialledbyextension,8512,1") in new stack
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Goto (ivr2-bdt-dialledbyextension,8512,1)
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Function result is ''
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'Verbose'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:1] Verbose("DAHDI/29-1", "0,'': Dialled By Extension '8512'") in new stack
[Jan 28 11:03:57] VERBOSE[28154] app_verbose.c: '': Dialled By Extension '8512'
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:2] MYSQL("DAHDI/29-1", "Connect connid localhost database user password") in new stack
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:3] MYSQL("DAHDI/29-1", "Query resultid 1 SELECT name FROM pbx WHERE extension=8512 ") in new stack
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:4] MYSQL("DAHDI/29-1", "Fetch fetchid 2 out-name") in new stack
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:5] MYSQL("DAHDI/29-1", "Clear 2") in new stack
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'MYSQL'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:6] MYSQL("DAHDI/29-1", "Disconnect 1") in new stack
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'Set'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:7] Set("DAHDI/29-1", "CDR(userfield)=9100-Alec Davis") in new stack
[Jan 28 11:03:57] DEBUG[28154] pbx.c: Launching 'Dial'
[Jan 28 11:03:57] VERBOSE[28154] pbx.c:     -- Executing [8512@ivr2-bdt-dialledbyextension:8] Dial("DAHDI/29-1", "DAHDI/g0/8512") in new stack
[Jan 28 11:03:57] DEBUG[28154] chan_dahdi.c: Using channel 5
.... and the call goes through to me as it turns out....