cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
149
Views
0
Helpful
0
Comments
cdnadmin
Level 11
Level 11
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.
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:

Quick Links