Solved: 4th FXO Line Not Working-Gives Half Rings

haseeb · ‎03-14-2010

Hi,

I am facing problem with 4 FXO lines configured on 2811 voice gateway with MGCP/CUCM7. Three lines are working perfectly on voice port 0,1 and 2, but when i connect 4th line on voice port 3 and calls from outside to inside then it gives half ring on the IP Phones instead of giving full ring. When i pick up the phone there is no response. Similarly i can't dialout using the same FXO port. I had connected other three working analog lines on this port and they work perfectly, which means the 4th port is fine. I had even used fifth analog number to ensure there is nothing wrong with the line, but the problem is not resolved. Please check the router configuration below and let me know what could be the possible issue?

Voice_Lab_Router#sh run

Building configuration...

Current configuration : 5507 bytes

!

version 12.4

service timestamps debug datetime msec

service timestamps log datetime msec

no service password-encryption

!

hostname Voice_Lab_Router

!

boot-start-marker

boot-end-marker

!

! card type command needed for slot/vwic-slot 0/2

logging buffered 51200 warnings

enable password cisco

!

no aaa new-model

dot11 syslog

!

ip cef

!

multilink bundle-name authenticated

!

voice-card 0

no dspfarm

!

crypto pki trustpoint TP-self-signed-2671316638

enrollment selfsigned

subject-name cn=IOS-Self-Signed-Certificate-2671316638

revocation-check none

rsakeypair TP-self-signed-2671316638

!

username admin password 0 cisco

archive

log config

hidekeys

!

interface FastEthernet0/0

description $ETH-LAN$$ETH-SW-LAUNCH$$INTF-INFO-FE 0/0$

ip address 192.168.80.254 255.255.255.0

duplex auto

speed auto

!

interface FastEthernet0/1

no ip address

shutdown

duplex auto

speed auto

!

ip forward-protocol nd

ip route 0.0.0.0 0.0.0.0 192.168.80.200

!

ip http server

ip http authentication local

ip http secure-server

ip http timeout-policy idle 60 life 86400 requests 10000

!

control-plane

!

voice-port 0/0/0

timing hookflash-out 50

caller-id enable

!

voice-port 0/0/1

caller-id enable

!

voice-port 0/0/2

timing hookflash-out 50

!

voice-port 0/0/3

timing hookflash-out 50

!

ccm-manager mgcp

ccm-manager music-on-hold

ccm-manager config server 192.168.80.10

ccm-manager config

!

mgcp

mgcp call-agent 192.168.80.10 2427 service-type mgcp version 0.1

mgcp rtp unreachable timeout 1000 action notify

mgcp modem passthrough voip mode nse

mgcp package-capability rtp-package

mgcp package-capability sst-package

mgcp package-capability pre-package

no mgcp package-capability res-package

no mgcp timer receive-rtcp

mgcp sdp simple

mgcp rtp payload-type g726r16 static

!

mgcp profile default

!

dial-peer voice 999000 pots

service mgcpapp

port 0/0/0

!

dial-peer voice 999001 pots

service mgcpapp

port 0/0/1

!

dial-peer voice 999002 pots

service mgcpapp

port 0/0/2

!

dial-peer voice 999003 pots

service mgcpapp

port 0/0/3

Thanks and Best Regards

paolo bevilacqua · ‎03-14-2010

Nothing appears to be wrong.

You could try H.323 instead of MGCP as it's much more stable.

View solution in original post

paolo bevilacqua · ‎03-14-2010

Likely it's gettin a power denial.

take "debug vpm signal" with "term mon". Do not enable any other debug, do not use attachaments.

You should also configure cptone according to your country.

haseeb · ‎03-14-2010

Thanks for your prompt reply. I had already tried cptone but it's not working.

I forgot to mention that these lines were working on Nortel BCM first and now i am shifting to CUCM7.

paolo bevilacqua · ‎03-14-2010

Do what is indicated above, not just cptone.

haseeb · ‎03-14-2010

The debug output is as follows:

