=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2022.08.28 11:40:02 =~=~=~=~=~=~=~=~=~=~=~=
debug vpm signal
Voice Port Module signaling debugging is enabled
CME_4331-VoiceGW#debug vtsp dsp
This CLI command is now 'debug voip dsm dsp'

CME_4331-VoiceGW#debug vtsp session
This CLI command is now 'debug voip vtsp session'

CME_4331-VoiceGW#de  
CME_4331-VoiceGW#

CME_4331-VoiceGW#debug voice ccapi inout 
voip ccapi inout debugging is on
CME_4331-VoiceGW#
CME_4331-VoiceGW#
CME_4331-VoiceGW#
CME_4331-VoiceGW#
CME_4331-VoiceGW#term mon
CME_4331-VoiceGW#term monitor 
CME_4331-VoiceGW#
Aug 28 08:47:16.894: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=61093 systime=179100277
Aug 28 08:47:16.895: htsp_process_event: [0/2/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Aug 28 08:47:16.895: htsp_timer - 125 msec
Aug 28 08:47:17.020: htsp_process_event: [0/2/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Aug 28 08:47:17.020: htsp_timer - 10000 msec
Aug 28 08:47:17.020: htsp_timer_stop3 htsp_setup_ind
Aug 28 08:47:17.020: [0/2/1] get_fxo_caller_id:Caller ID receive failed.  parseCallerIDString:no data.
Aug 28 08:47:17.020: [0/2/1] get_local_station_id calling num= calling name= calling time=08/28 11:47  orig called=
Aug 28 08:47:17.021: //-1/DAB1A547B457/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=4016
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFFFFFFFFFF
   cisco-rdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=0
   cisco-rdnsi=0
   cisco-redirectreason=0   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

Aug 28 08:47:17.022: //-1/DAB1A547B457/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x7FD8E3E2F390, Call Info(
   Calling Number=,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4016(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=1014, Progress Indication=ORIGINATING SIDE IS NON ISDN(3), Calling IE Present=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
Aug 28 08:47:17.022: //-1/DAB1A547B457/CCAPI/ccCheckClipClir:
   In: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Aug 28 08:47:17.022: //-1/DAB1A547B457/CCAPI/ccCheckClipClir:
   Out: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Aug 28 08:47:17.022: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Aug 28 08:47:17.022: :cc_get_feature_vsa malloc success
Aug 28 08:47:17.022: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Aug 28 08:47:17.022:  cc_get_feature_vsa count is 5
Aug 28 08:47:17.022: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Aug 28 08:47:17.022: :FEATURE_VSA attributes are: feature_name:0,feature_time:140569511142148,feature_id:18284
Aug 28 08:47:17.022: //21844/DAB1A547B457/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4016(TON=Unknown, NPI=Unknown))
Aug 28 08:47:17.023: htsp_process_event: [0/2/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Aug 28 08:47:17.023: fxols_wait_setup_ack: 
Aug 28 08:47:17.023: htsp_timer - 6000 msec
Aug 28 08:47:17.023: [0/2/1] htsp_start_caller_id_rx: Warning!! DTMF callerid requires line reversal alerting. 
Aug 28 08:47:17.023: [0/2/1] htsp_start_caller_id_rx:Mode DTMF. Alerting 0x4
Aug 28 08:47:17.023: //21844/DAB1A547B457/CCAPI/cc_process_call_setup_ind:
   Event=0x7FD8E3C91030
Aug 28 08:47:17.023: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 4016
Aug 28 08:47:17.024: //21844/DAB1A547B457/CCAPI/ccCallSetContext:
   Context=0x7FD8EF764D30
Aug 28 08:47:17.024: //21844/DAB1A547B457/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 21844 with tag 1014 to app "_ManagedAppProcess_Default"
Aug 28 08:47:17.026: //21844/DAB1A547B457/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
Aug 28 08:47:17.027: //21844/DAB1A547B457/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=FALSE, Mode=0,
   Outgoing Dial-peer=20004, Params=0x7FD8EF777980, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
Aug 28 08:47:17.027: //21844/DAB1A547B457/CCAPI/ccCheckClipClir:
   In: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Aug 28 08:47:17.027: //21844/DAB1A547B457/CCAPI/ccCheckClipClir:
   Out: Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Aug 28 08:47:17.027: //21844/DAB1A547B457/CCAPI/ccCallSetupRequest:
   Destination Pattern=4016$, Called Number=4016, Digit Strip=TRUE
Aug 28 08:47:17.027: //21844/DAB1A547B457/CCAPI/ccCallSetupRequest:
   Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4016(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=, Final Destination Flag=TRUE,
   Guid=DAB1A547-25E4-11ED-B457-9EBB5B9E066D, Outgoing Dial-peer=20004
Aug 28 08:47:17.027: //21844/DAB1A547B457/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=
   ----- ccCallInfo IE subfields -----
   cisco-ani=
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=4016
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFFFFFFFFFF
   cisco-rdn=
   cisco-rdntype=0
   cisco-rdnplan=0
   cisco-rdnpi=0
   cisco-rdnsi=0
   cisco-redirectreason=0   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0

Aug 28 08:47:17.028: //21844/DAB1A547B457/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x7FD8EE807460, Interface Type=6, Destination=, Mode=0x0,
   Call Params(Calling Number=,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=4016(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=20004, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Aug 28 08:47:17.028: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Aug 28 08:47:17.028: :cc_get_feature_vsa malloc success
Aug 28 08:47:17.028: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Aug 28 08:47:17.028:  cc_get_feature_vsa count is 6
Aug 28 08:47:17.028: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Aug 28 08:47:17.028: :FEATURE_VSA attributes are: feature_name:0,feature_time:140569511139236,feature_id:18285
Aug 28 08:47:17.028: //21845/DAB1A547B457/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
Aug 28 08:47:17.028: //21845/DAB1A547B457/CCAPI/ccCallSetContext:
   Context=0x7FD8EF777900
Aug 28 08:47:17.028: //21844/DAB1A547B457/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=20004
Aug 28 08:47:17.029: htsp_timer_stop3 
Aug 28 08:47:17.029: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_setup_req
Aug 28 08:47:17.030:  Orig called num:4016
Aug 28 08:47:17.030: //21845/DAB1A547B457/CCAPI/cc_api_update_call_info:
   Interface=0x7FD8EE807460, Call Id=0x5555
Aug 28 08:47:17.030: htsp_process_event: [50/0/4.1, EFXS_ONHOOK, E_HTSP_SETUP_REQ]efxs_onhook_setup
Aug 28 08:47:17.031: htsp_ephone_start_caller_id_tx calling num= calling name = called num=4016 orig called num=
Aug 28 08:47:17.031: [50/0/4.1] set signal state = 0x0 timestamp = 0
Aug 28 08:47:17.031: efxs_onhook_setup: local target is available
htsp_alert
Aug 28 08:47:17.032: //21845/DAB1A547B457/CCAPI/cc_api_call_proceeding:
   Interface=0x7FD8EE807460, Progress Indication=NULL(0)
Aug 28 08:47:17.033: //21845/DAB1A547B457/CCAPI/cc_api_call_alert:
   Interface=0x7FD8EE807460, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
Aug 28 08:47:17.033: //21845/DAB1A547B457/CCAPI/cc_api_call_alert:
   Call Entry(Retry Count=0, Responsed=TRUE)
Aug 28 08:47:17.033: //21844/DAB1A547B457/CCAPI/ccCallAlert:
   Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
Aug 28 08:47:17.033: //21844/DAB1A547B457/CCAPI/ccCallAlert:
   Call Entry(Responsed=TRUE, Alert Sent=TRUE)htsp_alert_notify
Aug 28 08:47:17.034: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alert
Aug 28 08:47:17.968: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=62170 systime=179100385
Aug 28 08:47:17.968: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear 
Aug 28 08:47:17.968: htsp_timer_stop2 
Aug 28 08:47:17.968: htsp_timer - 6000 msec
Aug 28 08:47:20.898: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=65104 systime=179100678
Aug 28 08:47:20.898: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring 
Aug 28 08:47:20.898: htsp_timer_stop 
Aug 28 08:47:21.974: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=640 systime=179100785
Aug 28 08:47:21.974: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear 
Aug 28 08:47:21.974: htsp_timer_stop2 
Aug 28 08:47:21.974: htsp_timer - 6000 msec
Aug 28 08:47:25.900: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=4556 systime=179101178
Aug 28 08:47:25.900: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring 
Aug 28 08:47:25.900: htsp_timer_stop 
Aug 28 08:47:26.981: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=5647 systime=179101286
Aug 28 08:47:26.981: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear 
Aug 28 08:47:26.982: htsp_timer_stop2 
Aug 28 08:47:26.982: htsp_timer - 6000 msec
Aug 28 08:47:30.899: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=9563 systime=179101678
Aug 28 08:47:30.899: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring 
Aug 28 08:47:30.899: htsp_timer_stop 
Aug 28 08:47:31.992: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=10655 systime=179101787
Aug 28 08:47:31.993: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear 
Aug 28 08:47:31.993: htsp_timer_stop2 
Aug 28 08:47:31.993: htsp_timer - 6000 msec
CME_4331-VoiceGW#
Aug 28 08:47:37.993: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Aug 28 08:47:37.994: htsp_timer_stop 
Aug 28 08:47:37.994: htsp_timer_stop2 
Aug 28 08:47:37.994: htsp_timer_stop3 
Aug 28 08:47:37.994: [0/2/1] htsp_stop_caller_id_rx. message length 0
Aug 28 08:47:37.994: //21844/DAB1A547B457/CCAPI/cc_api_call_disconnected:
   Cause Value=17, Interface=0x7FD8E3E2F390, Call Id=21844
Aug 28 08:47:37.994: //21844/DAB1A547B457/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=17, Retry Count=0)
Aug 28 08:47:37.994: //21844/DAB1A547B457/CCAPI/ccGenerateToneInfo:
   Stop Tone On Digit=FALSE, Tone=Null,
   Tone Direction=Network, Params=0x0, Call Id=21844
Aug 28 08:47:37.995: //21845/DAB1A547B457/CCAPI/ccCallDisconnect:
   Cause Value=17, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Aug 28 08:47:37.995: //21845/DAB1A547B457/CCAPI/ccCallDisconnect:
   Cause Value=17, Call Entry(Responsed=TRUE, Cause Value=17)
Aug 28 08:47:37.995: //21845/DAB1A547B457/CCAPI/cc_api_get_transfer_info:
   Transfer Number=NULL
Aug 28 08:47:37.995: htsp_timer_stop3 
Aug 28 08:47:37.996: //21844/DAB1A547B457/CCAPI/ccCallDisconnect:
   Cause Value=17, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=17)
Aug 28 08:47:37.996: //21844/DAB1A547B457/CCAPI/ccCallDisconnect:
   Cause Value=17, Call Entry(Responsed=TRUE, Cause Value=17)
Aug 28 08:47:37.996: //21844/DAB1A547B457/CCAPI/cc_api_get_transfer_info:
   Transfer Number=NULL
Aug 28 08:47:37.997: htsp_process_event: [50/0/4.1, EFXS_WAIT_OFFHOOK, E_HTSP_RELEASE_REQ]efxs_waitoff_release
Aug 28 08:47:37.997: [50/0/4.1] set signal state = 0x4 timestamp = 0
Aug 28 08:47:37.998: htsp_process_event: [0/2/1, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Aug 28 08:47:37.998: htsp_timer_stop 
Aug 28 08:47:37.998: htsp_timer_stop2 
Aug 28 08:47:37.998: htsp_timer_stop3 
Aug 28 08:47:37.998: [0/2/1] nim_set_sig_state: ABCD=4, timestamp=0, sys_time=179102388
Aug 28 08:47:37.998: [0/2/1] set signal state = 0x4 timestamp = 0
Aug 28 08:47:37.999: htsp_timer - 2000 msec
Aug 28 08:47:38.001: //21845/DAB1A547B457/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x7FD8EE807460, Tag=0x0, Call Id=21845,
   Call Entry(Disconnect Cause=17, Voice Class Cause Code=0, Retry Count=0)
Aug 28 08:47:38.002: //21845/DAB1A547B457/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Aug 28 08:47:38.002: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Aug 28 08:47:38.002: :cc_free_feature_vsa freeing 7FD8E3C71798
Aug 28 08:47:38.002: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Aug 28 08:47:38.002:  vsacount in free is 5
Aug 28 08:47:38.004: //21844/DAB1A547B457/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x7FD8E3E2F390, Tag=0x0, Call Id=21844,
   Call Entry(Disconnect Cause=17, Voice Class Cause Code=0, Retry Count=0)
Aug 28 08:47:38.004: //21844/DAB1A547B457/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Aug 28 08:47:38.004: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Aug 28 08:47:38.004: :cc_free_feature_vsa freeing 7FD8E3C722F8
Aug 28 08:47:38.004: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Aug 28 08:47:38.004:  vsacount in free is 4
CME_4331-VoiceGW#
CME_4331-VoiceGW#
CME_4331-VoiceGW#u
Aug 28 08:47:39.998: htsp_process_event: [0/2/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Aug 28 08:47:40.011: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=0 systime=179102589
Aug 28 08:47:40.011: htsp_process_event: [0/2/1, FXOLS_ONHOOK, E_DSP_SIG_0100]n de all
undebug de all
          ^
% Invalid input detected at '^' marker.

CME_4331-VoiceGW#und
Aug 28 08:47:46.154: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=57040 systime=179103203
Aug 28 08:47:46.154: htsp_process_event: [50/0/8.1, EFXS_CONNECT, E_DSP_SIG_0100]efxs_offhook_onhook
Aug 28 08:47:46.154: htsp_timer - 10 msec
Aug 28 08:47:46.165: htsp_process_event: [50/0/8.1, EFXS_CONNECT, E_HTSP_EVENT_TIMER]efxs_connect_wait_release_req
Aug 28 08:47:46.165: htsp_timer_stop 
Aug 28 08:47:46.165: //21839/BBF3289CB44C/CCAPI/cc_api_call_disconnected:
   Cause Value=16, Interface=0x7FD8EE888CC0, Call Id=21839
Aug 28 08:47:46.165: //21839/BBF3289CB44C/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
Aug 28 08:47:46.166: //21838/BBF3289CB44C/CCAPI/ccConferenceDestroy:
   Conference Id=0x13BE, Tag=0x0
Aug 28 08:47:46.166: //21838/BBF3289CB44C/CCAPI/ccConferenceDestroy:
   
Aug 28 08:47:46.166: confID:0x13BE; callEntry1 callID1:0x554E, type:6; callEntry2 callID2:0x554F, type:6

Aug 28 08:47:46.166: //21838/BBF3289CB44C/CCAPI/cc_api_bridge_drop_done:
   Conference Id=0x13BE, Source Interface=0x7FD8EE9CBB80, Source Call Id=21838,
   Destination Call Id=21839, Disposition=0x0, Tag=0x0
Aug 28 08:47:46.167: //21839/BBF3289CB44C/CCAPI/cc_api_bridge_drop_done:
   Conference Id=0x13BE, Source Interface=0x7FD8EE888CC0, Source Call Id=21839,
   Destination Call Id=21838, Disposition=0x0, Tag=0x0
Aug 28 08:47:46.167: //21838/BBF3289CB44C/CCAPI/cc_generic_bridge_done:
   Conference Id=0x13BE, Source Interface=0x7FD8EE888CC0, Source Call Id=21839,
   Destination Call Id=21838, Disposition=0x0, Tag=0x0
Aug 28 08:47:46.167: //21838/BBF3289CB44C/CCAPI/ccCallDisconnect:
   Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Aug 28 08:47:46.167: //21838/BBF3289CB44C/CCAPI/ccCallDisconnect:
   Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
Aug 28 08:47:46.168: //21838/BBF3289CB44C/CCAPI/cc_api_get_transfer_info:
   Transfer Number=NULL
Aug 28 08:47:46.168: //21839/BBF3289CB44C/CCAPI/ccCallDisconnect:
   Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
Aug 28 08:47:46.168: //21839/BBF3289CB44C/CCAPI/ccCallDisconnect:
   Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
Aug 28 08:47:46.168: //21839/BBF3289CB44C/CCAPI/cc_api_get_transfer_info:
   Transfer Number=NULL
Aug 28 08:47:46.168: htsp_timer_stop3 
Aug 28 08:47:46.169: htsp_timer_stop3 
Aug 28 08:47:46.169: htsp_process_event: [50/0/22.1, EFXS_CONNECT, E_HTSP_RELEASE_REQ]efxs_connect_disc
Aug 28 08:47:46.169: htsp_timer_stop 
Aug 28 08:47:46.169: [50/0/22.1] set signal state = 0xC timestamp = 0
Aug 28 08:47:46.169: [50/0/22.1] set signal state = 0x4 timestamp = 0efxs_cpc_timer
Aug 28 08:47:46.169: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=39536 systime=179103205
Aug 28 08:47:46.169: htsp_timer - 30000 msec
Aug 28 08:47:46.170: htsp_process_event: [50/0/8.1, EFXS_WAIT_RELEASE_REQ, E_HTSP_RELEASE_REQ]efxs_waitrls_req_rlshtsp_report_onhook_sig
Aug 28 08:47:46.170: //21839/BBF3289CB44C/CCAPI/cc_api_call_feature:
   Feature Type=6, Interface=0x7FD8EE888CC0, Call Id=21839
Aug 28 08:47:46.170: htsp_process_event: [50/0/22.1, EFXS_WAIT_ONHOOK, E_DSP_SIG_0100]efxs_waitonhook_onhook
Aug 28 08:47:46.170: htsp_timer_stop htsp_report_onhook_sig
Aug 28 08:47:46.171: //21838/BBF3289CB44C/CCAPI/cc_api_call_feature:
   Feature Type=6, Interface=0x7FD8EE9CBB80, Call Id=21838
Aug 28 08:47:46.173: //21839/BBF3289CB44C/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x7FD8EE888CC0, Tag=0x0, Call Id=21839,
   Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
Aug 28 08:47:46.173: //21839/BBF3289CB44C/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Aug 28 08:47:46.173: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Aug 28 08:47:46.173: :cc_free_feature_vsa freeing 7FD8E3C71BF8
Aug 28 08:47:46.173: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Aug 28 08:47:46.173:  vsacount in free is 3
Aug 28 08:47:46.173: //21838/BBF3289CB44C/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x7FD8EE9CBB80, Tag=0x0, Call Id=21838,
   Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
Aug 28 08:47:46.173: //21838/BBF3289CB44C/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Aug 28 08:47:46.173: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
    al
Aug 28 08:47:46.173: :cc_free_feature_vsa freeing 7FD8E3C729F8
Aug 28 08:47:46.173: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Aug 28 08:47:46.173:  vsacount in free is 2