Router#debug vpm si
Router#debug vpm signal 
Voice Port Module signaling debugging is enabled
Router#
Router#
Router#
Router#
Router#
Router#
*Jul  7 13:44:09.655: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=65219 systime=537866
*Jul  7 13:44:09.655: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Jul  7 13:44:09.655: htsp_timer - 125 msec
*Jul  7 13:44:09.783: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Jul  7 13:44:09.783: htsp_timer - 10000 msec
*Jul  7 13:44:09.783: htsp_timer3 - 5600 msec
*Jul  7 13:44:09.783: [0/3/1] htsp_start_caller_id_rx:Mode BELLCORE. Alerting 0x1
*Jul  7 13:44:09.783: htsp_start_caller_id_rx create dsp_stream_manager
*Jul  7 13:44:09.783: [0/3/1] htsp_dsm_create_success  returns 1
*Jul  7 13:44:10.663: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=686 systime=537967
*Jul  7 13:44:10.663: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
*Jul  7 13:44:10.663: fxols_ringing_not 
*Jul  7 13:44:10.663: htsp_timer_stop 
*Jul  7 13:44:10.663: htsp_timer - 10000 msec
*Jul  7 13:44:11.843: [0/3/1] htsp_dsm_feature_notify_cb  returns 2 id=DSM_FEATURE_SM_CALLERID_RX
*Jul  7 13:44:11.843: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]
*Jul  7 13:44:11.843: htsp_timer_stop 
*Jul  7 13:44:11.843: htsp_timer_stop3 
*Jul  7 13:44:11.843: [0/3/1] htsp_stop_caller_id_rx. message length 21htsp_setup_ind
*Jul  7 13:44:11.843: [0/3/1] get_fxo_caller_id:Caller ID received. Message type=4 length=21 checksum=56
*Jul  7 13:44:11.843: [0/3/1] Caller ID String 04 12 30 37 30 37 31 36 34 34 30 36 32 32 32 31 35 31 33 31 56 
*Jul  7 13:44:11.843: [0/3/1] get_fxo_caller_id calling num=0622215131 calling name= calling time=07/07 16:44  
*Jul  7 13:44:11.843: fxols_callerid_done: call being answered
*Jul  7 13:44:11.847: [0/3/1] htsp_dsm_close_done
*Jul  7 13:44:11.847: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Jul  7 13:44:11.847: fxols_wait_setup_ack: 
*Jul  7 13:44:11.847: htsp_timer - 6000 msec
*Jul  7 13:44:11.851: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc
*Jul  7 13:44:11.859: htsp_pre_connect_disconnect, cdb = 23332060 cause = 3F

