i have two ISR routers with VIC2-4FXO and running 15.1(4)M5
First routers FXO port gives fast busy when i send out call to PBX while the 2nd router's FXO port works fine for outbound call to PBX
Both routers FXO port are having same configuration. I wanted to eliminate any problems related to Router DSP or FXO port before i transfer the case to PBX team
flow below
ISR --FXO-->DID trunk --> PBX
Failing fxo port -- debug vpm all below
May 19 08:31:25: htsp_timer_stop3 htsp_setup_req
May 19 08:31:25: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
May 19 08:31:25: [0/3/2] set signal state = 0xC timestamp = 0
May 19 08:31:25: dsp_set_sig_state: [0/3/2] packet_len=12 channel_id=134 packet_id=39 state=0xC timestamp=0x0
May 19 08:31:25: TGRM: reg_invoke_tgrm_call_update(0, 3, 2, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:31:25: htsp_timer - 1300 msec
May 19 08:31:25: htsp_process_event: [0/3/2, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_0110]fxols_disc_clear
May 19 08:31:25: htsp_timer_stop2
May 19 08:31:25: htsp_timer - 1300 msec
May 19 08:31:26: htsp_process_event: [0/3/2, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_0100]fxols_disc_clear
May 19 08:31:26: htsp_timer_stop2
May 19 08:31:26: htsp_timer - 1300 msec
May 19 08:31:27: htsp_process_event: [0/3/2, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
May 19 08:31:27: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: htsp_process_event: [0/3/2, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_alert
May 19 08:31:28: htsp_timer - 350 msec
May 19 08:31:28: htsp_call_bridged invoked
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: flex_dsprm_forking_mixing_support:
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: htsp_process_event: [0/3/2, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
May 19 08:31:28: htsp_timer_stop
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: flex_dsprm_forking_mixing_support:
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:31:28: htsp_process_event: [0/3/2, FXOLS_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxols_proc_voice
After above debug messgae I hear fast busy, then i disconnect the call
May 19 08:31:54: htsp_timer_stop3 htsp_release_req: cause 16, no_onhook 0
May 19 08:31:54: htsp_process_event: [0/3/2, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
May 19 08:31:54: htsp_timer_stop
May 19 08:31:54: htsp_timer_stop2
May 19 08:31:54: htsp_timer_stop3
May 19 08:31:54: [0/3/2] set signal state = 0x4 timestamp = 0
May 19 08:31:54: dsp_set_sig_state: [0/3/2] packet_len=12 channel_id=134 packet_id=39 state=0x4 timestamp=0x0
May 19 08:31:54: TGRM: reg_invoke_tgrm_call_update(0, 3, 2, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:31:54: htsp_timer - 2000 msec
May 19 08:31:54: TGRM: reg_invoke_tgrm_channel_service_update(0, 3, 2, 65535, 1)
May 19 08:31:54: TGRM: reg_invoke_tgrm_call_update(0, 3, 2, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:31:54: flex_dsprm_close_cleanup
May 19 08:31:56: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
May 19 08:31:56: TGRM: reg_invoke_tgrm_call_update(0, 3, 2, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:31:56: dsp_req_sig_state: [0/3/2] packet_len=8 channel_id=134 packet_id=40
May 19 08:31:56: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Working FXO Port - debug vpm all
May 19 08:52:11.022: htsp_timer_stop3 htsp_setup_req
May 19 08:52:11.026: htsp_process_event: [0/3/3, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
May 19 08:52:11.026: [0/3/3] set signal state = 0xC timestamp = 0
May 19 08:52:11.026: dsp_set_sig_state: [0/3/3] packet_len=12 channel_id=135 packet_id=39 state=0xC timestamp=0x0
May 19 08:52:11.026: TGRM: reg_invoke_tgrm_call_update(0, 3, 3, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:52:11.026: htsp_timer - 1300 msec
May 19 08:52:11.278: htsp_process_event: [0/3/3, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_1100]fxols_power_denial_detected
May 19 08:52:11.278: htsp_timer2 - 1000 msec
rtr2#
May 19 08:52:11.278: htsp_timer_stop
May 19 08:52:12.278: htsp_process_event: [0/3/3, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER2]fxols_power_den_disc
May 19 08:52:12.278: htsp_timer_stop
May 19 08:52:12.278: htsp_timer_stop2
May 19 08:52:12.278: [0/3/3] set signal state = 0x4 timestamp = 0
May 19 08:52:12.278: dsp_set_sig_state: [0/3/3] packet_len=12 channel_id=135 packet_id=39 state=0x4 timestamp=0x0
May 19 08:52:12.278: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec htsp_release_req: cause 34, no_onhook 0
May 19 08:52:12.278: htsp_process_event: [0/3/3, FXOLS_ONHOOK, E_HTSP_RELEASE_REQ]fxols_onhook_release
May 19 08:52:12.278: TGRM: reg_invoke_tgrm_call_update(0, 3, 3, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:52:12.282: flex_dsprm_close_cleanup
May 19 08:52:12.282: htsp_timer_stop3 htsp_setup_req
May 19 08:52:12.286: htsp_process_event: [0/3/0, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
May 19 08:52:12.286: [0/3/0] set signal state = 0xC timestamp = 0
May 19 08:52:12.286: dsp_set_sig_state: [0/3/0] packet_len=12 channel_id=132 packet_id=39 state=0xC timestamp=0x0
May 19 08:52:12.286: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:52:12.286: htsp_timer - 1300 msec
rtr2#
May 19 08:52:12.618: htsp_process_event: [0/3/0, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_0110]fxols_disc_clear
May 19 08:52:12.618: htsp_timer_stop2
May 19 08:52:12.618: htsp_timer - 1300 msec
May 19 08:52:12.822: htsp_process_event: [0/3/0, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_0100]fxols_disc_clear
May 19 08:52:12.822: htsp_timer_stop2
May 19 08:52:12.822: htsp_timer - 1300 msec
rtr2#
May 19 08:52:14.122: htsp_process_event: [0/3/0, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
May 19 08:52:14.122: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:14.974: htsp_process_event: [0/3/0, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_alert
May 19 08:52:14.974: htsp_timer - 350 msec
May 19 08:52:14.974: htsp_call_bridged invoked
May 19 08:52:14.978: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:14.978: flex_dsprm_forking_mixing_support:
May 19 08:52:14.982: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:14.982: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:14.982: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:14.982: htsp_process_event: [0/3/0, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
May 19 08:52:14.982: htsp_timer_stop
May 19 08:52:15.138: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:15.142: flex_dsprm_forking_mixing_support:
May 19 08:52:15.142: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:15.142: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
rtr2#
May 19 08:52:15.142: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
May 19 08:52:15.146: htsp_process_event: [0/3/0, FXOLS_OFFHOOK, E_HTSP_VOICE_CUT_THROUGH]fxols_proc_voice
May 19 08:52:17.662: htsp_process_event: [0/3/0, FXOLS_OFFHOOK, E_DSP_SIG_0110]
May 19 08:52:17.662: htsp_timer_stop2 fxols_offhook_rvs_battery
By this above message i get the greeting played from PBX
Then I disconnect
May 19 08:53:01.437: htsp_timer_stop3 htsp_release_req: cause 16, no_onhook 0
May 19 08:53:01.461: htsp_process_event: [0/3/0, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
May 19 08:53:01.465: htsp_timer_stop
May 19 08:53:01.465: htsp_timer_stop2
May 19 08:53:01.465: htsp_timer_stop3
May 19 08:53:01.465: [0/3/0] set signal state = 0x4 timestamp = 0
May 19 08:53:01.465: dsp_set_sig_state: [0/3/0] packet_len=12 channel_id=132 packet_id=39 state=0x4 timestamp=0x0
May 19 08:53:01.465: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
May 19 08:53:01.465: htsp_timer - 2000 msec
