cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
505
Views
0
Helpful
4
Replies

caller-id fault

limak
Level 1
Level 1

Hello,

 

We have two Cisco 2900 routers, both of them connected to Cucm. i checked from PSTN caller id is enable receiving on display & lesson String on Test hand set. Other lines on router doesn't have any caller-id problem. This voice port has same configuration with other ports.

 

 

voice port config;

 

voice-port 0/3/2
supervisory disconnect dualtone mid-call
cptone TR
connection plar opx 91123
caller-id enable
!

 

logs:

Jan 8 07:03:06.599: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:06.599: fxols_ringing_not
Jan 8 07:03:06.599: htsp_timer_stop
Jan 8 07:03:06.599: htsp_timer - 10000 msechtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:10.503: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 07:03:11.203: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 07:03:11.203: htsp_timer_stop3
Jan 8 07:03:12.567: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:12.567: fxols_ringing_not
Jan 8 07:03:12.567: htsp_timer_stop
Jan 8 07:03:12.567: htsp_timer - 10000 msec
Jan 8 07:03:16.491: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 07:03:18.591: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:18.591: fxols_ringing_not
Jan 8 07:03:18.591: htsp_timer_stop
Jan 8 07:03:18.591: htsp_timer_stop3
Jan 8 07:03:18.595: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 07:03:18.595: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 07:03:18.595: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 07:03 orig called=
Jan 8 07:03:18.595: [0/3/2] htsp_dsm_close_done
Jan 8 07:03:18.595: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 07:03:18.595: fxols_wait_setup_ack:
Jan 8 07:03:18.595: htsp_timer - 6000 msec
Jan 8 07:03:18.599: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 07:03:18.659: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:18.951: htsp_process_event: [0/1/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:03:19.519: htsp_digit_ready(0/2/0): digit = 7
Jan 8 07:03:22.487: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 07:03:22.487: htsp_timer_stop
Jan 8 07:03:24.591: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 07:03:24.591: htsp_timer_stop2
Jan 8 07:03:24.591: htsp_timer - 6000 msec
Jan 8 07:03:27.995: htsp_call_bridged invokedhtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:27.995: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
Jan 8 07:03:27.995: [0/3/2] set signal state = 0xC timestamp = 0
Jan 8 07:03:27.995: htsp_timer_stop
Jan 8 07:03:27.995: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:03:28.271: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_DSP_SIG_0110]fxols_rvs_battery

 

---

router version:

c2900-universalk9-mz.SPA.152-1.T1.bin

 

4 Replies 4

Georgios Fotiadis
VIP Alumni
VIP Alumni

Your logs suggest that you do not receive any callerID:

Jan 8 07:03:18.595: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 07:03 orig called=

You can temporarily swap this line with one of those working and compare results.

Also, you may find this document helpful: Caller ID Name Delivery Issues on Cisco IOS Gateways

Georgios
Please rate if you find this helpful.

When i swap lines still did not get caller id. But when i swap id active line on other port i got caller-id without a problem. i can share logs if you need

Can you elaborate on what you did? The important test is to plug a line for which callerID works (when plugged in to another port) in 0/3/2.

Georgios
Please rate if you find this helpful.

Hello Georgios,

 

yes i swapped lines. 0/3/2 is faulty line, 0/3/1 is works normal when i swapped 0/3/2 to 0/3/1 caller-id fault continues but when i changed otherwise 0/3/2 works normal here are the logs;

 

int this log i swapped faulty line between 0/3/2 and 0/3/1

 

Log Buffer (1000000 bytes):