*Jul  7 13:44:11.859: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PRE_CONN_DISC]
*Jul  7 13:44:14.567: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=4595 systime=538358
*Jul  7 13:44:14.567: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_DSP_SIG_0000]
*Jul  7 13:44:15.663: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=5689 systime=538467
*Jul  7 13:44:15.663: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_DSP_SIG_0100]fxols_offhook_clear
*Jul  7 13:44:15.663: htsp_timer_stop2 
*Jul  7 13:44:17.847: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_HTSP_EVENT_TIMER]fxols_disc_confirm
*Jul  7 13:44:17.847: htsp_timer_stop 
*Jul  7 13:44:17.847: htsp_timer_stop2 
*Jul  7 13:44:17.847: htsp_timer_stop3 
*Jul  7 13:44:17.847: htsp_process_event: [0/3/1, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Jul  7 13:44:17.847: htsp_timer_stop 
*Jul  7 13:44:17.847: htsp_timer_stop2 
*Jul  7 13:44:17.847: htsp_timer_stop3 
*Jul  7 13:44:17.847: [0/3/1] set signal state = 0x4 timestamp = 0
*Jul  7 13:44:17.847: htsp_timer - 2000 msec
*Jul  7 13:44:19.563: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=9590 systime=538857
*Jul  7 13:44:19.563: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_DSP_SIG_0000]fxols_guard_out_ringing
*Jul  7 13:44:19.563: htsp_timer_stop fxols_onhook_ringing
*Jul  7 13:44:19.563: htsp_timer - 125 msec
*Jul  7 13:44:19.691: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Jul  7 13:44:19.691: htsp_timer - 10000 msec
*Jul  7 13:44:19.691: htsp_timer3 - 5600 msec
*Jul  7 13:44:19.691: [0/3/1] htsp_start_caller_id_rx:Mode BELLCORE. Alerting 0x1
*Jul  7 13:44:19.691: htsp_start_caller_id_rx create dsp_stream_manager
*Jul  7 13:44:19.691: [0/3/1] htsp_dsm_create_success  returns 1
*Jul  7 13:44:20.663: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=10690 systime=538967
*Jul  7 13:44:20.663: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
*Jul  7 13:44:20.667: fxols_ringing_not 
*Jul  7 13:44:20.667: htsp_timer_stop 
*Jul  7 13:44:20.667: htsp_timer - 10000 msec
*Jul  7 13:44:24.575: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=14603 systime=539358
*Jul  7 13:44:24.575: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0000]
*Jul  7 13:44:25.291: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
*Jul  7 13:44:25.291: htsp_timer_stop3 
*Jul  7 13:44:25.663: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=15692 systime=539467
*Jul  7 13:44:25.663: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
*Jul  7 13:44:25.667: fxols_ringing_not 
*Jul  7 13:44:25.667: htsp_timer_stop 
*Jul  7 13:44:25.667: htsp_timer_stop3 
*Jul  7 13:44:25.667: [0/3/1] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
*Jul  7 13:44:25.667: [0/3/1] get_fxo_caller_id:Caller ID receive failed.  parseCallerIDString:no data.
*Jul  7 13:44:25.667: [0/3/1] get_local_station_id calling num= calling name= calling time=07/07 13:44  orig called=
*Jul  7 13:44:25.671: [0/3/1] htsp_dsm_close_done
*Jul  7 13:44:25.671: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Jul  7 13:44:25.671: fxols_wait_setup_ack: 
*Jul  7 13:44:25.671: htsp_timer - 6000 msec
*Jul  7 13:44:25.675: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc
*Jul  7 13:44:25.683: htsp_pre_connect_disconnect, cdb = 23332060 cause = 3F

*Jul  7 13:44:25.683: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PRE_CONN_DISC]
*Jul  7 13:44:29.571: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=19597 systime=539858
*Jul  7 13:44:29.571: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_DSP_SIG_0000]
*Jul  7 13:44:30.667: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=20693 systime=539968
*Jul  7 13:44:30.667: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_DSP_SIG_0100]fxols_offhook_clear
*Jul  7 13:44:30.667: htsp_timer_stop2 
*Jul  7 13:44:31.671: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_HTSP_EVENT_TIMER]fxols_disc_confirm
*Jul  7 13:44:31.671: htsp_timer_stop 
*Jul  7 13:44:31.671: htsp_timer_stop2 
*Jul  7 13:44:31.671: htsp_timer_stop3 
*Jul  7 13:44:31.671: htsp_process_event: [0/3/1, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Jul  7 13:44:31.671: htsp_timer_stop 
*Jul  7 13:44:31.671: htsp_timer_stop2 
*Jul  7 13:44:31.671: htsp_timer_stop3 
*Jul  7 13:44:31.671: [0/3/1] set signal state = 0x4 timestamp = 0
*Jul  7 13:44:31.671: htsp_timer - 2000 msec
*Jul  7 13:44:33.671: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
*Jul  7 13:44:33.671: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=0 systime=540268
*Jul  7 13:44:33.671: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
*Jul  7 13:44:34.583: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=24608 systime=540359
*Jul  7 13:44:34.583: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Jul  7 13:44:34.583: htsp_timer - 125 msec
*Jul  7 13:44:34.711: htsp_process_event: [0/3/1, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Jul  7 13:44:34.711: htsp_timer - 10000 msec
*Jul  7 13:44:34.711: htsp_timer3 - 5600 msec
*Jul  7 13:44:34.711: [0/3/1] htsp_start_caller_id_rx:Mode BELLCORE. Alerting 0x1
*Jul  7 13:44:34.711: htsp_start_caller_id_rx create dsp_stream_manager
*Jul  7 13:44:34.711: [0/3/1] htsp_dsm_create_success  returns 1
*Jul  7 13:44:35.667: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=25696 systime=540468
*Jul  7 13:44:35.667: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
*Jul  7 13:44:35.667: fxols_ringing_not 
*Jul  7 13:44:35.667: htsp_timer_stop 
*Jul  7 13:44:35.667: htsp_timer - 10000 msec
*Jul  7 13:44:39.575: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=29602 systime=540858
*Jul  7 13:44:39.575: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0000]
*Jul  7 13:44:40.311: htsp_process_event: [0/3/1, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop
*Jul  7 13:44:40.311: htsp_timer_stop3 
*Jul  7 13:44:40.671: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=30698 systime=540968
*Jul  7 13:44:40.671: htsp_process_event: [0/3/1, FXOLS_RINGING, E_DSP_SIG_0100]
*Jul  7 13:44:40.671: fxols_ringing_not 
*Jul  7 13:44:40.671: htsp_timer_stop 
*Jul  7 13:44:40.671: htsp_timer_stop3 
*Jul  7 13:44:40.671: [0/3/1] htsp_stop_caller_id_rx. message length 0htsp_setup_ind
*Jul  7 13:44:40.671: [0/3/1] get_fxo_caller_id:Caller ID receive failed.  parseCallerIDString:no data.
*Jul  7 13:44:40.671: [0/3/1] get_local_station_id calling num= calling name= calling time=07/07 13:44  orig called=
*Jul  7 13:44:40.679: [0/3/1] htsp_dsm_close_done
*Jul  7 13:44:40.679: htsp_process_event: [0/3/1, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Jul  7 13:44:40.679: fxols_wait_setup_ack: 
*Jul  7 13:44:40.679: htsp_timer - 6000 msec
*Jul  7 13:44:40.679: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc
*Jul  7 13:44:40.691: htsp_pre_connect_disconnect, cdb = 23332060 cause = 3F

*Jul  7 13:44:40.691: htsp_process_event: [0/3/1, FXOLS_PROCEEDING, E_HTSP_PRE_CONN_DISC]
*Jul  7 13:44:44.571: htsp_dsp_message: SEND_SIG_STATUS: state=0x0 timestamp=34597 systime=541358
*Jul  7 13:44:44.571: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_DSP_SIG_0000]
*Jul  7 13:44:45.343: htsp_dsp_message: SEND_SIG_STATUS: state=0x4 timestamp=35370 systime=541435
*Jul  7 13:44:45.343: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_DSP_SIG_0100]fxols_offhook_clear
*Jul  7 13:44:45.343: htsp_timer_stop2 
*Jul  7 13:44:46.679: htsp_process_event: [0/3/1, FXOLS_OFFHOOK, E_HTSP_EVENT_TIMER]fxols_disc_confirm
*Jul  7 13:44:46.679: htsp_timer_stop 
*Jul  7 13:44:46.679: htsp_timer_stop2 
*Jul  7 13:44:46.679: htsp_timer_stop3 
*Jul  7 13:44:46.679: htsp_process_event: [0/3/1, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Jul  7 13:44:46.679: htsp_timer_stop 
*Jul  7 13:44:46.679: htsp_timer_stop2 
*Jul  7 13:44:46.679: htsp_timer_stop3 
*Jul  7 13:44:46.679: [0/3/1] set signal state = 0x4 timestamp = 0
*Jul  7 13:44:46.679: htsp_timer - 2000 msec
*Jul  7 13:44:48.679: htsp_process_event: [0/3/1, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
*Jul  7 13:44:48.679: htsp_dsp_message: RESP_SIG_STATUS: state=0x4 timestamp=0 systime=541769
*Jul  7 13:44:48.679: htsp_process_event: [0/3/1, FXOLS_ONHOOK, E_DSP_SIG_0100]
Router#
Router#
Router#
Router#
Router#
Router#
Router#
Router#
Router#