Voice_Lab_Router#debug vpm signal
Voice Port Module signaling debugging is enabled
Voice_Lab_Router#
*Mar 14 21:44:13.016: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Mar 14 21:44:13.016: htsp_timer - 125 msec
*Mar 14 21:44:13.144: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Mar 14 21:44:13.144: htsp_timer - 10000 msec
*Mar 14 21:44:13.556: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]
*Mar 14 21:44:13.556: fxols_ringing_not
*Mar 14 21:44:13.556: htsp_timer_stop
*Mar 14 21:44:13.556: htsp_timer_stop3 htsp_setup_ind
*Mar 14 21:44:13.556: [0/0/3] get_local_station_id calling num= calling name= calling time=03/14 21:44 orig called=
*Mar 14 21:44:13.564: htsp_process_event: [0/0/3, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Mar 14 21:44:13.564: fxols_wait_setup_ack:
*Mar 14 21:44:13.564: [0/0/3] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Mar 14 21:44:13.564: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
*Mar 14 21:44:13.564: htsp_timer_stop
*Mar 14 21:44:13.572: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:13.572: htsp_call_bridged invoked
*Mar 14 21:44:13.576: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:13.816: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_DSP_SIG_1100]fxols_offhook_disc
*Mar 14 21:44:13.816: htsp_timer2 - 350 msec
*Mar 14 21:44:14.168: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_EVENT_TIMER2]fxols_disc_confirm
*Mar 14 21:44:14.168: htsp_timer_stop
*Mar 14 21:44:14.168: htsp_timer_stop2
*Mar 14 21:44:14.168: htsp_timer_stop3
*Mar 14 21:44:14.176: htsp_timer_stop3
*Mar 14 21:44:14.196: htsp_process_event: [0/0/3, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Mar 14 21:44:14.196: htsp_timer_stop
*Mar 14 21:44:14.196: htsp_timer_stop2
*Mar 14 21:44:14.196: htsp_timer_stop3
*Mar 14 21:44:14.196: [0/0/3] set signal state = 0x4 timestamp = 0
*Mar 14 21:44:14.196: htsp_timer - 2000 msec
*Mar 14 21:44:15.576: htsp_process_event: [0/0/3, FXOLS_GUARD_OUT, E_DSP_SIG_0000]fxols_guard_out_ringing
*Mar 14 21:44:15.576: htsp_timer_stop fxols_onhook_ringing
*Mar 14 21:44:15.576: htsp_timer - 125 msec
*Mar 14 21:44:15.704: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Mar 14 21:44:15.704: htsp_timer - 10000 msec
*Mar 14 21:44:16.076: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]
*Mar 14 21:44:16.076: fxols_ringing_not
*Mar 14 21:44:16.076: htsp_timer_stop
*Mar 14 21:44:16.076: htsp_timer_stop3 htsp_setup_ind
*Mar 14 21:44:16.076: [0/0/3] get_local_station_id calling num= calling name= calling time=03/14 21:44 orig called=
*Mar 14 21:44:16.084: htsp_process_event: [0/0/3, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Mar 14 21:44:16.084: fxols_wait_setup_ack:
*Mar 14 21:44:16.084: [0/0/3] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Mar 14 21:44:16.088: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
*Mar 14 21:44:16.088: htsp_timer_stop
*Mar 14 21:44:16.092: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:16.096: htsp_call_bridged invoked
*Mar 14 21:44:16.100: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:16.340: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_DSP_SIG_1100]fxols_offhook_disc
*Mar 14 21:44:16.340: htsp_timer2 - 350 msec
*Mar 14 21:44:16.692: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_EVENT_TIMER2]fxols_disc_confirm
*Mar 14 21:44:16.692: htsp_timer_stop
*Mar 14 21:44:16.692: htsp_timer_stop2
*Mar 14 21:44:16.692: htsp_timer_stop3
*Mar 14 21:44:16.700: htsp_timer_stop3
*Mar 14 21:44:16.716: htsp_process_event: [0/0/3, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Mar 14 21:44:16.716: htsp_timer_stop
*Mar 14 21:44:16.716: htsp_timer_stop2
*Mar 14 21:44:16.716: htsp_timer_stop3
*Mar 14 21:44:16.716: [0/0/3] set signal state = 0x4 timestamp = 0
*Mar 14 21:44:16.716: htsp_timer - 2000 msec
*Mar 14 21:44:18.716: htsp_process_event: [0/0/3, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
*Mar 14 21:44:18.716: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0100]
*Mar 14 21:44:20.264: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Mar 14 21:44:20.264: htsp_timer - 125 msec
*Mar 14 21:44:20.392: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Mar 14 21:44:20.392: htsp_timer - 10000 msec
*Mar 14 21:44:21.276: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]
*Mar 14 21:44:21.276: fxols_ringing_not
*Mar 14 21:44:21.276: htsp_timer_stop
*Mar 14 21:44:21.276: htsp_timer_stop3 htsp_setup_ind
*Mar 14 21:44:21.276: [0/0/3] get_local_station_id calling num= calling name= calling time=03/14 21:44 orig called=
*Mar 14 21:44:21.284: htsp_process_event: [0/0/3, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Mar 14 21:44:21.284: fxols_wait_setup_ack:
*Mar 14 21:44:21.284: [0/0/3] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Mar 14 21:44:21.284: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
*Mar 14 21:44:21.284: htsp_timer_stop
*Mar 14 21:44:21.292: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:21.292: htsp_call_bridged invoked
*Mar 14 21:44:21.296: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:21.536: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_DSP_SIG_1100]fxols_offhook_disc
*Mar 14 21:44:21.540: htsp_timer2 - 350 msec
*Mar 14 21:44:21.892: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_EVENT_TIMER2]fxols_disc_confirm
*Mar 14 21:44:21.892: htsp_timer_stop
*Mar 14 21:44:21.892: htsp_timer_stop2
*Mar 14 21:44:21.892: htsp_timer_stop3
*Mar 14 21:44:21.900: htsp_timer_stop3
*Mar 14 21:44:21.916: htsp_process_event: [0/0/3, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Mar 14 21:44:21.916: htsp_timer_stop
*Mar 14 21:44:21.916: htsp_timer_stop2
*Mar 14 21:44:21.916: htsp_timer_stop3
*Mar 14 21:44:21.916: [0/0/3] set signal state = 0x4 timestamp = 0
*Mar 14 21:44:21.916: htsp_timer - 2000 msec
*Mar 14 21:44:23.916: htsp_process_event: [0/0/3, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
*Mar 14 21:44:23.916: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0100]
*Mar 14 21:44:25.224: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Mar 14 21:44:25.224: htsp_timer - 125 msec
*Mar 14 21:44:25.352: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Mar 14 21:44:25.352: htsp_timer - 10000 msec
*Mar 14 21:44:26.236: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]
*Mar 14 21:44:26.240: fxols_ringing_not
*Mar 14 21:44:26.240: htsp_timer_stop
*Mar 14 21:44:26.240: htsp_timer_stop3 htsp_setup_ind
*Mar 14 21:44:26.240: [0/0/3] get_local_station_id calling num= calling name= calling time=03/14 21:44 orig called=
*Mar 14 21:44:26.244: htsp_process_event: [0/0/3, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Mar 14 21:44:26.248: fxols_wait_setup_ack:
*Mar 14 21:44:26.248: [0/0/3] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Mar 14 21:44:26.248: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect
*Mar 14 21:44:26.248: htsp_timer_stop
*Mar 14 21:44:26.252: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:26.256: htsp_call_bridged invoked
*Mar 14 21:44:26.260: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_VOICE_CUT_THROUGH]fxols_connect_proc_voice
*Mar 14 21:44:26.500: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_DSP_SIG_1100]fxols_offhook_disc
*Mar 14 21:44:26.500: htsp_timer2 - 350 msec
*Mar 14 21:44:26.852: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_EVENT_TIMER2]fxols_disc_confirm
*Mar 14 21:44:26.852: htsp_timer_stop
*Mar 14 21:44:26.852: htsp_timer_stop2
*Mar 14 21:44:26.852: htsp_timer_stop3
*Mar 14 21:44:26.860: htsp_timer_stop3
*Mar 14 21:44:26.876: htsp_process_event: [0/0/3, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Mar 14 21:44:26.876: htsp_timer_stop
*Mar 14 21:44:26.876: htsp_timer_stop2
*Mar 14 21:44:26.876: htsp_timer_stop3
*Mar 14 21:44:26.876: [0/0/3] set signal state = 0x4 timestamp = 0
*Mar 14 21:44:26.876: htsp_timer

paolo bevilacqua · ‎03-14-2010

Nothing appears to be wrong.

You could try H.323 instead of MGCP as it's much more stable.

haseeb · ‎03-20-2010

I had changed to H.323 and still the same issue exists. First 3 lines are working and with 4th line it gives half ring

haseeb · ‎03-20-2010

H.323 GW debug output is as follows:

*Mar 20 08:41:59.799: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing

*Mar 20 08:41:59.799: htsp_timer - 125 msec

*Mar 20 08:41:59.927: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer

*Mar 20 08:41:59.927: htsp_timer - 10000 msec

*Mar 20 08:41:59.927: htsp_timer3 - 5600 msec

*Mar 20 08:41:59.927: [0/0/3] htsp_start_caller_id_rx:BELLCORE

*Mar 20 08:41:59.927: [0/0/3] htsp_dsm_create_success returns 1

*Mar 20 08:42:00.331: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]

*Mar 20 08:42:00.331: fxols_ringing_not

*Mar 20 08:42:00.331: htsp_timer_stop

*Mar 20 08:42:00.331: htsp_timer - 10000 msec

*Mar 20 08:42:01.519: [0/0/3] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX

*Mar 20 08:42:01.523: htsp_process_event: [0/0/3, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE]

*Mar 20 08:42:01.523: htsp_timer_stop

*Mar 20 08:42:01.523: htsp_timer_stop3

*Mar 20 08:42:01.523: [0/0/3] htsp_stop_caller_id_rx. message length 23htsp_setup_ind

*Mar 20 08:42:01.523: [0/0/3] get_fxo_caller_id:Caller ID received. Message type=128 length=23 checksum=28

*Mar 20 08:42:01.523: [0/0/3] Caller ID String 80 14 01 08 30 33 32 30 31 31 34 30 02 08 36 37 30 37 37 36 33 32 28

*Mar 20 08:42:01.523: [0/0/3] get_fxo_caller_id calling num=67077632 calling name= calling time=03/20 11:40

*Mar 20 08:42:01.523: fxols_callerid_done: call being answered

*Mar 20 08:42:01.527: htsp_process_event: [0/0/3, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]

*Mar 20 08:42:01.527: fxols_wait_setup_ack:

