08-20-2013 02:26 PM - edited 03-16-2019 06:58 PM
Hello, does anyone have ideas? I have a CME 8.6. I can see in the debug that I am receiving the number but lower in the log it is blank yet the name is showing. This is the same thing we are seeing on the phones. Where is the calling number going? Thanks!
Aug 20 20:14:59.341: [0/3/0] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATUR
E_SM_CALLERID_RX
Aug 20 20:14:59.341: htsp_process_event: [0/3/0, FXOLS_RINGING, E_HTSP_CALLERID_
RX_DONE]
Aug 20 20:14:59.341: htsp_timer_stop
Aug 20 20:14:59.341: htsp_timer_stop3
Aug 20 20:14:59.341: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_destroy: .
Aug 20 20:14:59.341: //-1/313233343930/DSM:(0/3/0):-1/dsm_delete_all_streams: .
Aug 20 20:14:59.341: //-1/313233343930/DSM:(0/3/0):-1/dsmapi_accept_modem_passth
rough_session: : dmgr: 3222DDDC, active sessions 0, max sessions: 16 rejected s
essions till now: 0
Aug 20 20:14:59.341: [0/3/0] htsp_stop_caller_id_rx. message length 40htsp_setup
_ind
Aug 20 20:14:59.341: [0/3/0] get_fxo_caller_id:Caller ID received. Message type=
128 length=39 checksum=43
Aug 20 20:14:59.341: [0/3/0] Caller ID String 80 24 01 08 30 38 32 30 31 36 31 3
4 02 0A 35 31 32 34 37 36 30 34 38 39 07 0C 4D 4F 4E 45 59 20 42 4F 58 20 54 48
43
Aug 20 20:14:59.341: [0/3/0] get_fxo_caller_id calling num=5124761234 calling na
me=STORE NUMBER calling time=08/20 16:14
Aug 20 20:14:59.341: TGRM: reg_invoke_tgrm_accept_call(1, TGRM_CALL_VOICE, TGRM_
DIRECTION_IN, 0, 3, 0, 65535)
Aug 20 20:14:59.341: TGRM: Calling vtsp_tsp_call_setup_ind().
Aug 20 20:14:59.341: fxols_callerid_done: call being answered
Aug 20 20:14:59.345: flex_dsprm_close_cleanup
Aug 20 20:14:59.345: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_reserve_resour
ce_cb: .
Aug 20 20:14:59.345: [0/3/0] htsp_dsm_close_done
Aug 20 20:14:59.345: htsp_process_event: [0/3/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SE
TUP_ACK]
Aug 20 20:14:59.345: fxols_wait_setup_ack:
Aug 20 20:14:59.345: [0/3/0] set signal state = 0xC timestamp = 0
Aug 20 20:14:59.345: dsp_set_sig_state: [0/3/0] packet_len=12 channel_id=132 pac
ket_id=39 state=0xC timestamp=0x0fxols_check_auto_call
Aug 20 20:14:59.349: htsp_timer_stop3
Aug 20 20:14:59.349: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_HTSP_PROCEE
DING]fxols_offhook_proc
Aug 20 20:14:59.349: htsp_timer - 120000 msechtsp_setup_req
Aug 20 20:14:59.349: htsp_process_event: [50/0/64.1, EFXS_ONHOOK, E_HTSP_SETUP_R
EQ]efxs_onhook_setup
Aug 20 20:14:59.349: htsp_ephone_start_caller_id_tx calling num= calling name =STORE NUMBER
called num=6400 orig called num=
Aug 20 20:14:59.341: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_detection_cb:
.
Solved! Go to Solution.
08-21-2013 01:33 PM
Remove translate under voice-port.
Instead, you can use a voice translation-profile and rule to prefix 9 if you like.
08-20-2013 02:48 PM
Update IOS and check again.
Also check the complete log, if there is too long a gap betwwen rings the router may thing it's two separate calls form that the lost CLID.
08-20-2013 04:08 PM
Looks like your telco is sending the caller id..You can try and adjust the caller id ring setting on your voice port
You can refer ot this thread to get a better understanding of the problem and possible solutions
https://learningnetwork.cisco.com/thread/5363#20433
Please rate all useful posts
"opportunity is a haughty goddess who waste no time with those who are unprepared"
08-21-2013 10:28 AM
Thanks for the suggestion but that did not work. I also tried battery-reversal.
I am on c2900-universalk9-mz.SPA.151-4.M2.bin is there a problem with this firmware?
08-21-2013 10:56 AM
Can you please post the complete trace starting when something appears in debug, ending when the calls is answered.
08-21-2013 11:20 AM
Okay sure, also included pic of what they see on the phone:
Aug 21 18:09:58.744: htsp_process_event: [0/3/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fx
ols_onhook_ringing
Aug 21 18:09:58.744: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_PENDING, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Aug 21 18:09:58.744: htsp_timer - 125 msec
Aug 21 18:09:58.872: htsp_process_event: [0/3/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVE
NT_TIMER]fxols_wait_ring_min_timer
Aug 21 18:09:58.872: htsp_timer - 10000 msec
Aug 21 18:09:58.872: htsp_timer3 - 5600 msec
Aug 21 18:09:58.872: [0/3/0] htsp_start_caller_id_rx:BELLCORE
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_create: .
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/set_echo_canceller_data: e
cho_cancel: 0
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/set_echo_canceller_data: e
cho_flags: 38, echo_len: 1024
Aug 21 18:09:58.872: htsp_start_caller_id_rx create dsp_stream_manager
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_set_dsp_all
ocated: .
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_implement_f
eature:
Aug 21 18:09:58.872: dsp_stream_mgr_implement_feature: feature id = 7
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_reserve_resour
ce_cb: .
Aug 21 18:09:58.872: [0/3/0] htsp_dsm_create_success returns 1
Aug 21 18:09:58.872: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:00.848: htsp_process_event: [0/3/0, FXOLS_RINGING, E_DSP_SIG_0100]
Aug 21 18:10:00.848: fxols_ringing_not
Aug 21 18:10:00.848: htsp_timer_stop
Aug 21 18:10:00.848: htsp_timer - 10000 msec
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_detection_cb:
.
Aug 21 18:10:01.920: [0/3/0] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATUR
E_SM_CALLERID_RX
Aug 21 18:10:01.920: htsp_process_event: [0/3/0, FXOLS_RINGING, E_HTSP_CALLERID_
RX_DONE]
Aug 21 18:10:01.920: htsp_timer_stop
Aug 21 18:10:01.920: htsp_timer_stop3
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_destroy: .
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsm_delete_all_streams: .
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsmapi_accept_modem_passth
rough_session: : dmgr: 3222DDDC, active sessions 0, max sessions: 16 rejected s
essions till now: 0
Aug 21 18:10:01.920: [0/3/0] htsp_stop_caller_id_rx. message length 40htsp_setup
_ind
Aug 21 18:10:01.920: [0/3/0] get_fxo_caller_id:Caller ID received. Message type=
128 length=39 checksum=2C
Aug 21 18:10:01.920: [0/3/0] Caller ID String 80 24 01 08 30 38 32 31 31 34 30 3
9 02 0A 33 31 36 35 35 39 35 36 31 38 07 0C 57 49 52 45 4C 45 53 53 20 43 41 4C
2C
Aug 21 18:10:01.920: [0/3/0] get_fxo_caller_id calling num=3165591234 calling na
me=WIRELESS CAL calling time=08/21 14:09
Aug 21 18:10:01.920: TGRM: reg_invoke_tgrm_accept_call(1, TGRM_CALL_VOICE, TGRM_
DIRECTION_IN, 0, 3, 0, 65535)
Aug 21 18:10:01.920: TGRM: Calling vtsp_tsp_call_setup_ind().
Aug 21 18:10:01.920: fxols_callerid_done: call being answered
Aug 21 18:10:01.924: flex_dsprm_close_cleanup
Aug 21 18:10:01.924: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_reserve_resour
ce_cb: .
Aug 21 18:10:01.924: [0/3/0] htsp_dsm_close_done
Aug 21 18:10:01.924: htsp_process_event: [0/3/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SE
TUP_ACK]
Aug 21 18:10:01.924: fxols_wait_setup_ack:
Aug 21 18:10:01.924: [0/3/0] set signal state = 0xC timestamp = 0
Aug 21 18:10:01.924: dsp_set_sig_state: [0/3/0] packet_len=12 channel_id=132 pac
ket_id=39 state=0xC timestamp=0x0fxols_check_auto_call
Aug 21 18:10:01.924: htsp_timer_stop3
Aug 21 18:10:01.928: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_HTSP_PROCEE
DING]fxols_offhook_proc
Aug 21 18:10:01.928: htsp_timer - 120000 msechtsp_setup_req
Aug 21 18:10:01.928: htsp_process_event: [50/0/64.1, EFXS_ONHOOK, E_HTSP_SETUP_R
EQ]efxs_onhook_setup
Aug 21 18:10:01.928: htsp_ephone_start_caller_id_tx calling num= calling name =W
IRELESS CAL called num=6400 orig called num=
Aug 21 18:10:01.928: [50/0/64.1] set signal state = 0x0 timestamp = 0
Aug 21 18:10:01.928: edsp_set_sig_state: [50/0/64.1] packet_len=12 channel_id=50
5 packet_id=39 state=0x0 timestamp=0x0
Aug 21 18:10:01.928: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:01.928: edsp_soutput: [50/0/64.1] DN=64 chnl=505 StationInsideRing
Aug 21 18:10:01.932: efxs_onhook_setup: local target is available
htsp_alerthtsp_alert_notify
Aug 21 18:10:01.936: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_HTSP_ALERT]
fxols_offhook_alert
Aug 21 18:10:01.936: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:02.248: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_DSP_SIG_011
0]fxols_rvs_battery
Aug 21 18:10:02.248: htsp_timer_stop2
Aug 21 18:10:02.248: htsp_timer_stop2
Aug 21 18:10:04.664: htsp_process_event: [50/0/64.1, EFXS_WAIT_OFFHOOK, E_DSP_SI
G_1100]efxs_waitoff_offhook
Aug 21 18:10:04.664: [50/0/64.1] set signal state = 0x4 timestamp = 0
Aug 21 18:10:04.664: edsp_set_sig_state: [50/0/64.1] packet_len=12 channel_id=50
5 packet_id=39 state=0x4 timestamp=0x0
Aug 21 18:10:04.664: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.664: edsp_soutput: [50/0/64.1] DN=64 chnl=505 StationRingOff hts
p_dial
Aug 21 18:10:04.664: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_DSP_DIALING
_DONE]
Aug 21 18:10:04.668: htsp_call_bridged invoked
Aug 21 18:10:04.668: flex_modem_relay_supported:Modem Relay supported. flex_type
=1
Aug 21 18:10:04.668: htsp_call_bridged invoked
Aug 21 18:10:04.668: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:04.668: flex_dsprm_forking_mixing_support: htsp_connect: no_offhook
0 call_connected 0
Aug 21 18:10:04.672: htsp_process_event: [0/3/0, FXOLS_PROCEED_RVS_BT, E_HTSP_CO
NNECT]fxols_offhook_connect
Aug 21 18:10:04.672: htsp_timer_stop
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_OPEN_VOICE_
CHANNEL
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_ENC_CONFIG
2
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_SET_VOICE_P
LAYOUT_DELAY
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_ECHO_CANCEL
LER_CONTROL
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_VOICE_MODE
codec=1 vad=0 size=160 edsp_state=0
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_ECHO_CANCEL
LER_CONTROL
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_SET_GAINS
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_HTSP_VOICE_
CUT_THROUGH]efxs_connect_cutthru
Aug 21 18:10:04.672: [50/0/64.1] set signal state = 0x7 timestamp = 0
Aug 21 18:10:04.672: edsp_set_sig_state: [50/0/64.1] packet_len=12 channel_id=50
5 packet_id=39 state=0x7 timestamp=0x0
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 EFXS_OPEN_VOICE_PA
TH count=1
Aug 21 18:10:04.672: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:04.676: htsp_process_event: [0/3/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT
_THROUGH]fxols_connect_proc_voice
Aug 21 18:10:23.768: htsp_process_event: [0/3/0, FXOLS_CONNECT, E_DSP_SIG_1100]f
xols_offhook_disc
Aug 21 18:10:23.768: htsp_timer2 - 350 msec
Aug 21 18:10:23.820: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_DSP_SIG_010
0]efxs_offhook_onhook
Aug 21 18:10:23.820: htsp_timer - 10 msec
Aug 21 18:10:23.832: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_HTSP_EVENT_
TIMER]efxs_connect_wait_release_req
Aug 21 18:10:23.832: htsp_timer_stop
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GEN_PACKET_
CONTROL
Aug 21 18:10:23.832: htsp_timer_stop3
Aug 21 18:10:23.832: htsp_timer_stop3
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_TX_STAT
Aug 21 18:10:23.832: edsp_fake_tx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 6
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_RX_STAT
Aug 21 18:10:23.832: edsp_fake_rx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 6
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_LEVELS
Aug 21 18:10:23.832: edsp_fake_levels: [50/0/64.1] DN=64 chnl=505 by proc_id 6
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_TX_STAT
Aug 21 18:10:23.832: edsp_fake_tx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_RX_STAT
Aug 21 18:10:23.832: edsp_fake_rx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_VOICE_P
LAYOUT_DELAY
Aug 21 18:10:23.832: edsp_fake_voice_playout_delay: [50/0/64.1] DN=64 chnl=505 b
y proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_VOICE_P
LAYOUT_ERROR
Aug 21 18:10:23.832: edsp_fake_voice_playout_error: [50/0/64.1] DN=64 chnl=505 b
y proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_LEVELS
Aug 21 18:10:23.832: edsp_fake_levels: [50/0/64.1] DN=64 chnl=505 by proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 GET_ERROR_STAT
Aug 21 18:10:23.832: edsp_fake_error_stat: [50/0/64.1] DN=64 chnl=505 by proc_id
8htsp_release_req: cause 16, no_onhook 0
Aug 21 18:10:23.836: htsp_process_event: [50/0/64.1, EFXS_WAIT_RELEASE_REQ, E_HT
SP_RELEASE_REQ]efxs_waitrls_req_rlshtsp_report_onhook_sig
Aug 21 18:10:23.836: TGRM: reg_invoke_tgrm_call_update(50, 0, 64, 65535, 0, TGRM
_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_IDLE_MODE
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_CLOSE_VOICE
_CHANNEL
Aug 21 18:10:23.836: edsprm_close_cleanuphtsp_release_req: cause 16, no_onhook 0
Aug 21 18:10:23.844: htsp_process_event: [0/3/0, FXOLS_CONNECT, E_HTSP_RELEASE_R
EQ]fxols_offhook_release
Aug 21 18:10:23.844: htsp_timer_stop
Aug 21 18:10:23.844: htsp_timer_stop2
Aug 21 18:10:23.844: htsp_timer_stop3
Aug 21 18:10:23.844: [0/3/0] set signal state = 0x4 timestamp = 0
Aug 21 18:10:23.844: dsp_set_sig_state: [0/3/0] packet_len=12 channel_id=132 pac
ket_id=39 state=0x4 timestamp=0x0
Aug 21 18:10:23.844: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Aug 21 18:10:23.844: htsp_timer - 2000 msec
Aug 21 18:10:23.844: TGRM: reg_invoke_tgrm_channel_service_update(0, 3, 0, 65535
, 1)
Aug 21 18:10:23.844: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Aug 21 18:10:23.844: flex_dsprm_close_cleanup
Aug 21 18:10:24.588: htsp_process_event: [0/3/0, FXOLS_GUARD_OUT, E_DSP_SIG_0110
]
Aug 21 18:10:25.844: htsp_process_event: [0/3/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_T
IMER]fxols_guard_out_timeout
Aug 21 18:10:25.844: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Aug 21 18:10:25.844: dsp_req_sig_state: [0/3/0] packet_len=8 channel_id=132 pack
et_id=40
Aug 21 18:10:25.844: htsp_process_event: [0/3/0, FXOLS_ONHOOK, E_DSP_SIG_0100]
Aug 21 18:09:58.744: htsp_process_event: [0/3/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fx
ols_onhook_ringing
Aug 21 18:09:58.744: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_PENDING, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Aug 21 18:09:58.744: htsp_timer - 125 msec
Aug 21 18:09:58.872: htsp_process_event: [0/3/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVE
NT_TIMER]fxols_wait_ring_min_timer
Aug 21 18:09:58.872: htsp_timer - 10000 msec
Aug 21 18:09:58.872: htsp_timer3 - 5600 msec
Aug 21 18:09:58.872: [0/3/0] htsp_start_caller_id_rx:BELLCORE
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_create: .
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/set_echo_canceller_data: e
cho_cancel: 0
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/set_echo_canceller_data: e
cho_flags: 38, echo_len: 1024
Aug 21 18:09:58.872: htsp_start_caller_id_rx create dsp_stream_manager
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_set_dsp_all
ocated: .
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_implement_f
eature:
Aug 21 18:09:58.872: dsp_stream_mgr_implement_feature: feature id = 7
Aug 21 18:09:58.872: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_reserve_resour
ce_cb: .
Aug 21 18:09:58.872: [0/3/0] htsp_dsm_create_success returns 1
Aug 21 18:09:58.872: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:00.848: htsp_process_event: [0/3/0, FXOLS_RINGING, E_DSP_SIG_0100]
Aug 21 18:10:00.848: fxols_ringing_not
Aug 21 18:10:00.848: htsp_timer_stop
Aug 21 18:10:00.848: htsp_timer - 10000 msec
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_detection_cb:
.
Aug 21 18:10:01.920: [0/3/0] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATUR
E_SM_CALLERID_RX
Aug 21 18:10:01.920: htsp_process_event: [0/3/0, FXOLS_RINGING, E_HTSP_CALLERID_
RX_DONE]
Aug 21 18:10:01.920: htsp_timer_stop
Aug 21 18:10:01.920: htsp_timer_stop3
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsp_stream_mgr_destroy: .
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsm_delete_all_streams: .
Aug 21 18:10:01.920: //-1/313233343930/DSM:(0/3/0):-1/dsmapi_accept_modem_passth
rough_session: : dmgr: 3222DDDC, active sessions 0, max sessions: 16 rejected s
essions till now: 0
Aug 21 18:10:01.920: [0/3/0] htsp_stop_caller_id_rx. message length 40htsp_setup
_ind
Aug 21 18:10:01.920: [0/3/0] get_fxo_caller_id:Caller ID received. Message type=
128 length=39 checksum=2C
Aug 21 18:10:01.920: [0/3/0] Caller ID String 80 24 01 08 30 38 32 31 31 34 30 3
9 02 0A 33 31 36 35 35 39 35 36 31 38 07 0C 57 49 52 45 4C 45 53 53 20 43 41 4C
2C
Aug 21 18:10:01.920: [0/3/0] get_fxo_caller_id calling num=3165591234 calling na
me=WIRELESS CAL calling time=08/21 14:09
Aug 21 18:10:01.920: TGRM: reg_invoke_tgrm_accept_call(1, TGRM_CALL_VOICE, TGRM_
DIRECTION_IN, 0, 3, 0, 65535)
Aug 21 18:10:01.920: TGRM: Calling vtsp_tsp_call_setup_ind().
Aug 21 18:10:01.920: fxols_callerid_done: call being answered
Aug 21 18:10:01.924: flex_dsprm_close_cleanup
Aug 21 18:10:01.924: //-1/313233343930/DSM:(0/3/0):-1/dsmp_dsmapi_reserve_resour
ce_cb: .
Aug 21 18:10:01.924: [0/3/0] htsp_dsm_close_done
Aug 21 18:10:01.924: htsp_process_event: [0/3/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SE
TUP_ACK]
Aug 21 18:10:01.924: fxols_wait_setup_ack:
Aug 21 18:10:01.924: [0/3/0] set signal state = 0xC timestamp = 0
Aug 21 18:10:01.924: dsp_set_sig_state: [0/3/0] packet_len=12 channel_id=132 pac
ket_id=39 state=0xC timestamp=0x0fxols_check_auto_call
Aug 21 18:10:01.924: htsp_timer_stop3
Aug 21 18:10:01.928: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_HTSP_PROCEE
DING]fxols_offhook_proc
Aug 21 18:10:01.928: htsp_timer - 120000 msechtsp_setup_req
Aug 21 18:10:01.928: htsp_process_event: [50/0/64.1, EFXS_ONHOOK, E_HTSP_SETUP_R
EQ]efxs_onhook_setup
Aug 21 18:10:01.928: htsp_ephone_start_caller_id_tx calling num= calling name =W
IRELESS CAL called num=6400 orig called num=
Aug 21 18:10:01.928: [50/0/64.1] set signal state = 0x0 timestamp = 0
Aug 21 18:10:01.928: edsp_set_sig_state: [50/0/64.1] packet_len=12 channel_id=50
5 packet_id=39 state=0x0 timestamp=0x0
Aug 21 18:10:01.928: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:01.928: edsp_soutput: [50/0/64.1] DN=64 chnl=505 StationInsideRing
Aug 21 18:10:01.932: efxs_onhook_setup: local target is available
htsp_alerthtsp_alert_notify
Aug 21 18:10:01.936: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_HTSP_ALERT]
fxols_offhook_alert
Aug 21 18:10:01.936: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:02.248: htsp_process_event: [0/3/0, FXOLS_PROCEEDING, E_DSP_SIG_011
0]fxols_rvs_battery
Aug 21 18:10:02.248: htsp_timer_stop2
Aug 21 18:10:02.248: htsp_timer_stop2
Aug 21 18:10:04.664: htsp_process_event: [50/0/64.1, EFXS_WAIT_OFFHOOK, E_DSP_SI
G_1100]efxs_waitoff_offhook
Aug 21 18:10:04.664: [50/0/64.1] set signal state = 0x4 timestamp = 0
Aug 21 18:10:04.664: edsp_set_sig_state: [50/0/64.1] packet_len=12 channel_id=50
5 packet_id=39 state=0x4 timestamp=0x0
Aug 21 18:10:04.664: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.664: edsp_soutput: [50/0/64.1] DN=64 chnl=505 StationRingOff hts
p_dial
Aug 21 18:10:04.664: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_DSP_DIALING
_DONE]
Aug 21 18:10:04.668: htsp_call_bridged invoked
Aug 21 18:10:04.668: flex_modem_relay_supported:Modem Relay supported. flex_type
=1
Aug 21 18:10:04.668: htsp_call_bridged invoked
Aug 21 18:10:04.668: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:04.668: flex_dsprm_forking_mixing_support: htsp_connect: no_offhook
0 call_connected 0
Aug 21 18:10:04.672: htsp_process_event: [0/3/0, FXOLS_PROCEED_RVS_BT, E_HTSP_CO
NNECT]fxols_offhook_connect
Aug 21 18:10:04.672: htsp_timer_stop
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_OPEN_VOICE_
CHANNEL
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_ENC_CONFIG
2
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_SET_VOICE_P
LAYOUT_DELAY
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_ECHO_CANCEL
LER_CONTROL
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_VOICE_MODE
codec=1 vad=0 size=160 edsp_state=0
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_ECHO_CANCEL
LER_CONTROL
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_SET_GAINS
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_HTSP_VOICE_
CUT_THROUGH]efxs_connect_cutthru
Aug 21 18:10:04.672: [50/0/64.1] set signal state = 0x7 timestamp = 0
Aug 21 18:10:04.672: edsp_set_sig_state: [50/0/64.1] packet_len=12 channel_id=50
5 packet_id=39 state=0x7 timestamp=0x0
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:04.672: edsp_soutput: [50/0/64.1] DN=64 chnl=505 EFXS_OPEN_VOICE_PA
TH count=1
Aug 21 18:10:04.672: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Co
dec
Aug 21 18:10:04.676: htsp_process_event: [0/3/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT
_THROUGH]fxols_connect_proc_voice
Aug 21 18:10:23.768: htsp_process_event: [0/3/0, FXOLS_CONNECT, E_DSP_SIG_1100]f
xols_offhook_disc
Aug 21 18:10:23.768: htsp_timer2 - 350 msec
Aug 21 18:10:23.820: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_DSP_SIG_010
0]efxs_offhook_onhook
Aug 21 18:10:23.820: htsp_timer - 10 msec
Aug 21 18:10:23.832: htsp_process_event: [50/0/64.1, EFXS_CONNECT, E_HTSP_EVENT_
TIMER]efxs_connect_wait_release_req
Aug 21 18:10:23.832: htsp_timer_stop
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GEN_PACKET_
CONTROL
Aug 21 18:10:23.832: htsp_timer_stop3
Aug 21 18:10:23.832: htsp_timer_stop3
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_TX_STAT
Aug 21 18:10:23.832: edsp_fake_tx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 6
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_RX_STAT
Aug 21 18:10:23.832: edsp_fake_rx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 6
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_LEVELS
Aug 21 18:10:23.832: edsp_fake_levels: [50/0/64.1] DN=64 chnl=505 by proc_id 6
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_TX_STAT
Aug 21 18:10:23.832: edsp_fake_tx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_RX_STAT
Aug 21 18:10:23.832: edsp_fake_rx_stat: [50/0/64.1] DN=64 chnl=505 by proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_VOICE_P
LAYOUT_DELAY
Aug 21 18:10:23.832: edsp_fake_voice_playout_delay: [50/0/64.1] DN=64 chnl=505 b
y proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_VOICE_P
LAYOUT_ERROR
Aug 21 18:10:23.832: edsp_fake_voice_playout_error: [50/0/64.1] DN=64 chnl=505 b
y proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_GET_LEVELS
Aug 21 18:10:23.832: edsp_fake_levels: [50/0/64.1] DN=64 chnl=505 by proc_id 8
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.832: edsp_soutput: [50/0/64.1] DN=64 chnl=505 GET_ERROR_STAT
Aug 21 18:10:23.832: edsp_fake_error_stat: [50/0/64.1] DN=64 chnl=505 by proc_id
8htsp_release_req: cause 16, no_onhook 0
Aug 21 18:10:23.836: htsp_process_event: [50/0/64.1, EFXS_WAIT_RELEASE_REQ, E_HT
SP_RELEASE_REQ]efxs_waitrls_req_rlshtsp_report_onhook_sig
Aug 21 18:10:23.836: TGRM: reg_invoke_tgrm_call_update(50, 0, 64, 65535, 0, TGRM
_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_IDLE_MODE
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505
Aug 21 18:10:23.836: edsp_soutput: [50/0/64.1] DN=64 chnl=505 MSG_RX_CLOSE_VOICE
_CHANNEL
Aug 21 18:10:23.836: edsprm_close_cleanuphtsp_release_req: cause 16, no_onhook 0
Aug 21 18:10:23.844: htsp_process_event: [0/3/0, FXOLS_CONNECT, E_HTSP_RELEASE_R
EQ]fxols_offhook_release
Aug 21 18:10:23.844: htsp_timer_stop
Aug 21 18:10:23.844: htsp_timer_stop2
Aug 21 18:10:23.844: htsp_timer_stop3
Aug 21 18:10:23.844: [0/3/0] set signal state = 0x4 timestamp = 0
Aug 21 18:10:23.844: dsp_set_sig_state: [0/3/0] packet_len=12 channel_id=132 pac
ket_id=39 state=0x4 timestamp=0x0
Aug 21 18:10:23.844: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_IN)
Aug 21 18:10:23.844: htsp_timer - 2000 msec
Aug 21 18:10:23.844: TGRM: reg_invoke_tgrm_channel_service_update(0, 3, 0, 65535
, 1)
Aug 21 18:10:23.844: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Aug 21 18:10:23.844: flex_dsprm_close_cleanup
Aug 21 18:10:24.588: htsp_process_event: [0/3/0, FXOLS_GUARD_OUT, E_DSP_SIG_0110
]
Aug 21 18:10:25.844: htsp_process_event: [0/3/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_T
IMER]fxols_guard_out_timeout
Aug 21 18:10:25.844: TGRM: reg_invoke_tgrm_call_update(0, 3, 0, 65535, 1, TGRM_C
ALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
Aug 21 18:10:25.844: dsp_req_sig_state: [0/3/0] packet_len=8 channel_id=132 pack
et_id=40
Aug 21 18:10:25.844: htsp_process_event: [0/3/0, FXOLS_ONHOOK, E_DSP_SIG_0100]
08-21-2013 11:38 AM
Please post complete config.
08-21-2013 12:05 PM
Removed config
08-21-2013 01:33 PM
Remove translate under voice-port.
Instead, you can use a voice translation-profile and rule to prefix 9 if you like.
08-21-2013 02:39 PM
Thanks Paolo that was it! Not sure why that was set like that but it makes sense now.
08-21-2013 05:01 PM
Thank you for the nice rating and good luck!
11-17-2021 08:24 PM
Hi Paolo, facing the same challenge, could you help?
11-18-2021 03:07 AM
@meenakshi.a Recommend you to open your own post instead of posting on an answered post that’s is a number of years old.
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide