Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for
- Cisco Community
- Technology and Support
- DevNet
- DevNet Collaboration
- Collaboration Knowledge Base
- TCL ev_feature event inconsistent
Options
- Subscribe to RSS Feed
- Mark as New
- Mark as Read
- Bookmark
- Subscribe
- Printer Friendly Page
- Report Inappropriate Content
149
Views
0
Helpful
0
Comments
Options
- Subscribe to RSS Feed
- Mark as New
- Mark as Read
- Bookmark
- Subscribe
- Printer Friendly Page
- Report Inappropriate Content
on 01-24-2014 04:07 PM
This document was generated from CDN thread
Created by: James Clapper on 23-07-2012 11:09:24 AM
Trying to capture digits after a hookflash event on a CAS T1. Tried to use the ev_hookflash but that would not even allow the script to load. Now trying to use the ev_feature event. It works in getting the hookflash and then triggering my digit collection, but only about 1 out of every 6 times. Not certain what is going on here? I have messed with the timing on the voice port, changed FSM, and now pretty much stuck.
Here is the script. Below is the logs that show that there is a hookflash that occurs and that the event kicks off only sometimes.
proc init { } {
global dcparams
global hooksxfrdest
global status
global dest
set dcparams(enableReporting) true
set dcparams(dialPlan) false
infotag set evt_feature_report hookflash onhook offhook
puts "\n Initializing script..................."
}
proc act_Setup { } {
global dest
# Ensure there is a DNIS or close
if { [infotag get leg_isdid] } {
set dest [infotag get leg_dnis]
} else {
call close
}
# Setup inbound leg
leg setupack leg_incoming
leg proceeding leg_incoming
leg connect leg_incoming
# Setup to the DNIS
leg setup $dest callInfo leg_incoming
}
proc act_Connected { } {
global status
# Ensure DID connected
set status [infotag get evt_status]
if { $status == "ls_000"} {
puts "\n Call to Number successful"
} else {
puts "\n Call to Number did not connect"
call close
}
}
proc act_DigitCollect { } {
puts [infotag get evt_event]
global dcparams
puts "\n Collecting Digits..................."
leg collectdigits leg_outgoing
#leg collectdigits [infotag get leg_all] dcparams
}
proc act_Xfer { } {
puts "\n Transfering..................."
#Something here if I can get this to work all the time....
}
proc act_Cleanup { } {
puts "\n Cleaning up..................."
call close
}
init
#------------------
# State Machine
#----------------------------------
set fsm(any_state,ev_disconnected) "act_Cleanup same_state"
############## "Meat" of the script
set fsm(CALL_INIT,ev_setup_indication) "act_Setup CONNECT"
set fsm(CONNECT,ev_setup_done) "act_Connected CONNECTED"
set fsm(CONNECTED,ev_feature) "act_DigitCollect XFEROUT"
set fsm(XFEROUT,ev_collectdigits_done) "act_Xfer CLEANUP"
set fsm(CLEANUP,ev_media_done) "act_Cleanup CALLEND"
############## Cleanup
set fsm(CALLEND,ev_media_done) "act_Cleanup CALLDISCONNECT"
set fsm(CALLDISCONNECT,ev_disconnected) "act_Cleanup same_state"
set fsm(CALLDISCONNECT,ev_media_done) "act_Cleanup same_state"
set fsm(CALLDISCONNECT,ev_disconnect_done) "act_Cleanup same_state"
set fsm(CALLDISCONNECT,ev_leg_timer) "act_Cleanup same_state"
fsm define fsm CALL_INIT
q99921voipgw1#show log
Syslog logging: enabled (266 messages dropped, 148 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: level debugging, 1044933 messages logged, xml disabled,
filtering disabled
Monitor logging: level debugging, 37099 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 1045049 messages logged, xml disabled,
filtering disabled
Exception Logging: size (8192 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 110786 message lines logged
Logging to 10.44.33.63 (udp port 514, audit disabled,
link up),
110786 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.44.28.5 (udp port 514, audit disabled,
link up),
110786 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.170.100.23 (udp port 514, audit disabled,
link up),
110786 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Log Buffer (1024000 bytes):
Jul 10 01:48:32.673: //-1//HIFS:/hifs_ifs_cb: hifs ifs file read succeeded. size=4149, url=flash:CAST1hookflash_1.tcl
Jul 10 01:48:32.673: //-1//HIFS:/hifs_free_idata: hifs_free_idata: 0x285E980C
Jul 10 01:48:32.673: //-1//HIFS:/hifs_hold_idata: hifs_hold_idata: 0x285E980C
Jul 10 01:48:32.673: //-1//AFW_:EE1D7D54C0000:/Tcl_Link: Linking script cast1hookflash
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_InfotagObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_InfotagSetObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:32.675: //-1//AFW_:EE1D7D54C0000:/vtw_ev_feature_report:
Jul 10 01:48:32.675: //-1//AFW_:EE1D7D54C0000:/vtw_ev_feature_report: reportFeatureBitmap=0x1C
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_PutsObjCmd:
Initializing script...................
Jul 10 01:48:32.675:
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_FSMObjCmd: fsm define fsm CALL_INIT
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_FSMDefineObjCmd: State Machine: Array fsm: Start State: CALL_INIT
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_FSMDefineObjCmd: FSM Data structure
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_leg_timer(1)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_media_done(175)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CONNECTED(3), ev_feature(38)--(act_DigitCollect)-->(XFEROUT(4))
Jul 10 01:48:32.675: (any_state(0), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CALLEND(5), ev_media_done(175)--(act_Cleanup)-->(CALLDISCONNECT(2))
Jul 10 01:48:32.675: (XFEROUT(4), ev_collectdigits_done(225)--(act_Xfer)-->(CLEANUP(6))
Jul 10 01:48:32.675: (CONNECT(7), ev_setup_done(216)--(act_Connected)-->(CONNECTED(3))
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_disconnect_done(21)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CLEANUP(6), ev_media_done(175)--(act_Cleanup)-->(CALLEND(5))
Jul 10 01:48:32.675: (CALL_INIT(1), ev_setup_indication(34)--(act_Setup)-->(CONNECT(7))
Jul 10 01:48:32.675: FSM start state CALL_INIT(1)
Jul 10 01:48:32.675: //-1//AFW_:EE1D7D54C0000:/Tcl_Link: Script cast1hookflash succesfully linked.
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/Tcl_Link: Linking script cast1hookflash
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_InfotagObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_InfotagSetObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/vtw_ev_feature_report:
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/vtw_ev_feature_report: reportFeatureBitmap=0x1C
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_PutsObjCmd:
Initializing script...................
Jul 10 01:48:42.162:
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_FSMObjCmd: fsm define fsm CALL_INIT
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_FSMDefineObjCmd: State Machine: Array fsm: Start State: CALL_INIT
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_FSMDefineObjCmd: FSM Data structure
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_leg_timer(1)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_media_done(175)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CONNECTED(3), ev_feature(38)--(act_DigitCollect)-->(XFEROUT(4))
Jul 10 01:48:42.162: (any_state(0), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CALLEND(5), ev_media_done(175)--(act_Cleanup)-->(CALLDISCONNECT(2))
Jul 10 01:48:42.162: (XFEROUT(4), ev_collectdigits_done(225)--(act_Xfer)-->(CLEANUP(6))
Jul 10 01:48:42.162: (CONNECT(7), ev_setup_done(216)--(act_Connected)-->(CONNECTED(3))
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_disconnect_done(21)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CLEANUP(6), ev_media_done(175)--(act_Cleanup)-->(CALLEND(5))
Jul 10 01:48:42.162: (CALL_INIT(1), ev_setup_indication(34)--(act_Setup)-->(CONNECT(7))
Jul 10 01:48:42.162: FSM start state CALL_INIT(1)
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/Tcl_Link: Script cast1hookflash succesfully linked.
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagObjCmd: infotag get leg_isdid
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get leg_isdid
Jul 10 01:48:42.162: //239520//AFW_:/vtr_lg_incdid: argc 2 argindex 2
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagObjCmd: infotag get leg_dnis
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis
Jul 10 01:48:42.162: //239520//AFW_:/vtr_lg_dnis: argc 2 argindex 2
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg setupack leg_incoming
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegSetupAckObjCmd: setupack leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg proceeding leg_incoming
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg connect leg_incoming
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegConnectObjCmd: connect leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 4
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: htsp_timer_stop3 htsp_setup_req
Jul 10 01:48:42.164: htsp_process_event: [1/0:0(4), FXSLS_ONHOOK, E_HTSP_SETUP_REQ]fxsls_onhook_setuphtsp_alertvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x0
Jul 10 01:48:42.164: htsp_call_bridged invoked
Jul 10 01:48:42.164: htsp_process_event: [1/0:0(4), FXSLS_WAIT_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxsls_waitoff_voice
Jul 10 01:48:44.213: htsp_process_event: [1/0:0(4), FXSLS_WAIT_OFFHOOK, E_DSP_SIG_1100]fxsls_waitoff_offhookvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x6
Jul 10 01:48:44.213: htsp_timer2 - 200 msec
Jul 10 01:48:44.413: htsp_process_event: [1/0:0(4), FXSLS_WAIT_OFFHOOK, E_HTSP_EVENT_TIMER2]fxsls_offhook_dial htsp_dial
Jul 10 01:48:44.413: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_DIALING_DONE]fxsls_conn_dial_done
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagObjCmd: infotag get evt_status
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status
Jul 10 01:48:44.413: //239520//AFW_:/vtr_ev_status: argc 2 argindex 2
Jul 10 01:48:44.413: //239520//TCL :/tcl_PutsObjCmd:
Call to Number successful
Jul 10 01:48:44.413:
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagObjCmd: infotag get leg_all
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get leg_all
Jul 10 01:48:44.413: //239520//AFW_:/vtr_lg_all: argc 2
Jul 10 01:48:44.413: //239520//TCL :/tcl_LegObjCmd: leg collectdigits 239520 239521 dcparams
Jul 10 01:48:44.413: //239520//Digi:/tcl_LegDigitCollectObjCmd: collectdigits 239520 239521 dcparams
Jul 10 01:48:44.413: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=2
Jul 10 01:48:44.413: //239520//Digi:/C_DigitCollect_Start: Leg=239520, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:48:44.413: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:48:44.413: //-1//Digi:HNCD4EAB66:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:48:44.413: //239520/5EBE28000006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:48:44.413: //239520//Digi:/C_DigitCollect_Start: Leg=239521, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:48:44.413: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:48:44.413: //-1//Digi:HNCD4EAB66:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:48:44.413: //239521/5EBE28000006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:48:44.413: //239520//Digi:/act_DCRunning_RDone: id=239520 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:48:44.413: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:48:44.413: //239520//Digi:/act_DCRunning_RDone: id=239521 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:48:44.413: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:49:12.397: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:49:12.397: htsp_timer - 1000 msec
Jul 10 01:49:12.997: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_SIG_1100]fxsls_offhook_offhookhtsp_hook_flash_ind
Jul 10 01:49:12.997: htsp_timer_stop
Jul 10 01:49:12.997: //239520//TCL :/tcl_InfotagObjCmd: infotag get evt_event
Jul 10 01:49:12.997: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get evt_event
Jul 10 01:49:12.997: //239520//AFW_:/vtr_ev_event: argc 2
Jul 10 01:49:12.997: //239520//AFW_:/vtr_ev_event: Event [ev_feature]
Jul 10 01:49:12.997: //239520//TCL :/tcl_PutsObjCmd: ev_feature
Jul 10 01:49:12.997:
Jul 10 01:49:12.997: //239520//TCL :/tcl_PutsObjCmd:
Collecting Digits...................
Jul 10 01:49:12.997:
Jul 10 01:49:12.997: //239520//TCL :/tcl_LegObjCmd: leg collectdigits leg_outgoing
Jul 10 01:49:12.997: //239520//Digi:/tcl_LegDigitCollectObjCmd: collectdigits leg_outgoing
Jul 10 01:49:12.997: //239520//AFW_:/vtd_lg_outgoing: argc 2
Jul 10 01:49:12.997: //239520//AFW_:/vtd_lg_outgoing: Legs [239521 ]
Jul 10 01:49:12.997: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:49:12.997: //239520//Digi:/C_DigitCollect_Start: Leg=239521, Dialplan=True, Diaplanterm=True, DigitReport=False, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:49:12.997: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:49:12.997: //-1//Digi:HNCD4F1B06:/AFW_DigitCollect_New: DialPlan=TRUE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=FALSE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=TRUE hotword=0
Jul 10 01:49:12.997: //239521/5EBE28000006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:49:12.997: //239520//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:49:12.997: //239520//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:49:12.997: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:12.997: //239520//Digi:/act_DCRunning_RDone: id=239521 Enable succeeded.enable=0 matchDialplan=1 numPatterns=0matchDialplanTerm=1
Jul 10 01:49:14.386: htsp_digit_ready(1/0:0(4)): digit = 1
Jul 10 01:49:14.386: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.386: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 1 Tone Mode 0
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.546: htsp_digit_ready(1/0:0(4)): digit = 3
Jul 10 01:49:14.546: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.546: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 3 Tone Mode 0
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.706: htsp_digit_ready(1/0:0(4)): digit = 9
Jul 10 01:49:14.706: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.706: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 9 Tone Mode 0
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.838: htsp_digit_ready(1/0:0(4)): digit = 9
Jul 10 01:49:14.838: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.838: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 9 Tone Mode 0
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.998: htsp_digit_ready(1/0:0(4)): digit = 9
Jul 10 01:49:14.998: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.998: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 9 Tone Mode 0
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.158: htsp_digit_ready(1/0:0(4)): digit = 5
Jul 10 01:49:15.158: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.158: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 5 Tone Mode 0
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139995
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.318: htsp_digit_ready(1/0:0(4)): digit = 2
Jul 10 01:49:15.318: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.318: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 2 Tone Mode 0
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399952
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.478: htsp_digit_ready(1/0:0(4)): digit = 2
Jul 10 01:49:15.478: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.478: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 2 Tone Mode 0
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999522
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.638: htsp_digit_ready(1/0:0(4)): digit = 3
Jul 10 01:49:15.638: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.638: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 3 Tone Mode 0
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139995223
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.798: htsp_digit_ready(1/0:0(4)): digit = 8
Jul 10 01:49:15.798: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.798: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 8 Tone Mode 0
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399952238
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.958: htsp_digit_ready(1/0:0(4)): digit = 3
Jul 10 01:49:15.958: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.958: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 3 Tone Mode 0
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999522383
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.118: htsp_digit_ready(1/0:0(4)): digit = 4
Jul 10 01:49:16.118: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:16.118: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 4 Tone Mode 0
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139995223834
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.278: htsp_digit_ready(1/0:0(4)): digit = 5
Jul 10 01:49:16.278: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:16.278: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 5 Tone Mode 0
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399952238345
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.438: htsp_digit_ready(1/0:0(4)): digit = 1
Jul 10 01:49:16.438: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:16.438: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 1 Tone Mode 0
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999522383451
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.450: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:49:16.450: htsp_timer - 1000 msec
Jul 10 01:49:17.451: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_HTSP_EVENT_TIMER]fxsls_connect_wait_release_req
Jul 10 01:49:17.451: htsp_timer_stop
Jul 10 01:49:17.451: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:17.451: //239520//Digi:/act_DCRunning_Disconnected:
Jul 10 01:49:17.451: //-1//Digi:/DigitCollect_Complete: DC_DISCONNECTED. Digits=13999522383451
Jul 10 01:49:17.451: //239520//TCL :/tcl_PutsObjCmd:
Cleaning up...................
Jul 10 01:49:17.451:
Jul 10 01:49:17.451: //239520//TCL :/tcl_CallObjCmd: call close
Jul 10 01:49:17.451: //239520//TCL :/tcl_CallCloseObjCmd: close
Jul 10 01:49:17.451: //239520//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:49:17.451: //239520//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:49:17.451: htsp_timer_stop3
Jul 10 01:49:17.479: htsp_process_event: [1/0:0(4), FXSLS_WAIT_RELEASE_REQ, E_HTSP_RELEASE_REQ]fxsls_waitrls_req_rlsvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x4
Jul 10 01:49:17.483: htsp_process_event: [1/0:0(4), FXSLS_ONHOOK, E_DSP_SIG_0100]fxsls_onhook_onhook
Jul 10 01:50:10.706: //237039//PACK:/DoMediaStop:
Jul 10 01:51:22.736: %ISDN-6-CONNECT: Interface Serial0/0/0:21 is now connected to 3212004539 N/A
q99921voipgw1#
q99921voipgw1#
q99921voipgw1#
q99921voipgw1#clear log
Clear logging buffer
q99921voipgw1#show log
Syslog logging: enabled (266 messages dropped, 148 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: level debugging, 1045135 messages logged, xml disabled,
filtering disabled
Monitor logging: level debugging, 37099 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 1045251 messages logged, xml disabled,
filtering disabled
Exception Logging: size (8192 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 110787 message lines logged
Logging to 10.44.33.63 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.44.28.5 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.170.100.23 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Log Buffer (1024000 bytes):
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_incdid: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_dnis: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setupack leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegSetupAckObjCmd: setupack leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg proceeding leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg connect leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegConnectObjCmd: connect leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 4
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: htsp_timer_stop3 htsp_setup_req
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_ONHOOK, E_HTSP_SETUP_REQ]fxsls_onhook_setuphtsp_alertvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x0
Jul 10 01:51:52.965: htsp_call_bridged invoked
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxsls_waitoff_voice
Jul 10 01:51:55.013: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_DSP_SIG_1100]fxsls_waitoff_offhookvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x6
Jul 10 01:51:55.013: htsp_timer2 - 200 msec
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_EVENT_TIMER2]fxsls_offhook_dial htsp_dial
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_DIALING_DONE]fxsls_conn_dial_done
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//AFW_:/vtr_ev_status: argc 2 argindex 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_PutsObjCmd:
Call to Number successful
Jul 10 01:51:55.213:
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//AFW_:/vtr_lg_all: argc 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_LegObjCmd: leg collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Digi:/tcl_LegDigitCollectObjCmd: collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=2
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239528, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239528/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239529, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239529/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239528 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239529 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:52:31.588: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:52:31.588: htsp_timer - 1000 msec
Jul 10 01:52:32.190: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_1100]fxsls_offhook_offhookhtsp_hook_flash_ind
Jul 10 01:52:32.190: htsp_timer_stop
Jul 10 01:52:32.577: htsp_digit_ready(1/0:0(1)): digit = 1
Jul 10 01:52:32.737: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:32.897: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.029: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.191: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.349: htsp_digit_ready(1/0:0(1)): digit = 5
Jul 10 01:52:33.509: htsp_digit_ready(1/0:0(1)): digit = 2
Jul 10 01:52:33.669: htsp_digit_ready(1/0:0(1)): digit = 2
q99921voipgw1#show log
Syslog logging: enabled (266 messages dropped, 148 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: level debugging, 1045171 messages logged, xml disabled,
filtering disabled
Monitor logging: level debugging, 37099 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 1045287 messages logged, xml disabled,
filtering disabled
Exception Logging: size (8192 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 110787 message lines logged
Logging to 10.44.33.63 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.44.28.5 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.170.100.23 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Log Buffer (1024000 bytes):
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_incdid: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_dnis: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setupack leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegSetupAckObjCmd: setupack leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg proceeding leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg connect leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegConnectObjCmd: connect leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 4
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: htsp_timer_stop3 htsp_setup_req
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_ONHOOK, E_HTSP_SETUP_REQ]fxsls_onhook_setuphtsp_alertvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x0
Jul 10 01:51:52.965: htsp_call_bridged invoked
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxsls_waitoff_voice
Jul 10 01:51:55.013: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_DSP_SIG_1100]fxsls_waitoff_offhookvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x6
Jul 10 01:51:55.013: htsp_timer2 - 200 msec
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_EVENT_TIMER2]fxsls_offhook_dial htsp_dial
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_DIALING_DONE]fxsls_conn_dial_done
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//AFW_:/vtr_ev_status: argc 2 argindex 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_PutsObjCmd:
Call to Number successful
Jul 10 01:51:55.213:
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//AFW_:/vtr_lg_all: argc 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_LegObjCmd: leg collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Digi:/tcl_LegDigitCollectObjCmd: collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=2
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239528, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239528/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239529, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239529/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239528 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239529 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:52:31.588: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:52:31.588: htsp_timer - 1000 msec
Jul 10 01:52:32.190: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_1100]fxsls_offhook_offhookhtsp_hook_flash_ind
Jul 10 01:52:32.190: htsp_timer_stop
Jul 10 01:52:32.577: htsp_digit_ready(1/0:0(1)): digit = 1
Jul 10 01:52:32.737: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:32.897: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.029: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.191: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.349: htsp_digit_ready(1/0:0(1)): digit = 5
Jul 10 01:52:33.509: htsp_digit_ready(1/0:0(1)): digit = 2
Jul 10 01:52:33.669: htsp_digit_ready(1/0:0(1)): digit = 2
Jul 10 01:52:33.829: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:33.989: htsp_digit_ready(1/0:0(1)): digit = 8
Jul 10 01:52:34.149: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:34.309: htsp_digit_ready(1/0:0(1)): digit = 4
Jul 10 01:52:34.469: htsp_digit_ready(1/0:0(1)): digit = 5
Jul 10 01:52:34.629: htsp_digit_ready(1/0:0(1)): digit = 1
Jul 10 01:52:34.637: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:52:34.637: htsp_timer - 1000 msec
Jul 10 01:52:35.637: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_HTSP_EVENT_TIMER]fxsls_connect_wait_release_req
Jul 10 01:52:35.637: htsp_timer_stop
Jul 10 01:52:35.637: //239528//TCL :/tcl_PutsObjCmd:
Cleaning up...................
Jul 10 01:52:35.637:
Jul 10 01:52:35.637: //239528//TCL :/tcl_CallObjCmd: call close
Jul 10 01:52:35.637: //239528//TCL :/tcl_CallCloseObjCmd: close
Jul 10 01:52:35.637: htsp_timer_stop3
Jul 10 01:52:35.669: htsp_process_event: [1/0:0(1), FXSLS_WAIT_RELEASE_REQ, E_HTSP_RELEASE_REQ]fxsls_waitrls_req_rlsvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4
Jul 10 01:52:35.673: htsp_process_event: [1/0:0(1), FXSLS_ONHOOK, E_DSP_SIG_0100]fxsls_onhook_onhook
Subject: RE: TCL ev_feature event inconsistent
Replied by: Yaw-Ming Chen on 23-07-2012 01:59:45 PM
I wonder how the call can be established?
Looks like the incoming leg is SIP
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Let setup command only takes digits, so before the leg setup you may want to extract the calling number like
regexp {[0-9]+} $dnis dnis
Subject: RE: TCL ev_feature event inconsistent
Replied by: James Clapper on 23-07-2012 04:30:57 PM
Thats a good question. It does however connect as you can see. Also get the IVR recording and status code is ls_000. Shouldn't this fail actually?
Will try and pull out the DNIS and see if that is the core of my issue.
These are my dial-peers:
dial-peer voice 4207 voip
service cast1hookflash
incoming called-number 19528284207
dtmf-relay rtp-nte digit-drop h245-alphanumeric
dial-peer voice 4208 pots
destination-pattern 19528284207
port 1/0:0
forward-digits 0
Subject: RE: TCL ev_feature event inconsistent
Replied by: James Clapper on 23-07-2012 04:46:22 PM
Got the digits only by adding the regex.
regexp {[0-9]{11}} $dest dest
leg setup $dest callInfo leg_incoming
Still works, but same issue as before. Only seeing the hookflash event every once and a while.
Subject: RE: TCL ev_feature event inconsistent
Replied by: Yaw-Ming Chen on 23-07-2012 05:01:40 PM
Also put "infotag set evt_feature_report hookflash" in the beginning of act_setup procedure see if it helps.
Subject: RE: TCL ev_feature event inconsistent
Replied by: James Clapper on 24-07-2012 08:48:14 PM
That did it! Hey thanks much. Guess it makes sense not to have it in init if I think about it.
Created by: James Clapper on 23-07-2012 11:09:24 AM
Trying to capture digits after a hookflash event on a CAS T1. Tried to use the ev_hookflash but that would not even allow the script to load. Now trying to use the ev_feature event. It works in getting the hookflash and then triggering my digit collection, but only about 1 out of every 6 times. Not certain what is going on here? I have messed with the timing on the voice port, changed FSM, and now pretty much stuck.
Here is the script. Below is the logs that show that there is a hookflash that occurs and that the event kicks off only sometimes.
proc init { } {
global dcparams
global hooksxfrdest
global status
global dest
set dcparams(enableReporting) true
set dcparams(dialPlan) false
infotag set evt_feature_report hookflash onhook offhook
puts "\n Initializing script..................."
}
proc act_Setup { } {
global dest
# Ensure there is a DNIS or close
if { [infotag get leg_isdid] } {
set dest [infotag get leg_dnis]
} else {
call close
}
# Setup inbound leg
leg setupack leg_incoming
leg proceeding leg_incoming
leg connect leg_incoming
# Setup to the DNIS
leg setup $dest callInfo leg_incoming
}
proc act_Connected { } {
global status
# Ensure DID connected
set status [infotag get evt_status]
if { $status == "ls_000"} {
puts "\n Call to Number successful"
} else {
puts "\n Call to Number did not connect"
call close
}
}
proc act_DigitCollect { } {
puts [infotag get evt_event]
global dcparams
puts "\n Collecting Digits..................."
leg collectdigits leg_outgoing
#leg collectdigits [infotag get leg_all] dcparams
}
proc act_Xfer { } {
puts "\n Transfering..................."
#Something here if I can get this to work all the time....
}
proc act_Cleanup { } {
puts "\n Cleaning up..................."
call close
}
init
#------------------
# State Machine
#----------------------------------
set fsm(any_state,ev_disconnected) "act_Cleanup same_state"
############## "Meat" of the script
set fsm(CALL_INIT,ev_setup_indication) "act_Setup CONNECT"
set fsm(CONNECT,ev_setup_done) "act_Connected CONNECTED"
set fsm(CONNECTED,ev_feature) "act_DigitCollect XFEROUT"
set fsm(XFEROUT,ev_collectdigits_done) "act_Xfer CLEANUP"
set fsm(CLEANUP,ev_media_done) "act_Cleanup CALLEND"
############## Cleanup
set fsm(CALLEND,ev_media_done) "act_Cleanup CALLDISCONNECT"
set fsm(CALLDISCONNECT,ev_disconnected) "act_Cleanup same_state"
set fsm(CALLDISCONNECT,ev_media_done) "act_Cleanup same_state"
set fsm(CALLDISCONNECT,ev_disconnect_done) "act_Cleanup same_state"
set fsm(CALLDISCONNECT,ev_leg_timer) "act_Cleanup same_state"
fsm define fsm CALL_INIT
q99921voipgw1#show log
Syslog logging: enabled (266 messages dropped, 148 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: level debugging, 1044933 messages logged, xml disabled,
filtering disabled
Monitor logging: level debugging, 37099 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 1045049 messages logged, xml disabled,
filtering disabled
Exception Logging: size (8192 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 110786 message lines logged
Logging to 10.44.33.63 (udp port 514, audit disabled,
link up),
110786 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.44.28.5 (udp port 514, audit disabled,
link up),
110786 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.170.100.23 (udp port 514, audit disabled,
link up),
110786 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Log Buffer (1024000 bytes):
Jul 10 01:48:32.673: //-1//HIFS:/hifs_ifs_cb: hifs ifs file read succeeded. size=4149, url=flash:CAST1hookflash_1.tcl
Jul 10 01:48:32.673: //-1//HIFS:/hifs_free_idata: hifs_free_idata: 0x285E980C
Jul 10 01:48:32.673: //-1//HIFS:/hifs_hold_idata: hifs_hold_idata: 0x285E980C
Jul 10 01:48:32.673: //-1//AFW_:EE1D7D54C0000:/Tcl_Link: Linking script cast1hookflash
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_InfotagObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_InfotagSetObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:32.675: //-1//AFW_:EE1D7D54C0000:/vtw_ev_feature_report:
Jul 10 01:48:32.675: //-1//AFW_:EE1D7D54C0000:/vtw_ev_feature_report: reportFeatureBitmap=0x1C
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_PutsObjCmd:
Initializing script...................
Jul 10 01:48:32.675:
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_FSMObjCmd: fsm define fsm CALL_INIT
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_FSMDefineObjCmd: State Machine: Array fsm: Start State: CALL_INIT
Jul 10 01:48:32.675: //-1//TCL :EE1D7D54C0000:/tcl_FSMDefineObjCmd: FSM Data structure
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_leg_timer(1)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_media_done(175)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CONNECTED(3), ev_feature(38)--(act_DigitCollect)-->(XFEROUT(4))
Jul 10 01:48:32.675: (any_state(0), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CALLEND(5), ev_media_done(175)--(act_Cleanup)-->(CALLDISCONNECT(2))
Jul 10 01:48:32.675: (XFEROUT(4), ev_collectdigits_done(225)--(act_Xfer)-->(CLEANUP(6))
Jul 10 01:48:32.675: (CONNECT(7), ev_setup_done(216)--(act_Connected)-->(CONNECTED(3))
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_disconnect_done(21)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CALLDISCONNECT(2), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:32.675: (CLEANUP(6), ev_media_done(175)--(act_Cleanup)-->(CALLEND(5))
Jul 10 01:48:32.675: (CALL_INIT(1), ev_setup_indication(34)--(act_Setup)-->(CONNECT(7))
Jul 10 01:48:32.675: FSM start state CALL_INIT(1)
Jul 10 01:48:32.675: //-1//AFW_:EE1D7D54C0000:/Tcl_Link: Script cast1hookflash succesfully linked.
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/Tcl_Link: Linking script cast1hookflash
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_InfotagObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_InfotagSetObjCmd: infotag set evt_feature_report hookflash onhook offhook
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/vtw_ev_feature_report:
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/vtw_ev_feature_report: reportFeatureBitmap=0x1C
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_PutsObjCmd:
Initializing script...................
Jul 10 01:48:42.162:
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_FSMObjCmd: fsm define fsm CALL_INIT
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_FSMDefineObjCmd: State Machine: Array fsm: Start State: CALL_INIT
Jul 10 01:48:42.162: //-1//TCL :EE1D7D53D8000:/tcl_FSMDefineObjCmd: FSM Data structure
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_leg_timer(1)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_media_done(175)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CONNECTED(3), ev_feature(38)--(act_DigitCollect)-->(XFEROUT(4))
Jul 10 01:48:42.162: (any_state(0), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CALLEND(5), ev_media_done(175)--(act_Cleanup)-->(CALLDISCONNECT(2))
Jul 10 01:48:42.162: (XFEROUT(4), ev_collectdigits_done(225)--(act_Xfer)-->(CLEANUP(6))
Jul 10 01:48:42.162: (CONNECT(7), ev_setup_done(216)--(act_Connected)-->(CONNECTED(3))
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_disconnect_done(21)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CALLDISCONNECT(2), ev_disconnected(20)--(act_Cleanup)-->(any_state(0))
Jul 10 01:48:42.162: (CLEANUP(6), ev_media_done(175)--(act_Cleanup)-->(CALLEND(5))
Jul 10 01:48:42.162: (CALL_INIT(1), ev_setup_indication(34)--(act_Setup)-->(CONNECT(7))
Jul 10 01:48:42.162: FSM start state CALL_INIT(1)
Jul 10 01:48:42.162: //-1//AFW_:EE1D7D53D8000:/Tcl_Link: Script cast1hookflash succesfully linked.
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagObjCmd: infotag get leg_isdid
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get leg_isdid
Jul 10 01:48:42.162: //239520//AFW_:/vtr_lg_incdid: argc 2 argindex 2
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagObjCmd: infotag get leg_dnis
Jul 10 01:48:42.162: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis
Jul 10 01:48:42.162: //239520//AFW_:/vtr_lg_dnis: argc 2 argindex 2
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg setupack leg_incoming
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegSetupAckObjCmd: setupack leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg proceeding leg_incoming
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg connect leg_incoming
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegConnectObjCmd: connect leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: argc 4
Jul 10 01:48:42.162: //239520//AFW_:/vtd_lg_incoming: Legs [239520 ]
Jul 10 01:48:42.162: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:48:42.162: htsp_timer_stop3 htsp_setup_req
Jul 10 01:48:42.164: htsp_process_event: [1/0:0(4), FXSLS_ONHOOK, E_HTSP_SETUP_REQ]fxsls_onhook_setuphtsp_alertvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x0
Jul 10 01:48:42.164: htsp_call_bridged invoked
Jul 10 01:48:42.164: htsp_process_event: [1/0:0(4), FXSLS_WAIT_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxsls_waitoff_voice
Jul 10 01:48:44.213: htsp_process_event: [1/0:0(4), FXSLS_WAIT_OFFHOOK, E_DSP_SIG_1100]fxsls_waitoff_offhookvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x6
Jul 10 01:48:44.213: htsp_timer2 - 200 msec
Jul 10 01:48:44.413: htsp_process_event: [1/0:0(4), FXSLS_WAIT_OFFHOOK, E_HTSP_EVENT_TIMER2]fxsls_offhook_dial htsp_dial
Jul 10 01:48:44.413: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_DIALING_DONE]fxsls_conn_dial_done
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagObjCmd: infotag get evt_status
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status
Jul 10 01:48:44.413: //239520//AFW_:/vtr_ev_status: argc 2 argindex 2
Jul 10 01:48:44.413: //239520//TCL :/tcl_PutsObjCmd:
Call to Number successful
Jul 10 01:48:44.413:
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagObjCmd: infotag get leg_all
Jul 10 01:48:44.413: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get leg_all
Jul 10 01:48:44.413: //239520//AFW_:/vtr_lg_all: argc 2
Jul 10 01:48:44.413: //239520//TCL :/tcl_LegObjCmd: leg collectdigits 239520 239521 dcparams
Jul 10 01:48:44.413: //239520//Digi:/tcl_LegDigitCollectObjCmd: collectdigits 239520 239521 dcparams
Jul 10 01:48:44.413: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=2
Jul 10 01:48:44.413: //239520//Digi:/C_DigitCollect_Start: Leg=239520, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:48:44.413: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:48:44.413: //-1//Digi:HNCD4EAB66:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:48:44.413: //239520/5EBE28000006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:48:44.413: //239520//Digi:/C_DigitCollect_Start: Leg=239521, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:48:44.413: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:48:44.413: //-1//Digi:HNCD4EAB66:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:48:44.413: //239521/5EBE28000006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:48:44.413: //239520//Digi:/act_DCRunning_RDone: id=239520 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:48:44.413: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:48:44.413: //239520//Digi:/act_DCRunning_RDone: id=239521 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:48:44.413: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:48:44.413: //239520//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:48:44.413: //239520//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:49:12.397: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:49:12.397: htsp_timer - 1000 msec
Jul 10 01:49:12.997: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_SIG_1100]fxsls_offhook_offhookhtsp_hook_flash_ind
Jul 10 01:49:12.997: htsp_timer_stop
Jul 10 01:49:12.997: //239520//TCL :/tcl_InfotagObjCmd: infotag get evt_event
Jul 10 01:49:12.997: //239520//TCL :/tcl_InfotagGetObjCmd: infotag get evt_event
Jul 10 01:49:12.997: //239520//AFW_:/vtr_ev_event: argc 2
Jul 10 01:49:12.997: //239520//AFW_:/vtr_ev_event: Event [ev_feature]
Jul 10 01:49:12.997: //239520//TCL :/tcl_PutsObjCmd: ev_feature
Jul 10 01:49:12.997:
Jul 10 01:49:12.997: //239520//TCL :/tcl_PutsObjCmd:
Collecting Digits...................
Jul 10 01:49:12.997:
Jul 10 01:49:12.997: //239520//TCL :/tcl_LegObjCmd: leg collectdigits leg_outgoing
Jul 10 01:49:12.997: //239520//Digi:/tcl_LegDigitCollectObjCmd: collectdigits leg_outgoing
Jul 10 01:49:12.997: //239520//AFW_:/vtd_lg_outgoing: argc 2
Jul 10 01:49:12.997: //239520//AFW_:/vtd_lg_outgoing: Legs [239521 ]
Jul 10 01:49:12.997: //239520//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:49:12.997: //239520//Digi:/C_DigitCollect_Start: Leg=239521, Dialplan=True, Diaplanterm=True, DigitReport=False, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:49:12.997: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:49:12.997: //-1//Digi:HNCD4F1B06:/AFW_DigitCollect_New: DialPlan=TRUE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=FALSE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=TRUE hotword=0
Jul 10 01:49:12.997: //239521/5EBE28000006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:49:12.997: //239520//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:49:12.997: //239520//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:49:12.997: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:12.997: //239520//Digi:/act_DCRunning_RDone: id=239521 Enable succeeded.enable=0 matchDialplan=1 numPatterns=0matchDialplanTerm=1
Jul 10 01:49:14.386: htsp_digit_ready(1/0:0(4)): digit = 1
Jul 10 01:49:14.386: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.386: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 1 Tone Mode 0
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.386: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.546: htsp_digit_ready(1/0:0(4)): digit = 3
Jul 10 01:49:14.546: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.546: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 3 Tone Mode 0
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.546: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.706: htsp_digit_ready(1/0:0(4)): digit = 9
Jul 10 01:49:14.706: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.706: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 9 Tone Mode 0
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.706: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.838: htsp_digit_ready(1/0:0(4)): digit = 9
Jul 10 01:49:14.838: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.838: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 9 Tone Mode 0
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.838: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:14.998: htsp_digit_ready(1/0:0(4)): digit = 9
Jul 10 01:49:14.998: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:14.998: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 9 Tone Mode 0
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:14.998: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.158: htsp_digit_ready(1/0:0(4)): digit = 5
Jul 10 01:49:15.158: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.158: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 5 Tone Mode 0
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139995
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.158: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.318: htsp_digit_ready(1/0:0(4)): digit = 2
Jul 10 01:49:15.318: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.318: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 2 Tone Mode 0
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399952
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.318: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.478: htsp_digit_ready(1/0:0(4)): digit = 2
Jul 10 01:49:15.478: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.478: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 2 Tone Mode 0
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999522
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.478: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.638: htsp_digit_ready(1/0:0(4)): digit = 3
Jul 10 01:49:15.638: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.638: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 3 Tone Mode 0
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139995223
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.638: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.798: htsp_digit_ready(1/0:0(4)): digit = 8
Jul 10 01:49:15.798: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.798: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 8 Tone Mode 0
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399952238
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.798: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:15.958: htsp_digit_ready(1/0:0(4)): digit = 3
Jul 10 01:49:15.958: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:15.958: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 3 Tone Mode 0
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999522383
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:15.958: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.118: htsp_digit_ready(1/0:0(4)): digit = 4
Jul 10 01:49:16.118: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:16.118: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 4 Tone Mode 0
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=139995223834
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:16.118: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.278: htsp_digit_ready(1/0:0(4)): digit = 5
Jul 10 01:49:16.278: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:16.278: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 5 Tone Mode 0
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=1399952238345
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:16.278: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.438: htsp_digit_ready(1/0:0(4)): digit = 1
Jul 10 01:49:16.438: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:16.438: //239520//Digi:/act_DCRunning_Digit: : pLeg 239521 Digit 1 Tone Mode 0
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_TreatDigit:
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_DialPlanMatch: pattern offset=0, digits=13999522383451
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_DialPlanMatch: src carrier id:, tgt carrier id:
Jul 10 01:49:16.438: //239520//Digi:/DigitCollect_DialPlanMatch: Match single infotype
Jul 10 01:49:16.450: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:49:16.450: htsp_timer - 1000 msec
Jul 10 01:49:17.451: htsp_process_event: [1/0:0(4), FXSLS_CONNECT, E_HTSP_EVENT_TIMER]fxsls_connect_wait_release_req
Jul 10 01:49:17.451: htsp_timer_stop
Jul 10 01:49:17.451: //239520//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:49:17.451: //239520//Digi:/act_DCRunning_Disconnected:
Jul 10 01:49:17.451: //-1//Digi:/DigitCollect_Complete: DC_DISCONNECTED. Digits=13999522383451
Jul 10 01:49:17.451: //239520//TCL :/tcl_PutsObjCmd:
Cleaning up...................
Jul 10 01:49:17.451:
Jul 10 01:49:17.451: //239520//TCL :/tcl_CallObjCmd: call close
Jul 10 01:49:17.451: //239520//TCL :/tcl_CallCloseObjCmd: close
Jul 10 01:49:17.451: //239520//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:49:17.451: //239520//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:49:17.451: htsp_timer_stop3
Jul 10 01:49:17.479: htsp_process_event: [1/0:0(4), FXSLS_WAIT_RELEASE_REQ, E_HTSP_RELEASE_REQ]fxsls_waitrls_req_rlsvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(4)] set signal state = 0x4
Jul 10 01:49:17.483: htsp_process_event: [1/0:0(4), FXSLS_ONHOOK, E_DSP_SIG_0100]fxsls_onhook_onhook
Jul 10 01:50:10.706: //237039//PACK:/DoMediaStop:
Jul 10 01:51:22.736: %ISDN-6-CONNECT: Interface Serial0/0/0:21 is now connected to 3212004539 N/A
q99921voipgw1#
q99921voipgw1#
q99921voipgw1#
q99921voipgw1#clear log
Clear logging buffer
q99921voipgw1#show log
Syslog logging: enabled (266 messages dropped, 148 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: level debugging, 1045135 messages logged, xml disabled,
filtering disabled
Monitor logging: level debugging, 37099 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 1045251 messages logged, xml disabled,
filtering disabled
Exception Logging: size (8192 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 110787 message lines logged
Logging to 10.44.33.63 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.44.28.5 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.170.100.23 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Log Buffer (1024000 bytes):
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_incdid: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_dnis: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setupack leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegSetupAckObjCmd: setupack leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg proceeding leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg connect leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegConnectObjCmd: connect leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 4
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: htsp_timer_stop3 htsp_setup_req
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_ONHOOK, E_HTSP_SETUP_REQ]fxsls_onhook_setuphtsp_alertvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x0
Jul 10 01:51:52.965: htsp_call_bridged invoked
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxsls_waitoff_voice
Jul 10 01:51:55.013: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_DSP_SIG_1100]fxsls_waitoff_offhookvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x6
Jul 10 01:51:55.013: htsp_timer2 - 200 msec
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_EVENT_TIMER2]fxsls_offhook_dial htsp_dial
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_DIALING_DONE]fxsls_conn_dial_done
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//AFW_:/vtr_ev_status: argc 2 argindex 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_PutsObjCmd:
Call to Number successful
Jul 10 01:51:55.213:
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//AFW_:/vtr_lg_all: argc 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_LegObjCmd: leg collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Digi:/tcl_LegDigitCollectObjCmd: collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=2
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239528, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239528/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239529, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239529/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239528 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239529 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:52:31.588: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:52:31.588: htsp_timer - 1000 msec
Jul 10 01:52:32.190: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_1100]fxsls_offhook_offhookhtsp_hook_flash_ind
Jul 10 01:52:32.190: htsp_timer_stop
Jul 10 01:52:32.577: htsp_digit_ready(1/0:0(1)): digit = 1
Jul 10 01:52:32.737: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:32.897: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.029: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.191: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.349: htsp_digit_ready(1/0:0(1)): digit = 5
Jul 10 01:52:33.509: htsp_digit_ready(1/0:0(1)): digit = 2
Jul 10 01:52:33.669: htsp_digit_ready(1/0:0(1)): digit = 2
q99921voipgw1#show log
Syslog logging: enabled (266 messages dropped, 148 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)
No Active Message Discriminator.
No Inactive Message Discriminator.
Console logging: level debugging, 1045171 messages logged, xml disabled,
filtering disabled
Monitor logging: level debugging, 37099 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 1045287 messages logged, xml disabled,
filtering disabled
Exception Logging: size (8192 bytes)
Count and timestamp logging messages: disabled
Persistent logging: disabled
Trap logging: level informational, 110787 message lines logged
Logging to 10.44.33.63 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.44.28.5 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Logging to 10.170.100.23 (udp port 514, audit disabled,
link up),
110787 message lines logged,
0 message lines rate-limited,
0 message lines dropped-by-MD,
xml disabled, sequence number disabled
filtering disabled
Log Buffer (1024000 bytes):
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_isdid
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_incdid: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis
Jul 10 01:51:52.963: //239528//AFW_:/vtr_lg_dnis: argc 2 argindex 2
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setupack leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegSetupAckObjCmd: setupack leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg proceeding leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg connect leg_incoming
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegConnectObjCmd: connect leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 2
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: //239528//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: argc 4
Jul 10 01:51:52.963: //239528//AFW_:/vtd_lg_incoming: Legs [239528 ]
Jul 10 01:51:52.963: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
Jul 10 01:51:52.963: htsp_timer_stop3 htsp_setup_req
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_ONHOOK, E_HTSP_SETUP_REQ]fxsls_onhook_setuphtsp_alertvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x0
Jul 10 01:51:52.965: htsp_call_bridged invoked
Jul 10 01:51:52.965: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxsls_waitoff_voice
Jul 10 01:51:55.013: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_DSP_SIG_1100]fxsls_waitoff_offhookvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x6
Jul 10 01:51:55.013: htsp_timer2 - 200 msec
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_WAIT_OFFHOOK, E_HTSP_EVENT_TIMER2]fxsls_offhook_dial htsp_dial
Jul 10 01:51:55.213: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_DIALING_DONE]fxsls_conn_dial_done
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status
Jul 10 01:51:55.213: //239528//AFW_:/vtr_ev_status: argc 2 argindex 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_PutsObjCmd:
Call to Number successful
Jul 10 01:51:55.213:
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//TCL :/tcl_InfotagGetObjCmd: infotag get leg_all
Jul 10 01:51:55.213: //239528//AFW_:/vtr_lg_all: argc 2
Jul 10 01:51:55.213: //239528//TCL :/tcl_LegObjCmd: leg collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Digi:/tcl_LegDigitCollectObjCmd: collectdigits 239528 239529 dcparams
Jul 10 01:51:55.213: //239528//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=2
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239528, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239528/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/C_DigitCollect_Start: Leg=239529, Dialplan=False, Diaplanterm=False, DigitReport=True, DigitConsume=False IgnoreInitialKey=False, IgnoreDTMFacceptINFO=False, Abortkey=^@, Terminationkey=^@, Numpatterns=0, Maxdigits=0, Mindigits=0, Interruptprompt=False, InterTimeout=-1000, Initialtimeout=-1000, Mask=0 Hotword=0
Jul 10 01:51:55.213: //-1//Digi:/AFW_DigitCollect_New:
Jul 10 01:51:55.213: //-1//Digi:HNCD51947E:/AFW_DigitCollect_New: DialPlan=FALSE AbortKey=^@ TermKey=^@ NumPatts=0
Enable=TRUE Consume=FALSE InterruptPrompt=FALSE minDigits=0 maxDigits=0 DialPlanTerm=FALSE hotword=0
Jul 10 01:51:55.213: //239529/D09671800006/Digi:/DigitCollectStart_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollect_MLPPTuning: Precednece Digit Collect not enabled
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239528 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_Action:
Jul 10 01:51:55.213: //239528//Digi:/act_DCRunning_RDone: id=239529 Enable succeeded.enable=1 matchDialplan=0 numPatterns=0matchDialplanTerm=0
Jul 10 01:51:55.213: //-1//Digi:/DigitCollect_Complete: DC_ENABLED. Digits=
Jul 10 01:51:55.213: //239528//Digi:/AFW_M_DigitCollect_EventPreProcess:
Jul 10 01:51:55.213: //239528//Digi:/DigitCollectEnd_UpdateStats:
Jul 10 01:52:31.588: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:52:31.588: htsp_timer - 1000 msec
Jul 10 01:52:32.190: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_1100]fxsls_offhook_offhookhtsp_hook_flash_ind
Jul 10 01:52:32.190: htsp_timer_stop
Jul 10 01:52:32.577: htsp_digit_ready(1/0:0(1)): digit = 1
Jul 10 01:52:32.737: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:32.897: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.029: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.191: htsp_digit_ready(1/0:0(1)): digit = 9
Jul 10 01:52:33.349: htsp_digit_ready(1/0:0(1)): digit = 5
Jul 10 01:52:33.509: htsp_digit_ready(1/0:0(1)): digit = 2
Jul 10 01:52:33.669: htsp_digit_ready(1/0:0(1)): digit = 2
Jul 10 01:52:33.829: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:33.989: htsp_digit_ready(1/0:0(1)): digit = 8
Jul 10 01:52:34.149: htsp_digit_ready(1/0:0(1)): digit = 3
Jul 10 01:52:34.309: htsp_digit_ready(1/0:0(1)): digit = 4
Jul 10 01:52:34.469: htsp_digit_ready(1/0:0(1)): digit = 5
Jul 10 01:52:34.629: htsp_digit_ready(1/0:0(1)): digit = 1
Jul 10 01:52:34.637: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_DSP_SIG_0100]fxsls_offhook_onhook, HF duration Max=1000, HF duration Min=150
Jul 10 01:52:34.637: htsp_timer - 1000 msec
Jul 10 01:52:35.637: htsp_process_event: [1/0:0(1), FXSLS_CONNECT, E_HTSP_EVENT_TIMER]fxsls_connect_wait_release_req
Jul 10 01:52:35.637: htsp_timer_stop
Jul 10 01:52:35.637: //239528//TCL :/tcl_PutsObjCmd:
Cleaning up...................
Jul 10 01:52:35.637:
Jul 10 01:52:35.637: //239528//TCL :/tcl_CallObjCmd: call close
Jul 10 01:52:35.637: //239528//TCL :/tcl_CallCloseObjCmd: close
Jul 10 01:52:35.637: htsp_timer_stop3
Jul 10 01:52:35.669: htsp_process_event: [1/0:0(1), FXSLS_WAIT_RELEASE_REQ, E_HTSP_RELEASE_REQ]fxsls_waitrls_req_rlsvnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4vnm_dsp_set_sig_state:[Foreign Exchange Station 1/0:0(1)] set signal state = 0x4
Jul 10 01:52:35.673: htsp_process_event: [1/0:0(1), FXSLS_ONHOOK, E_DSP_SIG_0100]fxsls_onhook_onhook
Subject: RE: TCL ev_feature event inconsistent
Replied by: Yaw-Ming Chen on 23-07-2012 01:59:45 PM
I wonder how the call can be established?
Looks like the incoming leg is SIP
Jul 10 01:48:42.162: //239520//TCL :/tcl_LegObjCmd: leg setup sip:19528284207@10.170.47.11:5060 callInfo leg_incoming
Let setup command only takes digits, so before the leg setup you may want to extract the calling number like
regexp {[0-9]+} $dnis dnis
Subject: RE: TCL ev_feature event inconsistent
Replied by: James Clapper on 23-07-2012 04:30:57 PM
Thats a good question. It does however connect as you can see. Also get the IVR recording and status code is ls_000. Shouldn't this fail actually?
Will try and pull out the DNIS and see if that is the core of my issue.
These are my dial-peers:
dial-peer voice 4207 voip
service cast1hookflash
incoming called-number 19528284207
dtmf-relay rtp-nte digit-drop h245-alphanumeric
dial-peer voice 4208 pots
destination-pattern 19528284207
port 1/0:0
forward-digits 0
Subject: RE: TCL ev_feature event inconsistent
Replied by: James Clapper on 23-07-2012 04:46:22 PM
Got the digits only by adding the regex.
regexp {[0-9]{11}} $dest dest
leg setup $dest callInfo leg_incoming
Still works, but same issue as before. Only seeing the hookflash event every once and a while.
Subject: RE: TCL ev_feature event inconsistent
Replied by: Yaw-Ming Chen on 23-07-2012 05:01:40 PM
Also put "infotag set evt_feature_report hookflash" in the beginning of act_setup procedure see if it helps.
Subject: RE: TCL ev_feature event inconsistent
Replied by: James Clapper on 24-07-2012 08:48:14 PM
That did it! Hey thanks much. Guess it makes sense not to have it in init if I think about it.
Labels:
Getting Started
Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community:
Customers Also Viewed These Support Documents