*Mar 20 08:42:01.527: [0/0/3] set signal state = 0xC timestamp = 0fxols_check_auto_call

*Mar 20 08:42:01.531: [0/0/3] htsp_dsm_close_done

*Mar 20 08:42:01.539: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc

*Mar 20 08:42:01.539: htsp_timer - 120000 msechtsp_alert_notify

*Mar 20 08:42:01.743: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alert

*Mar 20 08:42:01.779: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_DSP_SIG_1100]fxols_offhook_disc

*Mar 20 08:42:01.779: htsp_timer2 - 350 msechtsp_call_service_msghtsp_call_service_msg not EFXS (2)

*Mar 20 08:42:02.131: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER2]fxols_disc_confirm

*Mar 20 08:42:02.131: htsp_timer_stop

*Mar 20 08:42:02.131: htsp_timer_stop2

*Mar 20 08:42:02.131: htsp_timer_stop3

*Mar 20 08:42:02.135: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release

*Mar 20 08:42:02.135: htsp_timer_stop

*Mar 20 08:42:02.135: htsp_timer_stop2

*Mar 20 08:42:02.135: htsp_timer_stop3

*Mar 20 08:42:02.135: [0/0/3] set signal state = 0x4 timestamp = 0

*Mar 20 08:42:02.135: htsp_timer - 2000 msec

*Mar 20 08:42:02.455: htsp_process_event: [0/0/3, FXOLS_GUARD_OUT, E_DSP_SIG_0000]fxols_guard_out_ringing

*Mar 20 08:42:02.455: htsp_timer_stop fxols_onhook_ringing

*Mar 20 08:42:02.455: htsp_timer - 125 msec

*Mar 20 08:42:02.583: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer

*Mar 20 08:42:02.583: htsp_timer - 10000 msec

*Mar 20 08:42:02.583: htsp_timer3 - 5600 msec

*Mar 20 08:42:02.583: [0/0/3] htsp_start_caller_id_rx:BELLCORE

*Mar 20 08:42:02.583: [0/0/3] htsp_dsm_create_success returns 1

*Mar 20 08:42:02.891: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]

*Mar 20 08:42:02.891: fxols_ringing_not

*Mar 20 08:42:02.891: htsp_timer_stop

*Mar 20 08:42:02.895: htsp_timer - 10000 msec

*Mar 20 08:42:06.927: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0000]

*Mar 20 08:42:07.971: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]

*Mar 20 08:42:07.971: fxols_ringing_not

*Mar 20 08:42:07.971: htsp_timer_stop

*Mar 20 08:42:07.971: htsp_timer_stop3

*Mar 20 08:42:07.971: [0/0/3] htsp_stop_caller_id_rx. message length 0htsp_setup_ind

*Mar 20 08:42:07.971: [0/0/3] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.

*Mar 20 08:42:07.971: [0/0/3] get_local_station_id calling num= calling name= calling time=03/20 08:42 orig called=

*Mar 20 08:42:07.979: htsp_process_event: [0/0/3, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]

*Mar 20 08:42:07.979: fxols_wait_setup_ack:

*Mar 20 08:42:07.979: [0/0/3] set signal state = 0xC timestamp = 0fxols_check_auto_call

*Mar 20 08:42:07.987: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc

*Mar 20 08:42:07.987: htsp_timer - 120000 msec

*Mar 20 08:42:07.987: [0/0/3] htsp_dsm_close_donehtsp_alert_notify

*Mar 20 08:42:08.003: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)

*Mar 20 08:42:08.231: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_DSP_SIG_1100]fxols_offhook_disc

*Mar 20 08:42:08.231: htsp_timer2 - 350 msec

*Mar 20 08:42:08.583: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_EVENT_TIMER2]fxols_disc_confirm

*Mar 20 08:42:08.583: htsp_timer_stop

*Mar 20 08:42:08.583: htsp_timer_stop2

*Mar 20 08:42:08.583: htsp_timer_stop3

*Mar 20 08:42:08.587: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release

*Mar 20 08:42:08.587: htsp_timer_stop

*Mar 20 08:42:08.587: htsp_timer_stop2

*Mar 20 08:42:08.587: htsp_timer_stop3

*Mar 20 08:42:08.587: [0/0/3] set signal state = 0x4 timestamp = 0

*Mar 20 08:42:08.587: htsp_timer - 2000 msec

*Mar 20 08:42:10.587: htsp_process_event: [0/0/3, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout

*Mar 20 08:42:10.587: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0100]

*Mar 20 08:42:11.887: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing

*Mar 20 08:42:11.887: htsp_timer - 125 msec

*Mar 20 08:42:12.015: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer

*Mar 20 08:42:12.015: htsp_timer - 10000 msec

*Mar 20 08:42:12.015: htsp_timer3 - 5600 msec

*Mar 20 08:42:12.015: [0/0/3] htsp_start_caller_id_rx:BELLCORE

*Mar 20 08:42:12.015: [0/0/3] htsp_dsm_create_success returns 1

*Mar 20 08:42:12.935: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]

*Mar 20 08:42:12.935: fxols_ringing_not

*Mar 20 08:42:12.935: htsp_timer_stop

*Mar 20 08:42:12.935: htsp_timer - 10000 msec

*Mar 20 08:42:16.811: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0000]

*Mar 20 08:42:17.615: htsp_process_event: [0/0/3, FXOLS_RINGING, E_HTSP_EVENT_TIMER3]fxols_snoop_clid_stop