Dec 25 14:07:25.037: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Dec 25 14:07:25.037: htsp_timer - 125 msec
Dec 25 14:07:25.165: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Dec 25 14:07:25.165: htsp_timer - 10000 msec
Dec 25 14:07:25.165: htsp_timer3 - 5600 msec
Dec 25 14:07:25.165: [0/3/2] htsp_start_caller_id_rx:ETSI
Dec 25 14:07:25.165: htsp_start_caller_id_rx create dsp_stream_manager
Dec 25 14:07:25.165: [0/3/2] htsp_dsm_create_success returns 1
Dec 25 14:07:26.157: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Dec 25 14:07:26.157: fxols_ringing_not
Dec 25 14:07:26.157: htsp_timer_stop
Dec 25 14:07:26.157: htsp_timer - 10000 msec
Dec 25 14:07:30.069: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Dec 25 14:07:30.765: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Dec 25 14:07:30.765: htsp_timer_stop3
Dec 25 14:07:32.137: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Dec 25 14:07:32.137: fxols_ringing_not
Dec 25 14:07:32.137: htsp_timer_stop
Dec 25 14:07:32.137: htsp_timer_stop3
Dec 25 14:07:32.137: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Dec 25 14:07:32.137: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Dec 25 14:07:32.137: [0/3/2] get_local_station_id calling num= calling name= calling time=12/25 14:07 orig called=
Dec 25 14:07:32.137: [0/3/2] htsp_dsm_close_done
Dec 25 14:07:32.137: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Dec 25 14:07:32.137: fxols_wait_setup_ack:
Dec 25 14:07:32.137: htsp_timer - 6000 msec
Dec 25 14:07:32.141: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Dec 25 14:07:32.213: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Dec 25 14:07:34.457: htsp_call_bridged invokedhtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Dec 25 14:07:34.461: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
Dec 25 14:07:34.461: [0/3/2] set signal state = 0xC timestamp = 0
Dec 25 14:07:34.461: htsp_timer_stop
Dec 25 14:07:34.461: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Dec 25 14:07:42.589: htsp_timer_stop3
Dec 25 14:07:42.605: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
Dec 25 14:07:42.605: htsp_timer_stop
Dec 25 14:07:42.605: htsp_timer_stop2
Dec 25 14:07:42.605: htsp_timer_stop3
Dec 25 14:07:42.605: [0/3/2] set signal state = 0x4 timestamp = 0
Dec 25 14:07:42.605: htsp_timer - 2000 msec
Dec 25 14:07:44.605: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Dec 25 14:07:44.609: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Dec 25 14:07:45.325: htsp_process_event: [0/0/2, FXOLS_RINGING, E_DSP_SIG_0100]
Dec 25 14:07:45.325: fxols_ringing_not
Dec 25 14:07:45.325: htsp_timer_stop
Dec 25 14:07:45.325: htsp_timer - 10000 msec
Jan 8 07:03:05.475: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 07:03:05.475: htsp_timer - 125 msec
Jan 8 07:03:05.603: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 07:03:05.603: htsp_timer - 10000 msec
Jan 8 07:03:05.603: htsp_timer3 - 5600 msec
Jan 8 07:03:05.603: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 07:03:05.603: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 07:03:05.603: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 07:03:06.599: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:06.599: fxols_ringing_not
Jan 8 07:03:06.599: htsp_timer_stop
Jan 8 07:03:06.599: htsp_timer - 10000 msechtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:10.503: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 07:03:11.203: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 07:03:11.203: htsp_timer_stop3
Jan 8 07:03:12.567: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:12.567: fxols_ringing_not
Jan 8 07:03:12.567: htsp_timer_stop
Jan 8 07:03:12.567: htsp_timer - 10000 msec
Jan 8 07:03:16.491: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 07:03:18.591: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:18.591: fxols_ringing_not
Jan 8 07:03:18.591: htsp_timer_stop
Jan 8 07:03:18.591: htsp_timer_stop3
Jan 8 07:03:18.595: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 07:03:18.595: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 07:03:18.595: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 07:03 orig called=
Jan 8 07:03:18.595: [0/3/2] htsp_dsm_close_done
Jan 8 07:03:18.595: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 07:03:18.595: fxols_wait_setup_ack:
Jan 8 07:03:18.595: htsp_timer - 6000 msec
Jan 8 07:03:18.599: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 07:03:18.659: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:19.519: htsp_digit_ready(0/2/0): digit = 7
Jan 8 07:03:22.487: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 07:03:22.487: htsp_timer_stop
Jan 8 07:03:24.591: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 07:03:24.591: htsp_timer_stop2
Jan 8 07:03:24.591: htsp_timer - 6000 msec
Jan 8 07:03:27.995: htsp_call_bridged invokedhtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:27.995: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
Jan 8 07:03:27.995: [0/3/2] set signal state = 0xC timestamp = 0
Jan 8 07:03:27.995: htsp_timer_stop
Jan 8 07:03:27.995: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:03:28.271: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_DSP_SIG_0110]fxols_rvs_battery
Jan 8 07:03:28.271: htsp_timer_stop2 htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:31.295: htsp_process_event: [0/1/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:03:31.303: htsp_process_event: [0/1/2, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voicehtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:39.219: htsp_digit_ready(0/2/0): digit = *htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:40.447: htsp_process_event: [0/1/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:03:52.815: htsp_timer_stop3
Jan 8 07:03:52.839: htsp_process_event: [0/1/2, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 07:03:52.839: htsp_timer_stop
Jan 8 07:03:52.839: htsp_timer_stop2
Jan 8 07:03:52.839: htsp_timer_stop3
Jan 8 07:03:52.839: [0/1/2] set signal state = 0x4 timestamp = 0
Jan 8 07:03:52.839: htsp_timer - 2000 msec
Jan 8 07:03:54.839: htsp_process_event: [0/1/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 07:03:54.839: htsp_process_event: [0/1/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 07:04:07.147: htsp_timer_stop3
Jan 8 07:04:07.167: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 07:04:07.167: htsp_timer_stop
Jan 8 07:04:07.167: htsp_timer_stop2
Jan 8 07:04:07.167: htsp_timer_stop3
Jan 8 07:04:07.167: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 07:04:07.167: htsp_timer - 2000 msec
Jan 8 07:04:07.439: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_DSP_SIG_0110]htsp_call_service_msghtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:04:09.167: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 07:04:09.171: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:04:12.579: htsp_process_event: [0/2/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:04:20.055: htsp_process_event: [0/2/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voicehtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:04:26.335: htsp_timer_stop3
Jan 8 07:04:26.359: htsp_timer_stop
Jan 8 07:04:26.359: htsp_timer_stop2
Jan 8 07:04:26.359: htsp_timer_stop3
Jan 8 07:04:26.359: [0/1/3] set signal state = 0x4 timestamp = 0
Jan 8 07:04:26.359: htsp_timer - 2000 msec
Jan 8 16:51:50.125: htsp_timer - 350 msec
Jan 8 16:51:50.129: htsp_call_bridged invoked
Jan 8 16:51:50.225: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:51:50.225: htsp_timer - 125 msec
Jan 8 16:51:50.353: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:51:50.353: htsp_timer - 10000 msec
Jan 8 16:51:50.353: htsp_timer3 - 5600 msec
Jan 8 16:51:50.353: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 16:51:50.353: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:51:50.353: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 16:51:51.317: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:51:51.317: fxols_ringing_not
Jan 8 16:51:51.317: htsp_timer_stop
Jan 8 16:51:51.317: htsp_timer - 10000 msec
Jan 8 16:51:55.277: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 16:51:55.953: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 16:51:55.953: htsp_timer_stop3
Jan 8 16:51:56.113: htsp_timer_stop3
Jan 8 16:51:56.825: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:51:56.825: fxols_ringing_not
Jan 8 16:51:56.825: htsp_timer_stop
Jan 8 16:51:56.825: htsp_timer_stop3
Jan 8 16:51:56.825: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 16:51:56.825: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 16:51:56.825: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 16:51 orig called=
Jan 8 16:51:56.825: [0/3/2] htsp_dsm_close_done
Jan 8 16:51:56.825: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:51:56.825: fxols_wait_setup_ack:
Jan 8 16:51:56.825: htsp_timer - 6000 msec
Jan 8 16:51:56.829: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:51:56.901: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:52:02.825: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:52:02.825: htsp_timer_stop
Jan 8 16:52:02.825: htsp_timer_stop2
Jan 8 16:52:02.825: htsp_timer_stop3
Jan 8 16:52:02.825: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:02.825: htsp_timer_stop
Jan 8 16:52:02.825: htsp_timer_stop2
Jan 8 16:52:02.825: htsp_timer_stop3
Jan 8 16:52:02.825: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:52:02.825: htsp_timer - 2000 msec
Jan 8 16:52:04.189: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:52:04.189: htsp_timer - 125 msec
Jan 8 16:52:04.317: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:52:04.317: htsp_timer - 10000 msec
Jan 8 16:52:04.317: htsp_timer3 - 5600 msec
Jan 8 16:52:04.317: [0/3/1] htsp_start_caller_id_rx:ETSI
Jan 8 16:52:04.317: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:52:04.317: [0/3/1] htsp_dsm_create_success returns 1
Jan 8 16:52:04.825: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:52:04.829: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:05.281: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:52:05.281: fxols_ringing_not
Jan 8 16:52:05.281: htsp_timer_stop
Jan 8 16:52:05.281: htsp_timer - 10000 msec
Jan 8 16:52:06.145: [0/3/1] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX
Jan 8 16:52:06.145: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
Jan 8 16:52:06.145: htsp_timer_stop
Jan 8 16:52:06.145: htsp_timer_stop3
Jan 8 16:52:06.145: [0/3/1] htsp_stop_caller_id_rx. message length 22htsp_setup_ind
Jan 8 16:52:06.145: [0/3/1] get_fxo_caller_id:Caller ID received. Message type=128 length=22 checksum=59
Jan 8 16:52:06.145: [0/3/1] Caller ID String 80 13 01 08 30 31 30 38 31 39 35 32 02 07 34 34 37 30 33 31 35 59
Jan 8 16:52:06.145: [0/3/1] get_fxo_caller_id calling num=4470315 calling name= calling time=01/08 19:52
Jan 8 16:52:06.149: fxols_callerid_done: call being answered
Jan 8 16:52:06.149: [0/3/1] htsp_dsm_close_done
Jan 8 16:52:06.149: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:52:06.149: fxols_wait_setup_ack:
Jan 8 16:52:06.149: htsp_timer - 6000 msec
Jan 8 16:52:06.153: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:52:06.217: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:52:09.225: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 16:52:09.225: htsp_timer_stop
Jan 8 16:52:11.025: htsp_timer_stop3
Jan 8 16:52:11.041: htsp_process_event: [0/2/3, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:11.041: htsp_timer_stop
Jan 8 16:52:11.041: htsp_timer_stop2
Jan 8 16:52:11.041: htsp_timer_stop3
Jan 8 16:52:11.041: [0/2/3] set signal state = 0x4 timestamp = 0
Jan 8 16:52:11.041: htsp_timer - 2000 msec
Jan 8 16:52:11.289: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 16:52:11.289: htsp_timer_stop2
Jan 8 16:52:11.289: htsp_timer - 6000 msec
Jan 8 16:52:11.313: htsp_process_event: [0/2/3, FXOLS_GUARD_OUT, E_DSP_SIG_0110]
Jan 8 16:52:13.041: htsp_process_event: [0/2/3, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:52:13.041: htsp_process_event: [0/2/3, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:17.289: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:52:17.289: htsp_timer_stop
Jan 8 16:52:17.289: htsp_timer_stop2
Jan 8 16:52:17.289: htsp_timer_stop3
Jan 8 16:52:17.289: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:17.289: htsp_timer_stop
Jan 8 16:52:17.289: htsp_timer_stop2
Jan 8 16:52:17.289: htsp_timer_stop3
Jan 8 16:52:17.289: [0/3/1] set signal state = 0x4 timestamp = 0
Jan 8 16:52:17.289: htsp_timer - 2000 msec
Jan 8 16:52:19.305: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:52:19.305: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:27.093: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0110]
Jan 8 16:52:27.093: fxols_line_reversal_clid_wait. On_hook line reversal detected possibily due to crossed cable
Jan 8 16:52:42.417: htsp_timer_stop3 htsp_setup_req
Jan 8 16:52:45.533: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:52:45.533: htsp_timer - 125 msec
Jan 8 16:52:45.661: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:52:45.661: htsp_timer - 10000 msec
Jan 8 16:52:45.661: htsp_timer3 - 5600 msec
Jan 8 16:52:45.661: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 16:52:45.661: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:52:45.661: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 16:52:46.657: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:52:46.657: fxols_ringing_not
Jan 8 16:52:46.657: htsp_timer_stop
Jan 8 16:52:46.657: htsp_timer - 10000 msec
Jan 8 16:52:47.505: [0/3/2] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX
Jan 8 16:52:47.505: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
Jan 8 16:52:47.505: htsp_timer_stop
Jan 8 16:52:47.509: htsp_timer_stop3
Jan 8 16:52:47.509: [0/3/2] htsp_stop_caller_id_rx. message length 22htsp_setup_ind
Jan 8 16:52:47.509: [0/3/2] get_fxo_caller_id:Caller ID received. Message type=128 length=22 checksum=49
Jan 8 16:52:47.509: [0/3/2] Caller ID String 80 13 01 08 30 31 30 38 31 39 35 33 02 07 34 34 36 38 38 30 39 49
Jan 8 16:52:47.509: [0/3/2] get_fxo_caller_id calling num=4468809 calling name= calling time=01/08 19:53
Jan 8 16:52:47.509: fxols_callerid_done: call being answered
Jan 8 16:52:47.509: [0/3/2] htsp_dsm_close_done
Jan 8 16:52:47.509: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:52:47.509: fxols_wait_setup_ack:
Jan 8 16:52:47.509: htsp_timer - 6000 msec
Jan 8 16:52:47.513: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:52:47.549: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:52:50.573: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 16:52:50.573: htsp_timer_stop
Jan 8 16:52:52.149: htsp_timer_stop3
Jan 8 16:52:52.169: htsp_process_event: [0/2/1, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:52.169: htsp_timer_stop
Jan 8 16:52:52.169: htsp_timer_stop2
Jan 8 16:52:52.169: htsp_timer_stop3
Jan 8 16:52:52.169: [0/2/1] set signal state = 0x4 timestamp = 0
Jan 8 16:52:52.169: htsp_timer - 2000 msec
Jan 8 16:52:52.445: htsp_process_event: [0/2/1, FXOLS_GUARD_OUT, E_DSP_SIG_0110]
Jan 8 16:52:52.637: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 16:52:52.637: htsp_timer_stop2
Jan 8 16:52:52.637: htsp_timer - 6000 msec
Jan 8 16:52:54.169: htsp_process_event: [0/2/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:52:54.173: htsp_process_event: [0/2/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:57.609: htsp_timer_stop3 htsp_setup_req
Jan 8 16:52:57.613: htsp_process_event: [0/1/1, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
Jan 8 16:52:57.613: [0/1/1] set signal state = 0xC timestamp = 0
Jan 8 16:52:57.613: htsp_timer - 1300 msec
Jan 8 16:52:58.637: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:52:58.637: htsp_timer_stop
Jan 8 16:52:58.637: htsp_timer_stop2
Jan 8 16:52:58.637: htsp_timer_stop3
Jan 8 16:52:58.637: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:58.637: htsp_timer_stop
Jan 8 16:52:58.637: htsp_timer_stop2
Jan 8 16:52:58.637: htsp_timer_stop3
Jan 8 16:52:58.637: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:52:58.637: htsp_timer - 2000 msec
Jan 8 16:53:00.433: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:53:00.433: htsp_timer - 125 msec
Jan 8 16:53:00.561: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:53:00.561: htsp_timer - 10000 msec
Jan 8 16:53:00.561: htsp_timer3 - 5600 msec
Jan 8 16:53:00.561: [0/3/1] htsp_start_caller_id_rx:ETSI
Jan 8 16:53:00.561: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:53:00.561: [0/3/1] htsp_dsm_create_success returns 1
Jan 8 16:53:00.637: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:53:00.637: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:53:01.513: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:53:01.513: fxols_ringing_not
Jan 8 16:53:01.513: htsp_timer_stop
Jan 8 16:53:01.513: htsp_timer - 10000 msec
Jan 8 16:53:05.417: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 16:53:06.161: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 16:53:06.161: htsp_timer_stop3
Jan 8 16:53:07.565: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:53:07.565: fxols_ringing_not
Jan 8 16:53:07.565: htsp_timer_stop
Jan 8 16:53:07.565: htsp_timer_stop3
Jan 8 16:53:07.565: [0/3/1] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 16:53:07.565: [0/3/1] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 16:53:07.565: [0/3/1] get_local_station_id calling num= calling name= calling time=01/08 16:53 orig called=
Jan 8 16:53:07.565: [0/3/1] htsp_dsm_close_done
Jan 8 16:53:07.565: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:53:07.565: fxols_wait_setup_ack:
Jan 8 16:53:07.565: htsp_timer - 6000 msec
Jan 8 16:53:07.569: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:53:07.637: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:53:11.469: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 16:53:11.469: htsp_timer_stop
Jan 8 16:53:13.573: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 16:53:13.577: htsp_timer_stop2
Jan 8 16:53:13.577: htsp_timer - 6000 msec
Jan 8 16:53:14.581: htsp_timer_stop3
Jan 8 16:53:19.577: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:53:19.577: htsp_timer_stop
Jan 8 16:53:19.577: htsp_timer_stop2
Jan 8 16:53:19.577: htsp_timer_stop3
Jan 8 16:53:19.577: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:53:19.577: htsp_timer_stop
Jan 8 16:53:19.577: htsp_timer_stop2
Jan 8 16:53:19.577: htsp_timer_stop3
Jan 8 16:53:19.577: [0/3/1] set signal state = 0x4 timestamp = 0
Jan 8 16:53:19.577: htsp_timer - 2000 msec
Jan 8 16:53:21.577: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:53:21.577: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:53:26.537: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0110]
Jan 8 16:53:26.537: fxols_line_reversal_clid_wait. On_hook line reversal detected possibily due to crossed cable
Jan 8 16:54:09.517: htsp_timer_stop3 htsp_setup_req
Jan 8 16:59:42.177: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:59:42.177: htsp_timer_stop
Jan 8 16:59:42.177: htsp_timer_stop2
Jan 8 16:59:42.177: htsp_timer_stop3
Jan 8 16:59:42.177: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:59:42.177: htsp_timer_stop
Jan 8 16:59:42.177: htsp_timer_stop2
Jan 8 16:59:42.177: htsp_timer_stop3
Jan 8 16:59:42.177: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:59:42.177: htsp_timer - 2000 msec
Jan 8 16:59:42.873: htsp_timer_stop3 htsp_setup_req
Jan 8 16:59:44.177: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:59:44.177: htsp_process_event: [0/1/1, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
Jan 8 16:59:44.177: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:59:45.605: htsp_process_event: [0/1/1, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_progress
Jan 8 16:59:45.605: htsp_timer - 350 msec
Jan 8 16:59:45.605: htsp_call_bridged invoked
Jan 8 16:59:45.633: htsp_process_event: [0/1/1, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
Jan 8 16:59:45.633: htsp_timer_stop
Jan 8 16:59:45.729: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:59:45.729: htsp_timer - 125 msec
Jan 8 16:59:45.857: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:59:45.857: htsp_timer - 10000 msec
Jan 8 16:59:45.857: htsp_timer3 - 5600 msec
Jan 8 16:59:45.857: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 16:59:45.857: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:59:45.857: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 16:59:46.797: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:59:46.797: fxols_ringing_not
Jan 8 16:59:46.797: htsp_timer_stop
Jan 8 16:59:46.797: htsp_timer - 10000 msec
Jan 8 16:59:50.717: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 16:59:51.457: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 16:59:51.457: htsp_timer_stop3
Jan 8 16:59:52.793: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:59:52.793: fxols_ringing_not
Jan 8 16:59:52.793: htsp_timer_stop
Jan 8 16:59:52.793: htsp_timer_stop3
Jan 8 16:59:52.793: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 16:59:52.793: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 16:59:52.793: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 16:59 orig called=
Jan 8 16:59:52.797: [0/3/2] htsp_dsm_close_done
Jan 8 16:59:52.797: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:59:52.797: fxols_wait_setup_ack:
Jan 8 16:59:52.797: htsp_timer - 6000 msec
Jan 8 16:59:52.797: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:59:52.865: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:59:52.893: htsp_timer_stop3
Jan 8 16:59:58.797: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:59:58.797: htsp_timer_stop
Jan 8 16:59:58.797: htsp_timer_stop2
Jan 8 16:59:58.797: htsp_timer_stop3
Jan 8 16:59:58.797: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:59:58.797: htsp_timer_stop
Jan 8 16:59:58.797: htsp_timer_stop2
Jan 8 16:59:58.797: htsp_timer_stop3
Jan 8 16:59:58.797: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:59:58.797: htsp_timer - 2000 msec
Jan 8 17:00:00.797: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 17:00:00.801: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 17:00:05.493: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0110]
Jan 8 17:00:05.493: fxols_line_reversal_clid_wait. On_hook line reversal detected possibily due to crossed cable
Jan 8 17:00:10.585: htsp_timer_stop3 htsp_setup_req
Jan 8 17:00:13.709: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 17:00:13.709: htsp_timer - 125 msec
Jan 8 17:00:13.837: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 17:00:13.837: htsp_timer - 10000 msec
Jan 8 17:00:13.837: htsp_timer3 - 5600 msec
Jan 8 17:00:13.837: [0/3/1] htsp_start_caller_id_rx:ETSI
Jan 8 17:00:13.837: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 17:00:13.837: [0/3/1] htsp_dsm_create_success returns 1
Jan 8 17:00:14.773: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 17:00:14.773: fxols_ringing_not
Jan 8 17:00:14.773: htsp_timer_stop
Jan 8 17:00:14.773: htsp_timer - 10000 msec
Jan 8 17:00:18.725: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 17:00:19.437: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 17:00:19.437: htsp_timer_stop3
Jan 8 17:00:20.833: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 17:00:20.833: fxols_ringing_not
Jan 8 17:00:20.833: htsp_timer_stop
Jan 8 17:00:20.833: htsp_timer_stop3
Jan 8 17:00:20.833: [0/3/1] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 17:00:20.833: [0/3/1] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 17:00:20.833: [0/3/1] get_local_station_id calling num= calling name= calling time=01/08 17:00 orig called=
Jan 8 17:00:20.837: [0/3/1] htsp_dsm_close_done
Jan 8 17:00:20.837: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 17:00:20.837: fxols_wait_setup_ack:
Jan 8 17:00:20.837: htsp_timer - 6000 msec
Jan 8 17:00:20.837: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 17:00:20.901: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 17:00:24.717: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 17:00:24.717: htsp_timer_stop
Jan 8 17:00:26.081: htsp_timer_stop3
Jan 8 17:00:26.785: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear

 

after that i swapped 0/3/1 to 0/3/2 and it seems ok,

 

Log Buffer (1000000 bytes):

Dec 25 14:07:25.037: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Dec 25 14:07:25.037: htsp_timer - 125 msec
Dec 25 14:07:25.165: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Dec 25 14:07:25.165: htsp_timer - 10000 msec
Dec 25 14:07:25.165: htsp_timer3 - 5600 msec
Dec 25 14:07:25.165: [0/3/2] htsp_start_caller_id_rx:ETSI
Dec 25 14:07:25.165: htsp_start_caller_id_rx create dsp_stream_manager
Dec 25 14:07:25.165: [0/3/2] htsp_dsm_create_success returns 1
Dec 25 14:07:26.157: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Dec 25 14:07:26.157: fxols_ringing_not
Dec 25 14:07:26.157: htsp_timer_stop
Dec 25 14:07:26.157: htsp_timer - 10000 msec
Dec 25 14:07:30.069: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Dec 25 14:07:30.765: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Dec 25 14:07:30.765: htsp_timer_stop3
Dec 25 14:07:32.137: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Dec 25 14:07:32.137: fxols_ringing_not
Dec 25 14:07:32.137: htsp_timer_stop
Dec 25 14:07:32.137: htsp_timer_stop3
Dec 25 14:07:32.137: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Dec 25 14:07:32.137: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Dec 25 14:07:32.137: [0/3/2] get_local_station_id calling num= calling name= calling time=12/25 14:07 orig called=
Dec 25 14:07:32.137: [0/3/2] htsp_dsm_close_done
Dec 25 14:07:32.137: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Dec 25 14:07:32.137: fxols_wait_setup_ack:
Dec 25 14:07:32.137: htsp_timer - 6000 msec
Dec 25 14:07:32.141: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Dec 25 14:07:32.213: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Dec 25 14:07:34.457: htsp_call_bridged invokedhtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Dec 25 14:07:34.461: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
Dec 25 14:07:34.461: [0/3/2] set signal state = 0xC timestamp = 0
Dec 25 14:07:34.461: htsp_timer_stop
Dec 25 14:07:34.461: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Dec 25 14:07:42.589: htsp_timer_stop3
Dec 25 14:07:42.605: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
Dec 25 14:07:42.605: htsp_timer_stop
Dec 25 14:07:42.605: htsp_timer_stop2
Dec 25 14:07:42.605: htsp_timer_stop3
Dec 25 14:07:42.605: [0/3/2] set signal state = 0x4 timestamp = 0
Dec 25 14:07:42.605: htsp_timer - 2000 msec
Dec 25 14:07:44.261: htsp_process_event: [0/0/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Dec 25 14:07:44.261: htsp_timer - 125 msec
Dec 25 14:07:44.389: htsp_process_event: [0/0/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Dec 25 14:07:44.389: htsp_timer - 10000 msec
Dec 25 14:07:44.389: htsp_timer3 - 5600 msec
Dec 25 14:07:44.389: [0/0/2] htsp_start_caller_id_rx:ETSI
Dec 25 14:07:44.389: htsp_start_caller_id_rx create dsp_stream_manager
Dec 25 14:07:44.389: [0/0/2] htsp_dsm_create_success returns 1
Dec 25 14:07:44.605: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Dec 25 14:07:44.609: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]

Jan 8 07:03:05.475: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 07:03:05.475: htsp_timer - 125 msec
Jan 8 07:03:05.603: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 07:03:05.603: htsp_timer - 10000 msec
Jan 8 07:03:05.603: htsp_timer3 - 5600 msec
Jan 8 07:03:05.603: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 07:03:05.603: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 07:03:05.603: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 07:03:06.599: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:06.599: fxols_ringing_not
Jan 8 07:03:06.599: htsp_timer_stop
Jan 8 07:03:06.599: htsp_timer - 10000 msechtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:10.503: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 07:03:11.203: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 07:03:11.203: htsp_timer_stop3
Jan 8 07:03:12.567: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:12.567: fxols_ringing_not
Jan 8 07:03:12.567: htsp_timer_stop
Jan 8 07:03:12.567: htsp_timer - 10000 msec
Jan 8 07:03:16.491: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 07:03:18.591: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 07:03:18.591: fxols_ringing_not
Jan 8 07:03:18.591: htsp_timer_stop
Jan 8 07:03:18.591: htsp_timer_stop3
Jan 8 07:03:18.595: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 07:03:18.595: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 07:03:18.595: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 07:03 orig called=
Jan 8 07:03:18.595: [0/3/2] htsp_dsm_close_done
Jan 8 07:03:18.595: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 07:03:18.595: fxols_wait_setup_ack:
Jan 8 07:03:18.595: htsp_timer - 6000 msec
Jan 8 07:03:18.599: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 07:03:18.659: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:18.951: htsp_process_event: [0/1/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:03:19.519: htsp_digit_ready(0/2/0): digit = 7
Jan 8 07:03:22.487: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 07:03:22.487: htsp_timer_stop
Jan 8 07:03:24.591: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 07:03:24.591: htsp_timer_stop2
Jan 8 07:03:24.591: htsp_timer - 6000 msec
Jan 8 07:03:27.995: htsp_call_bridged invokedhtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:03:27.995: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
Jan 8 07:03:27.995: [0/3/2] set signal state = 0xC timestamp = 0
Jan 8 07:03:27.995: htsp_timer_stop
Jan 8 07:03:27.995: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:03:28.271: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_DSP_SIG_0110]fxols_rvs_battery
Jan 8 07:03:28.271: htsp_timer_stop2 htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:04:07.167: htsp_process_event: [0/3/2, FXOLS_CONNECT, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 07:04:07.167: htsp_timer_stop
Jan 8 07:04:07.167: htsp_timer_stop2
Jan 8 07:04:07.167: htsp_timer_stop3
Jan 8 07:04:07.167: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 07:04:07.167: htsp_timer - 2000 msec
Jan 8 07:04:07.439: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_DSP_SIG_0110]htsp_call_service_msghtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:04:09.167: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 07:04:09.171: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]htsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:04:12.579: htsp_process_event: [0/2/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
Jan 8 07:04:20.055: htsp_process_event: [0/2/0, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voicehtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 07:04:26.335: htsp_timer_stop3
Jan 8 16:51:50.225: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:51:50.225: htsp_timer - 125 msec
Jan 8 16:51:50.353: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:51:50.353: htsp_timer - 10000 msec
Jan 8 16:51:50.353: htsp_timer3 - 5600 msec
Jan 8 16:51:50.353: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 16:51:50.353: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:51:50.353: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 16:51:51.317: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:51:51.317: fxols_ringing_not
Jan 8 16:51:51.317: htsp_timer_stop
Jan 8 16:51:51.317: htsp_timer - 10000 msec
Jan 8 16:51:55.277: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 16:51:55.953: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 16:51:55.953: htsp_timer_stop3
Jan 8 16:51:56.113: htsp_timer_stop3
Jan 8 16:51:56.133: htsp_process_event: [0/2/2, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:51:56.133: htsp_timer_stop
Jan 8 16:51:56.133: htsp_timer_stop2
Jan 8 16:51:56.133: htsp_timer_stop3
Jan 8 16:51:56.133: [0/2/2] set signal state = 0x4 timestamp = 0
Jan 8 16:51:56.133: htsp_timer - 2000 msec
Jan 8 16:51:56.825: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:51:56.825: fxols_ringing_not
Jan 8 16:51:56.825: htsp_timer_stop
Jan 8 16:51:56.825: htsp_timer_stop3
Jan 8 16:51:56.825: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 16:51:56.825: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 16:51:56.825: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 16:51 orig called=
Jan 8 16:51:56.825: [0/3/2] htsp_dsm_close_done
Jan 8 16:51:56.825: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:51:56.825: fxols_wait_setup_ack:
Jan 8 16:51:56.825: htsp_timer - 6000 msec
Jan 8 16:51:56.829: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:51:56.901: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:51:58.133: htsp_process_event: [0/2/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:51:58.137: htsp_process_event: [0/2/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:01.113: htsp_timer_stop3 htsp_setup_req
Jan 8 16:52:01.113: htsp_process_event: [0/2/3, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
Jan 8 16:52:01.113: [0/2/3] set signal state = 0xC timestamp = 0
Jan 8 16:52:01.117: htsp_timer - 1300 msec
Jan 8 16:52:01.389: htsp_process_event: [0/2/3, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_0110]fxols_disc_clear
Jan 8 16:52:01.389: htsp_timer_stop2
Jan 8 16:52:01.389: htsp_timer - 1300 msec
Jan 8 16:52:02.689: htsp_process_event: [0/2/3, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
Jan 8 16:52:02.825: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:52:02.825: htsp_timer_stop
Jan 8 16:52:02.825: htsp_timer_stop2
Jan 8 16:52:02.825: htsp_timer_stop3
Jan 8 16:52:02.825: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:02.825: htsp_timer_stop
Jan 8 16:52:02.825: htsp_timer_stop2
Jan 8 16:52:02.825: htsp_timer_stop3
Jan 8 16:52:02.825: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:52:02.825: htsp_timer - 2000 msec
Jan 8 16:52:04.117: htsp_process_event: [0/2/3, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_progress
Jan 8 16:52:04.117: htsp_timer - 350 msec
Jan 8 16:52:04.117: htsp_call_bridged invoked
Jan 8 16:52:04.145: htsp_process_event: [0/2/3, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
Jan 8 16:52:04.145: htsp_timer_stop
Jan 8 16:52:04.189: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:52:04.189: htsp_timer - 125 msec
Jan 8 16:52:04.317: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:52:04.317: htsp_timer - 10000 msec
Jan 8 16:52:04.317: htsp_timer3 - 5600 msec
Jan 8 16:52:04.317: [0/3/1] htsp_start_caller_id_rx:ETSI
Jan 8 16:52:04.317: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:52:04.317: [0/3/1] htsp_dsm_create_success returns 1
Jan 8 16:52:04.825: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:52:04.829: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:05.281: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:52:05.281: fxols_ringing_not
Jan 8 16:52:05.281: htsp_timer_stop
Jan 8 16:52:05.281: htsp_timer - 10000 msec
Jan 8 16:52:06.145: [0/3/1] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX
Jan 8 16:52:06.145: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
Jan 8 16:52:06.145: htsp_timer_stop
Jan 8 16:52:06.145: htsp_timer_stop3
Jan 8 16:52:06.145: [0/3/1] htsp_stop_caller_id_rx. message length 22htsp_setup_ind
Jan 8 16:52:06.145: [0/3/1] get_fxo_caller_id:Caller ID received. Message type=128 length=22 checksum=59
Jan 8 16:52:06.145: [0/3/1] Caller ID String 80 13 01 08 30 31 30 38 31 39 35 32 02 07 34 34 37 30 33 31 35 59
Jan 8 16:52:06.145: [0/3/1] get_fxo_caller_id calling num=4470315 calling name= calling time=01/08 19:52
Jan 8 16:52:06.149: fxols_callerid_done: call being answered
Jan 8 16:52:06.149: [0/3/1] htsp_dsm_close_done
Jan 8 16:52:06.149: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:52:06.149: fxols_wait_setup_ack:
Jan 8 16:52:06.149: htsp_timer - 6000 msec
Jan 8 16:52:06.153: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:52:06.217: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:52:09.225: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 16:52:09.225: htsp_timer_stop
Jan 8 16:52:11.025: htsp_timer_stop3
Jan 8 16:52:11.041: htsp_process_event: [0/2/3, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:11.041: htsp_timer_stop
Jan 8 16:52:11.041: htsp_timer_stop2
Jan 8 16:52:11.041: htsp_timer_stop3
Jan 8 16:52:11.041: [0/2/3] set signal state = 0x4 timestamp = 0
Jan 8 16:52:11.041: htsp_timer - 2000 msec
Jan 8 16:52:11.289: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 16:52:11.289: htsp_timer_stop2
Jan 8 16:52:11.289: htsp_timer - 6000 msec
Jan 8 16:52:11.313: htsp_process_event: [0/2/3, FXOLS_GUARD_OUT, E_DSP_SIG_0110]
Jan 8 16:52:13.041: htsp_process_event: [0/2/3, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:52:13.041: htsp_process_event: [0/2/3, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:17.289: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:52:17.289: htsp_timer_stop
Jan 8 16:52:17.289: htsp_timer_stop2
Jan 8 16:52:17.289: htsp_timer_stop3
Jan 8 16:52:17.289: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:17.289: htsp_timer_stop
Jan 8 16:52:17.289: htsp_timer_stop2
Jan 8 16:52:17.289: htsp_timer_stop3
Jan 8 16:52:17.289: [0/3/1] set signal state = 0x4 timestamp = 0
Jan 8 16:52:17.289: htsp_timer - 2000 msec
Jan 8 16:52:19.305: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:52:19.305: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:52:27.093: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0110]
Jan 8 16:52:27.093: fxols_line_reversal_clid_wait. On_hook line reversal detected possibily due to crossed cable
Jan 8 16:52:42.417: htsp_timer_stop3 htsp_setup_req
Jan 8 16:52:42.417: htsp_process_event: [0/2/1, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
Jan 8 16:52:42.417: [0/2/1] set signal state = 0xC timestamp = 0
Jan 8 16:52:42.417: htsp_timer - 1300 msec
Jan 8 16:52:42.689: htsp_process_event: [0/2/1, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_0110]fxols_disc_clear
Jan 8 16:52:42.689: htsp_timer_stop2
Jan 8 16:52:42.689: htsp_timer - 1300 msec
Jan 8 16:52:43.989: htsp_process_event: [0/2/1, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
Jan 8 16:52:45.413: htsp_process_event: [0/2/1, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_progress
Jan 8 16:52:45.413: htsp_timer - 350 msec
Jan 8 16:52:45.413: htsp_call_bridged invoked
Jan 8 16:52:45.437: htsp_process_event: [0/2/1, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
Jan 8 16:52:45.437: htsp_timer_stop
Jan 8 16:52:45.533: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:52:45.533: htsp_timer - 125 msec
Jan 8 16:52:45.661: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:52:45.661: htsp_timer - 10000 msec
Jan 8 16:52:45.661: htsp_timer3 - 5600 msec
Jan 8 16:52:45.661: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 16:52:45.661: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:52:45.661: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 16:52:46.657: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:52:46.657: fxols_ringing_not
Jan 8 16:52:46.657: htsp_timer_stop
Jan 8 16:52:46.657: htsp_timer - 10000 msec
Jan 8 16:52:47.505: [0/3/2] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX
Jan 8 16:52:47.505: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
Jan 8 16:52:47.505: htsp_timer_stop
Jan 8 16:52:47.509: htsp_timer_stop3
Jan 8 16:52:47.509: [0/3/2] htsp_stop_caller_id_rx. message length 22htsp_setup_ind
Jan 8 16:52:47.509: [0/3/2] get_fxo_caller_id:Caller ID received. Message type=128 length=22 checksum=49
Jan 8 16:52:47.509: [0/3/2] Caller ID String 80 13 01 08 30 31 30 38 31 39 35 33 02 07 34 34 36 38 38 30 39 49
Jan 8 16:52:47.509: [0/3/2] get_fxo_caller_id calling num=4468809 calling name= calling time=01/08 19:53
Jan 8 16:52:47.509: fxols_callerid_done: call being answered
Jan 8 16:52:47.509: [0/3/2] htsp_dsm_close_done
Jan 8 16:52:47.509: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:52:47.509: fxols_wait_setup_ack:
Jan 8 16:52:47.509: htsp_timer - 6000 msec
Jan 8 16:52:47.513: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:52:47.549: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:52:50.573: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 16:52:50.573: htsp_timer_stop
Jan 8 16:52:52.149: htsp_timer_stop3
Jan 8 16:52:52.637: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 16:52:52.637: htsp_timer_stop2
Jan 8 16:52:52.637: htsp_timer - 6000 msec
Jan 8 16:52:58.637: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:52:58.637: htsp_timer_stop
Jan 8 16:52:58.637: htsp_timer_stop2
Jan 8 16:52:58.637: htsp_timer_stop3
Jan 8 16:52:58.637: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:52:58.637: htsp_timer_stop
Jan 8 16:52:58.637: htsp_timer_stop2
Jan 8 16:52:58.637: htsp_timer_stop3
Jan 8 16:52:58.637: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:52:58.637: htsp_timer - 2000 msec
Jan 8 16:53:00.433: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:53:00.433: htsp_timer - 125 msec
Jan 8 16:53:00.561: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:53:00.561: htsp_timer - 10000 msec
Jan 8 16:53:00.561: htsp_timer3 - 5600 msec
Jan 8 16:53:00.561: [0/3/1] htsp_start_caller_id_rx:ETSI
Jan 8 16:53:00.561: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:53:00.561: [0/3/1] htsp_dsm_create_success returns 1
Jan 8 16:53:00.637: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:53:00.637: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:53:01.513: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:53:01.513: fxols_ringing_not
Jan 8 16:53:01.513: htsp_timer_stop
Jan 8 16:53:01.513: htsp_timer - 10000 msec
Jan 8 16:53:05.417: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 16:53:06.161: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 16:53:06.161: htsp_timer_stop3
Jan 8 16:53:07.565: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:53:07.565: fxols_ringing_not
Jan 8 16:53:07.565: htsp_timer_stop
Jan 8 16:53:07.565: htsp_timer_stop3
Jan 8 16:53:07.565: [0/3/1] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 16:53:07.565: [0/3/1] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 16:53:07.565: [0/3/1] get_local_station_id calling num= calling name= calling time=01/08 16:53 orig called=
Jan 8 16:53:07.565: [0/3/1] htsp_dsm_close_done
Jan 8 16:53:07.565: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:53:07.565: fxols_wait_setup_ack:
Jan 8 16:53:07.565: htsp_timer - 6000 msec
Jan 8 16:53:07.569: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:53:07.637: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:53:11.469: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 16:53:11.469: htsp_timer_stop
Jan 8 16:53:13.573: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 16:53:13.577: htsp_timer_stop2
Jan 8 16:53:13.577: htsp_timer - 6000 msec
Jan 8 16:53:14.581: htsp_timer_stop3
Jan 8 16:53:19.577: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:53:19.577: htsp_timer_stop
Jan 8 16:53:19.577: htsp_timer_stop2
Jan 8 16:53:19.577: htsp_timer_stop3
Jan 8 16:53:19.577: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:53:19.577: htsp_timer_stop
Jan 8 16:53:19.577: htsp_timer_stop2
Jan 8 16:53:19.577: htsp_timer_stop3
Jan 8 16:53:19.577: [0/3/1] set signal state = 0x4 timestamp = 0
Jan 8 16:53:19.577: htsp_timer - 2000 msec
Jan 8 16:53:21.577: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:53:21.577: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:53:26.537: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0110]
Jan 8 16:53:26.537: fxols_line_reversal_clid_wait. On_hook line reversal detected possibily due to crossed cable
Jan 8 16:54:09.517: htsp_timer_stop3 htsp_setup_req
Jan 8 16:59:42.177: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:59:42.177: htsp_timer_stop
Jan 8 16:59:42.177: htsp_timer_stop2
Jan 8 16:59:42.177: htsp_timer_stop3
Jan 8 16:59:42.177: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:59:42.177: htsp_timer_stop
Jan 8 16:59:42.177: htsp_timer_stop2
Jan 8 16:59:42.177: htsp_timer_stop3
Jan 8 16:59:42.177: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:59:42.177: htsp_timer - 2000 msec
Jan 8 16:59:42.873: htsp_timer_stop3 htsp_setup_req
Jan 8 16:59:42.877: htsp_process_event: [0/1/1, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
Jan 8 16:59:42.877: [0/1/1] set signal state = 0xC timestamp = 0
Jan 8 16:59:42.877: htsp_timer - 1300 msec
Jan 8 16:59:44.177: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:59:44.177: htsp_process_event: [0/1/1, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
Jan 8 16:59:44.177: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:59:45.729: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 16:59:45.729: htsp_timer - 125 msec
Jan 8 16:59:45.857: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 16:59:45.857: htsp_timer - 10000 msec
Jan 8 16:59:45.857: htsp_timer3 - 5600 msec
Jan 8 16:59:45.857: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 16:59:45.857: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 16:59:45.857: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 16:59:46.797: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:59:46.797: fxols_ringing_not
Jan 8 16:59:46.797: htsp_timer_stop
Jan 8 16:59:46.797: htsp_timer - 10000 msec
Jan 8 16:59:50.717: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 16:59:51.457: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 16:59:51.457: htsp_timer_stop3
Jan 8 16:59:52.793: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 16:59:52.793: fxols_ringing_not
Jan 8 16:59:52.793: htsp_timer_stop
Jan 8 16:59:52.793: htsp_timer_stop3
Jan 8 16:59:52.793: [0/3/2] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 16:59:52.793: [0/3/2] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 16:59:52.793: [0/3/2] get_local_station_id calling num= calling name= calling time=01/08 16:59 orig called=
Jan 8 16:59:52.797: [0/3/2] htsp_dsm_close_done
Jan 8 16:59:52.797: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 16:59:52.797: fxols_wait_setup_ack:
Jan 8 16:59:52.797: htsp_timer - 6000 msec
Jan 8 16:59:52.797: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 16:59:52.865: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 16:59:52.893: htsp_timer_stop3
Jan 8 16:59:52.909: htsp_process_event: [0/1/1, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:59:52.909: htsp_timer_stop
Jan 8 16:59:52.909: htsp_timer_stop2
Jan 8 16:59:52.909: htsp_timer_stop3
Jan 8 16:59:52.909: [0/1/1] set signal state = 0x4 timestamp = 0
Jan 8 16:59:52.909: htsp_timer - 2000 msec
Jan 8 16:59:54.909: htsp_process_event: [0/1/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 16:59:54.913: htsp_process_event: [0/1/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 16:59:58.797: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 16:59:58.797: htsp_timer_stop
Jan 8 16:59:58.797: htsp_timer_stop2
Jan 8 16:59:58.797: htsp_timer_stop3
Jan 8 16:59:58.797: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 16:59:58.797: htsp_timer_stop
Jan 8 16:59:58.797: htsp_timer_stop2
Jan 8 16:59:58.797: htsp_timer_stop3
Jan 8 16:59:58.797: [0/3/2] set signal state = 0x4 timestamp = 0
Jan 8 16:59:58.797: htsp_timer - 2000 msec
Jan 8 17:00:00.797: htsp_process_event: [0/3/2, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 17:00:00.801: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 17:00:05.493: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0110]
Jan 8 17:00:05.493: fxols_line_reversal_clid_wait. On_hook line reversal detected possibily due to crossed cable
Jan 8 17:00:10.585: htsp_timer_stop3 htsp_setup_req
Jan 8 17:00:10.585: htsp_process_event: [0/2/3, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
Jan 8 17:00:10.589: [0/2/3] set signal state = 0xC timestamp = 0
Jan 8 17:00:10.589: htsp_timer - 1300 msec
Jan 8 17:00:10.861: htsp_process_event: [0/2/3, FXOLS_WAIT_DIAL_TONE, E_DSP_SIG_0110]fxols_disc_clear
Jan 8 17:00:10.861: htsp_timer_stop2
Jan 8 17:00:10.861: htsp_timer - 1300 msec
Jan 8 17:00:12.161: htsp_process_event: [0/2/3, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
Jan 8 17:00:13.589: htsp_process_event: [0/2/3, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_progress
Jan 8 17:00:13.589: htsp_timer - 350 msec
Jan 8 17:00:13.589: htsp_call_bridged invoked
Jan 8 17:00:13.613: htsp_process_event: [0/2/3, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
Jan 8 17:00:13.613: htsp_timer_stop
Jan 8 17:00:13.709: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 17:00:13.709: htsp_timer - 125 msec
Jan 8 17:00:13.837: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 17:00:13.837: htsp_timer - 10000 msec
Jan 8 17:00:13.837: htsp_timer3 - 5600 msec
Jan 8 17:00:13.837: [0/3/1] htsp_start_caller_id_rx:ETSI
Jan 8 17:00:13.837: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 17:00:13.837: [0/3/1] htsp_dsm_create_success returns 1
Jan 8 17:00:14.773: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 17:00:14.773: fxols_ringing_not
Jan 8 17:00:14.773: htsp_timer_stop
Jan 8 17:00:14.773: htsp_timer - 10000 msec
Jan 8 17:00:18.725: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0000]
Jan 8 17:00:19.437: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 17:00:19.437: htsp_timer_stop3
Jan 8 17:00:20.833: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 17:00:20.833: fxols_ringing_not
Jan 8 17:00:20.833: htsp_timer_stop
Jan 8 17:00:20.833: htsp_timer_stop3
Jan 8 17:00:20.833: [0/3/1] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
Jan 8 17:00:20.833: [0/3/1] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.
Jan 8 17:00:20.833: [0/3/1] get_local_station_id calling num= calling name= calling time=01/08 17:00 orig called=
Jan 8 17:00:20.837: [0/3/1] htsp_dsm_close_done
Jan 8 17:00:20.837: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 17:00:20.837: fxols_wait_setup_ack:
Jan 8 17:00:20.837: htsp_timer - 6000 msec
Jan 8 17:00:20.837: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 17:00:20.901: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 17:00:24.717: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0000]fxols_proceed_ring
Jan 8 17:00:24.717: htsp_timer_stop
Jan 8 17:00:26.081: htsp_timer_stop3
Jan 8 17:00:26.785: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_DSP_SIG_0100]fxols_proceed_clear
Jan 8 17:00:26.785: htsp_timer_stop2
Jan 8 17:00:26.785: htsp_timer - 6000 msec
Jan 8 17:02:12.565: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
Jan 8 17:02:12.565: htsp_timer_stop3
Jan 8 17:02:17.445: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER]fxols_ringing_disc
Jan 8 17:02:17.445: htsp_timer_stop3
Jan 8 17:02:17.445: htsp_timer_stop
Jan 8 17:02:17.445: [0/3/1] htsp_stop_caller_id_rx. message length 0
Jan 8 17:02:17.445: [0/3/1] htsp_dsm_close_done
Jan 8 17:03:41.925: htsp_timer_stop3 htsp_setup_req
Jan 8 17:03:41.925: htsp_process_event: [0/2/0, FXOLS_ONHOOK, E_HTSP_SETUP_REQ]fxols_onhook_setup
Jan 8 17:03:41.925: [0/2/0] set signal state = 0xC timestamp = 0
Jan 8 17:03:41.929: htsp_timer - 1300 msec
Jan 8 17:03:43.229: htsp_process_event: [0/2/0, FXOLS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxols_wait_dial_timer htsp_dial
Jan 8 17:03:44.657: htsp_process_event: [0/2/0, FXOLS_WAIT_DIAL_DONE, E_DSP_DIALING_DONE]fxols_wait_dial_done htsp_progress
Jan 8 17:03:44.657: htsp_timer - 350 msec
Jan 8 17:03:44.657: htsp_call_bridged invoked
Jan 8 17:03:44.685: htsp_process_event: [0/2/0, FXOLS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxols_handle_cut_thru
Jan 8 17:03:44.685: htsp_timer_stop
Jan 8 17:03:44.773: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 17:03:44.773: htsp_timer - 125 msec
Jan 8 17:03:44.901: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 17:03:44.901: htsp_timer - 10000 msec
Jan 8 17:03:44.901: htsp_timer3 - 5600 msec
Jan 8 17:03:44.901: [0/3/1] htsp_start_caller_id_rx:ETSI
Jan 8 17:03:44.901: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 17:03:44.901: [0/3/1] htsp_dsm_create_success returns 1
Jan 8 17:03:45.853: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 17:03:45.853: fxols_ringing_not
Jan 8 17:03:45.857: htsp_timer_stop
Jan 8 17:03:45.857: htsp_timer - 10000 msec
Jan 8 17:03:46.709: [0/3/1] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX
Jan 8 17:03:46.709: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
Jan 8 17:03:46.709: htsp_timer_stop
Jan 8 17:03:46.709: htsp_timer_stop3
Jan 8 17:03:46.709: [0/3/1] htsp_stop_caller_id_rx. message length 22htsp_setup_ind
Jan 8 17:03:46.709: [0/3/1] get_fxo_caller_id:Caller ID received. Message type=128 length=22 checksum=56
Jan 8 17:03:46.709: [0/3/1] Caller ID String 80 13 01 08 30 31 30 38 32 30 30 34 02 07 34 34 36 38 38 30 38 56
Jan 8 17:03:46.709: [0/3/1] get_fxo_caller_id calling num=4468808 calling name= calling time=01/08 20:04
Jan 8 17:03:46.709: fxols_callerid_done: call being answered
Jan 8 17:03:46.709: [0/3/1] htsp_dsm_close_done
Jan 8 17:03:46.709: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 17:03:46.709: fxols_wait_setup_ack:
Jan 8 17:03:46.709: htsp_timer - 6000 msec
Jan 8 17:03:46.713: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 17:03:46.777: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 17:03:48.461: htsp_timer_stop3
Jan 8 17:03:48.481: htsp_process_event: [0/2/0, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 17:03:48.481: htsp_timer_stop
Jan 8 17:03:48.481: htsp_timer_stop2
Jan 8 17:03:48.481: htsp_timer_stop3
Jan 8 17:03:48.481: [0/2/0] set signal state = 0x4 timestamp = 0
Jan 8 17:03:48.481: htsp_timer - 2000 msec
Jan 8 17:03:50.481: htsp_process_event: [0/2/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 17:03:50.481: htsp_process_event: [0/2/0, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 17:03:52.709: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER]fxols_disc_confirm
Jan 8 17:03:52.709: htsp_timer_stop
Jan 8 17:03:52.709: htsp_timer_stop2
Jan 8 17:03:52.709: htsp_timer_stop3
Jan 8 17:03:52.709: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 17:03:52.709: htsp_timer_stop
Jan 8 17:03:52.709: htsp_timer_stop2
Jan 8 17:03:52.709: htsp_timer_stop3
Jan 8 17:03:52.709: [0/3/1] set signal state = 0x4 timestamp = 0
Jan 8 17:03:52.709: htsp_timer - 2000 msec
Jan 8 17:03:54.709: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 17:03:54.713: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Jan 8 17:04:08.781: htsp_timer_stop3 htsp_setup_req
Jan 8 17:04:11.645: htsp_process_event: [0/3/2, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
Jan 8 17:04:11.645: htsp_timer - 125 msec
Jan 8 17:04:11.773: htsp_process_event: [0/3/2, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
Jan 8 17:04:11.773: htsp_timer - 10000 msec
Jan 8 17:04:11.773: htsp_timer3 - 5600 msec
Jan 8 17:04:11.773: [0/3/2] htsp_start_caller_id_rx:ETSI
Jan 8 17:04:11.773: htsp_start_caller_id_rx create dsp_stream_manager
Jan 8 17:04:11.773: [0/3/2] htsp_dsm_create_success returns 1
Jan 8 17:04:12.753: htsp_process_event: [0/3/2, FXOLS_RINGING, E_DSP_SIG_0100]
Jan 8 17:04:12.753: fxols_ringing_not
Jan 8 17:04:12.753: htsp_timer_stop
Jan 8 17:04:12.753: htsp_timer - 10000 msec
Jan 8 17:04:13.601: [0/3/2] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX
Jan 8 17:04:13.601: htsp_process_event: [0/3/2, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
Jan 8 17:04:13.601: htsp_timer_stop
Jan 8 17:04:13.601: htsp_timer_stop3
Jan 8 17:04:13.601: [0/3/2] htsp_stop_caller_id_rx. message length 22htsp_setup_ind
Jan 8 17:04:13.601: [0/3/2] get_fxo_caller_id:Caller ID received. Message type=128 length=22 checksum=57
Jan 8 17:04:13.601: [0/3/2] Caller ID String 80 13 01 08 30 31 30 38 32 30 30 34 02 07 34 34 36 38 38 30 37 57
Jan 8 17:04:13.601: [0/3/2] get_fxo_caller_id calling num=4468807 calling name= calling time=01/08 20:04
Jan 8 17:04:13.601: fxols_callerid_done: call being answered
Jan 8 17:04:13.601: [0/3/2] htsp_dsm_close_done
Jan 8 17:04:13.601: htsp_process_event: [0/3/2, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
Jan 8 17:04:13.601: fxols_wait_setup_ack:
Jan 8 17:04:13.601: htsp_timer - 6000 msec
Jan 8 17:04:13.605: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_prochtsp_alert_notify
Jan 8 17:04:13.645: htsp_process_event: [0/3/2, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)
Jan 8 17:04:13.909: htsp_timer_stop3
Jan 8 17:04:13.925: htsp_process_event: [0/1/3, FXOLS_OFFHOOK, E_HTSP_RELEASE_REQ]fxols_offhook_release
Jan 8 17:04:13.925: htsp_timer_stop
Jan 8 17:04:13.925: htsp_timer_stop2
Jan 8 17:04:13.925: htsp_timer_stop3
Jan 8 17:04:13.925: [0/1/3] set signal state = 0x4 timestamp = 0
Jan 8 17:04:13.925: htsp_timer - 2000 msec
Jan 8 17:04:15.925: htsp_process_event: [0/1/3, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
Jan 8 17:04:15.925: htsp_process_event: [0/1/3, FXOLS_ONHOOK, E_DSP_SIG_0100]