GCityRouter#sh debug

Voice Port Module session debugging is on
Voice Port Module DSPware overlay debugging is on
Voice Port Module error debugging is on
Voice Port Module signaling debugging is on
Voice Port Module voaal2 debugging (type3  ) is on
 
Voice Port Module trunk conditioning is on
Voice Port Module tgrm debugging is on

 
GCityRouter#
Nov  5 2019 01:37:06.712 UTC: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=56897 systime=415070215
Nov  5 2019 01:37:06.712 UTC: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Nov  5 2019 01:37:06.712 UTC: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_PENDING, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Nov  5 2019 01:37:06.712 UTC: htsp_timer - 125 msec
Nov  5 2019 01:37:06.840 UTC: htsp_process_event: [0/1/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Nov  5 2019 01:37:06.840 UTC: htsp_timer - 10000 msec
Nov  5 2019 01:37:06.840 UTC: htsp_timer3 - 5600 msec
Nov  5 2019 01:37:06.840 UTC: [0/1/0] htsp_start_caller_id_rx:Mode BELLCORE. Alerting 0x1
Nov  5 2019 01:37:06.840 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_create: .
Nov  5 2019 01:37:06.840 UTC: //-1/313233343930/DSM:(0/1/0):-1/set_echo_canceller_data: echo_cancel: 0
Nov  5 2019 01:37:06.840 UTC: //-1/313233343930/DSM:(0/1/0):-1/set_echo_canceller_data: echo_flags: 38, echo_len: 1024
Nov  5 2019 01:37:06.840 UTC: htsp_start_caller_id_rx create dsp_stream_manager
Nov  5 2019 01:37:06.840 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_set_dsp_allocated: .
Nov  5 2019 01:37:06.840 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_set_feature_parameters: Fax Relay Version after update = 0
Nov  5 2019 01:37:06.840 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_implement_feature:
Nov  5 2019 01:37:06.840 UTC: dsp_stream_mgr_implement_feature: feature id = 7
Nov  5 2019 01:37:06.844 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsmp_dsmapi_reserve_resource_cb: .
Nov  5 2019 01:37:06.844 UTC: [0/1/0] htsp_dsm_create_success  returns 1
Nov  5 2019 01:37:06.844 UTC: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec

*****

Nov  5 2019 01:37:08.796 UTC: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=58979 systime=415070423
Nov  5 2019 01:37:08.796 UTC: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
Nov  5 2019 01:37:08.796 UTC: fxols_ringing_not
Nov  5 2019 01:37:08.796 UTC: htsp_timer_stop
Nov  5 2019 01:37:08.796 UTC: htsp_timer - 10000 msec,     

*****
 
GCityRouter#
Nov  5 2019 01:37:14.744 UTC: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=64927 systime=415071018
Nov  5 2019 01:37:14.744 UTC: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
Nov  5 2019 01:37:14.744 UTC: fxols_ringing_not
Nov  5 2019 01:37:14.744 UTC: htsp_timer_stop
Nov  5 2019 01:37:14.744 UTC: htsp_timer_stop3
Nov  5 2019 01:37:14.744 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_destroy: .
Nov  5 2019 01:37:14.744 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsm_delete_all_streams: .
Nov  5 2019 01:37:14.744 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsmapi_accept_modem_passthrough_session:  : dmgr: 3E383208, active sessions 0, max sessions: 16 rejected sessions till now: 0
Nov  5 2019 01:37:14.744 UTC: [0/1/0] htsp_stop_caller_id_rx. message length 0
Nov  5 2019 01:37:14.744 UTC: htsp_timer3 - 20 msec
Nov  5 2019 01:37:14.748 UTC: flex_dsprm_close_cleanup
Nov  5 2019 01:37:14.748 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsmp_dsmapi_reserve_resource_cb: .
Nov  5 2019 01:37:14.748 UTC: [0/1/0] htsp_dsm_close_done
Nov  5 2019 01:37:14.764 UTC: htsp_process_event: [0/1/0, FXOLS_STOP_CALLERID_DELAY, E_HTSP_EVENT_TIMER3]
Nov  5 2019 01:37:14.764 UTC: htsp_timer_stop
Nov  5 2019 01:37:14.764 UTC: htsp_timer_stop3 htsp_setup_ind
Nov  5 2019 01:37:14.764 UTC: [0/1/0] get_fxo_caller_id:Caller ID receive failed.  parseCallerIDString:no data.
Nov  5 2019 01:37:14.764 UTC: [0/1/0] get_local_station_id calling num= calling name= calling time=11/05 01:37  orig called=
Nov  5 2019 01:37:14.764 UTC: TGRM: reg_invoke_tgrm_accept_call(1, TGRM_CALL_VOICE, TGRM_DIRECTION_IN, 0, 1, 0, 65535)
Nov  5 2019 01:37:14.764 UTC: TGRM: Calling vtsp_tsp_call_setup_ind().
Nov  5 2019 01:37:14.764 UTC: fxols_callerid_done: call being answered
Nov  5 2019 01:37:14.768 UTC: htsp_process_event: [0/1/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Nov  5 2019 01:37:14.768 UTC: fxols_wait_setup_ack:
Nov  5 2019 01:37:14.768 UTC: [0/1/0] set signal state = 0xC timestamp = 0
Nov  5 2019 01:37:14.768 UTC: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0xC timestamp=0x0fxols_check_auto_call
Nov  5 2019 01:37:14.772 UTC: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc
Nov  5 2019 01:37:14.772 UTC: htsp_timer - 120000 msechtsp_alert_notify
Nov  5 2019 01:37:14.952 UTC: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alert
Nov  5 2019 01:37:14.952 UTC: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec .    

****

GCityRouter#
Nov  5 2019 01:37:15.020 UTC: htsp_dsp_message: SEND_SIG_STATUS: state=0xC timestamp=65204 systime=415071046
Nov  5 2019 01:37:15.020 UTC: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_DSP_SIG_1100]fxols_offhook_disc
Nov  5 2019 01:37:15.020 UTC: htsp_timer2 - 350 msec
Nov  5 2019 01:37:15.372 UTC: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER2]fxols_disc_confirm
Nov  5 2019 01:37:15.372 UTC: htsp_timer_stop
Nov  5 2019 01:37:15.372 UTC: htsp_timer_stop2
Nov  5 2019 01:37:15.372 UTC: htsp_timer_stop3 htsp_release_req: cause 16, no_onhook 0
Nov  5 2019 01:37:15.372 UTC: htsp_process_event: [0/1/0, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Nov  5 2019 01:37:15.372 UTC: htsp_timer_stop
Nov  5 2019 01:37:15.372 UTC: htsp_timer_stop2
Nov  5 2019 01:37:15.372 UTC: htsp_timer_stop3
Nov  5 2019 01:37:15.372 UTC: [0/1/0] set signal state = 0x4 timestamp = 0
Nov  5 2019 01:37:15.372 UTC: dsp_set_sig_state: [0/1/0] packet_len=12 channel_id=128 packet_id=39 state=0x4 timestamp=0x0
Nov  5 2019 01:37:15.372 UTC: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Nov  5 2019 01:37:15.372 UTC: htsp_timer - 2000 msec
Nov  5 2019 01:37:15.372 UTC: TGRM: reg_invoke_tgrm_channel_service_update(0, 1, 0, 65535, 1)
Nov  5 2019 01:37:15.372 UTC: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Nov  5 2019 01:37:15.380 UTC: flex_dsprm_close_cleanup
Nov  5 2019 01:37:17.372 UTC: htsp_process_event: [0/1/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Nov  5 2019 01:37:17.372 UTC: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Nov  5 2019 01:37:17.372 UTC: dsp_req_sig_state: [0/1/0] packet_len=8 channel_id=128 packet_id=40
Nov  5 2019 01:37:17.372 UTC: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=0 systime=415071281
Nov  5 2019 01:37:17.372 UTC: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0100]

****

Nov  5 2019 01:37:18.664 UTC: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=3308 systime=415071410
Nov  5 2019 01:37:18.664 UTC: htsp_process_event: [0/1/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Nov  5 2019 01:37:18.664 UTC: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_PENDING, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Nov  5 2019 01:37:18.664 UTC: htsp_timer - 125 msec
Nov  5 2019 01:37:18.792 UTC: htsp_process_event: [0/1/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Nov  5 2019 01:37:18.792 UTC: htsp_timer - 10000 msec
Nov  5 2019 01:37:18.792 UTC: htsp_timer3 - 5600 msec
Nov  5 2019 01:37:18.792 UTC: [0/1/0] htsp_start_caller_id_rx:Mode BELLCORE. Alerting 0x1
Nov  5 2019 01:37:18.792 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_create: .
Nov  5 2019 01:37:18.792 UTC: //-1/313233343930/DSM:(0/1/0):-1/set_echo_canceller_data: echo_cancel: 0
Nov  5 2019 01:37:18.792 UTC: //-1/313233343930/DSM:(0/1/0):-1/set_echo_canceller_data: echo_flags: 38, echo_len: 1024
Nov  5 2019 01:37:18.792 UTC: htsp_start_caller_id_rx create dsp_stream_manager
Nov  5 2019 01:37:18.792 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_set_dsp_allocated: .
Nov  5 2019 01:37:18.792 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_set_feature_parameters: Fax Relay Version after update = 0
Nov  5 2019 01:37:18.792 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_implement_feature:
Nov  5 2019 01:37:18.792 UTC: dsp_stream_mgr_implement_feature: feature id = 7
Nov  5 2019 01:37:18.792 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsmp_dsmapi_reserve_resource_cb: .
Nov  5 2019 01:37:18.792 UTC: [0/1/0] htsp_dsm_create_success  returns 1
Nov  5 2019 01:37:18.796 UTC: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec

****

Nov  5 2019 01:37:20.744 UTC: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=5391 systime=415071618
Nov  5 2019 01:37:20.744 UTC: htsp_process_event: [0/1/0, FXOLS_RINGING, E_DSP_SIG_0100]
Nov  5 2019 01:37:20.744 UTC: fxols_ringing_not
Nov  5 2019 01:37:20.744 UTC: htsp_timer_stop
Nov  5 2019 01:37:20.744 UTC: htsp_timer - 10000 msec
Nov  5 2019 01:37:24.392 UTC: htsp_process_event: [0/1/0, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Nov  5 2019 01:37:24.392 UTC: htsp_timer_stop3
Nov  5 2019 01:37:30.744 UTC: htsp_process_event: [0/1/0, FXOLS_RINGING, E_HTSP_EVENT_TIMER]fxols_ringing_disc
Nov  5 2019 01:37:30.744 UTC: htsp_timer_stop3
Nov  5 2019 01:37:30.744 UTC: htsp_timer_stop
Nov  5 2019 01:37:30.744 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsp_stream_mgr_destroy: .
Nov  5 2019 01:37:30.744 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsm_delete_all_streams: .
Nov  5 2019 01:37:30.744 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsmapi_accept_modem_passthrough_session:  : dmgr: 3E383208, active sessions 0, max sessions: 16 rejected sessions till now: 0
Nov  5 2019 01:37:30.744 UTC: [0/1/0] htsp_stop_caller_id_rx. message length 0
Nov  5 2019 01:37:30.744 UTC: TGRM: reg_invoke_tgrm_call_update(0, 1, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Nov  5 2019 01:37:30.748 UTC: flex_dsprm_close_cleanup
Nov  5 2019 01:37:30.748 UTC: //-1/313233343930/DSM:(0/1/0):-1/dsmp_dsmapi_reserve_resource_cb: .
Nov  5 2019 01:37:30.748 UTC: [0/1/0] htsp_dsm_close_done,     *****