*Mar 20 08:42:17.615: htsp_timer_stop3

*Mar 20 08:42:18.015: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]

*Mar 20 08:42:18.015: fxols_ringing_not

*Mar 20 08:42:18.015: htsp_timer_stop

*Mar 20 08:42:18.015: htsp_timer_stop3

*Mar 20 08:42:18.015: [0/0/3] htsp_stop_caller_id_rx. message length 0htsp_setup_ind

*Mar 20 08:42:18.015: [0/0/3] get_fxo_caller_id:Caller ID receive failed. parseCallerIDString:no data.

*Mar 20 08:42:18.015: [0/0/3] get_local_station_id calling num= calling name= calling time=03/20 08:42 orig called=

*Mar 20 08:42:18.019: htsp_process_event: [0/0/3, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]

*Mar 20 08:42:18.023: fxols_wait_setup_ack:

*Mar 20 08:42:18.023: [0/0/3] set signal state = 0xC timestamp = 0fxols_check_auto_call

*Mar 20 08:42:18.027: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc

*Mar 20 08:42:18.027: htsp_timer - 120000 msec

*Mar 20 08:42:18.031: [0/0/3] htsp_dsm_close_donehtsp_alert_notify

*Mar 20 08:42:18.047: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_ALERT]fxols_offhook_alerthtsp_call_service_msghtsp_call_service_msg not EFXS (2)

*Mar 20 08:42:18.275: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_DSP_SIG_1100]fxols_offhook_disc

*Mar 20 08:42:18.275: htsp_timer2 - 350 msec

*Mar 20 08:42:18.531: htsp_call_bridged invokedhtsp_call_service_msghtsp_call_service_msg not EFXS (2)

*Mar 20 08:42:18.539: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_VOICE_CUT_THROUGH]fxols_proc_voice

*Mar 20 08:42:18.539: htsp_process_event: [0/0/3, FXOLS_PROCEEDING, E_HTSP_CONNECT]fxols_offhook_connect

*Mar 20 08:42:18.543: htsp_timer_stop

*Mar 20 08:42:18.627: htsp_process_event: [0/0/3, FXOLS_CONNECT, E_HTSP_EVENT_TIMER2]fxols_disc_confirm

*Mar 20 08:42:18.627: htsp_timer_stop

*Mar 20 08:42:18.627: htsp_timer_stop2

*Mar 20 08:42:18.627: htsp_timer_stop3

*Mar 20 08:42:18.651: htsp_process_event: [0/0/3, FXOLS_REMOTE_RELEASE, E_HTSP_RELEASE_REQ]fxols_offhook_release

*Mar 20 08:42:18.651: htsp_timer_stop

*Mar 20 08:42:18.651: htsp_timer_stop2

*Mar 20 08:42:18.651: htsp_timer_stop3

*Mar 20 08:42:18.651: [0/0/3] set signal state = 0x4 timestamp = 0

*Mar 20 08:42:18.651: htsp_timer - 2000 msec

*Mar 20 08:42:20.651: htsp_process_event: [0/0/3, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout

*Mar 20 08:42:20.651: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0100]

*Mar 20 08:42:21.931: htsp_process_event: [0/0/3, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing

*Mar 20 08:42:21.931: htsp_timer - 125 msec

*Mar 20 08:42:22.059: htsp_process_event: [0/0/3, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer

*Mar 20 08:42:22.059: htsp_timer - 10000 msec

*Mar 20 08:42:22.059: htsp_timer3 - 5600 msec

*Mar 20 08:42:22.059: [0/0/3] htsp_start_caller_id_rx:BELLCORE

*Mar 20 08:42:22.059: [0/0/3] htsp_dsm_create_success returns 1

*Mar 20 08:42:22.227: htsp_process_event: [0/0/3, FXOLS_RINGING, E_DSP_SIG_0100]

*Mar 20 08:42:22.227: fxols_ringing_not

*Mar 20 08:42:22.227: htsp_timer_stop

*Mar 20 08:42:22.227: htsp_timer - 10000 msec