Re: Caller ID not working on VIC2-2FXO with BT line - Page 2

pholding1 · ‎11-13-2010

I have recently setup a Cisco 1751-v router with a VIC2-2FXO card and a BT phone line, however after several attempts I am unable to successfully obtain the caller ID. The IOS version is 12.4(19).

The configuration of the voice-port is as follows

voice-port 2/0
supervisory disconnect dualtone mid-call
no comfort-noise
cptone GB
timeouts call-disconnect 5
timeouts wait-release 5
caller-id alerting dsp-pre-allocate

I have tried setting caller-id alerting to dsp-pre-allocate, line-reversal, pre-ring and ring (with the values 1, 2, 3 and 4), although each time the caller id is not obtained.

Are the caller-id alerting settings mutually exclusive? Looking at some examples on the web, it gives the impression that some configs have multiple caller-id alerting settings for the same voice port, however I am only able to set one.

The line has caller ID enabled and with an analogue phone and the clid is displayed on the second ring.

One thing I have noticed is that running show voice port 2/0 includes in the output "Caller ID Info Follows: Standard ETSI", however a google search shows that BT uses SIN227 (V23 FSK before first ring).

Has anyone successfully got caller ID working on a BT phone line with a VIC2-2FXO card? If so could you please let me know what config you are running for the voice port.

Is there anything else I can do to make this work correctly?

The output from debug vpm signal is as follows

*Nov 13 17:43:19.346 GMT: htsp_process_event: [2/0, FXOLS_ONHOOK, E_DSP_SIG_0000
]fxols_onhook_ringing
*Nov 13 17:43:19.346 GMT: htsp_timer - 125 msec
*Nov 13 17:43:19.478 GMT: htsp_process_event: [2/0, FXOLS_WAIT_RING_MIN, E_HTSP_
EVENT_TIMER]fxols_wait_ring_min_timer
*Nov 13 17:43:19.478 GMT: htsp_timer - 10000 msec
*Nov 13 17:43:20.446 GMT: htsp_process_event: [2/0, FXOLS_RINGING, E_DSP_SIG_010
0]
*Nov 13 17:43:20.446 GMT: fxols_ringing_not
*Nov 13 17:43:20.446 GMT: htsp_timer_stop
*Nov 13 17:43:20.446 GMT: htsp_timer_stop3
*Nov 13 17:43:20.446 GMT: [2/0] htsp_stop_caller_id_rx. message length 0htsp_set
up_ind
*Nov 13 17:43:20.446 GMT: [2/0] get_fxo_caller_id:Caller ID receive failed. par
seCallerIDString:no data.
*Nov 13 17:43:20.450 GMT: [2/0] get_local_station_id calling num= calling name=
calling time=11/13 17:43 orig called=
*Nov 13 17:43:20.470 GMT: [2/0] htsp_dsm_close_done
*Nov 13 17:43:20.474 GMT: htsp_process_event: [2/0, FXOLS_WAIT_SETUP_ACK, E_HTSP
_SETUP_ACK]
*Nov 13 17:43:20.474 GMT: fxols_wait_setup_ack:
*Nov 13 17:43:20.474 GMT: [2/0] set signal state = 0xC timestamp = 0fxols_check_
auto_call
*Nov 13 17:43:20.726 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_DSP_SIG_
1100]fxols_offhook_disc
*Nov 13 17:43:20.730 GMT: htsp_timer2 - 350 msec
*Nov 13 17:43:21.082 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_EVE
NT_TIMER2]fxols_disc_confirm
*Nov 13 17:43:21.082 GMT: htsp_timer_stop
*Nov 13 17:43:21.082 GMT: htsp_timer_stop2
*Nov 13 17:43:21.082 GMT: htsp_timer_stop3
*Nov 13 17:43:21.090 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_REL
EASE_REQ]fxols_offhook_release
*Nov 13 17:43:21.094 GMT: htsp_timer_stop
*Nov 13 17:43:21.094 GMT: htsp_timer_stop2
*Nov 13 17:43:21.094 GMT: htsp_timer_stop3
*Nov 13 17:43:21.094 GMT: [2/0] set signal state = 0x4 timestamp = 0
*Nov 13 17:43:21.094 GMT: htsp_timer - 2000 msec
*Nov 13 17:43:22.358 GMT: htsp_process_event: [2/0, FXOLS_GUARD_OUT, E_DSP_SIG_0
000]fxols_guard_out_ringing
*Nov 13 17:43:22.358 GMT: htsp_timer_stop fxols_onhook_ringing
*Nov 13 17:43:22.358 GMT: htsp_timer - 125 msec
*Nov 13 17:43:22.490 GMT: htsp_process_event: [2/0, FXOLS_WAIT_RING_MIN, E_HTSP_
EVENT_TIMER]fxols_wait_ring_min_timer
*Nov 13 17:43:22.490 GMT: htsp_timer - 10000 msec
*Nov 13 17:43:23.446 GMT: htsp_process_event: [2/0, FXOLS_RINGING, E_DSP_SIG_010
0]
*Nov 13 17:43:23.446 GMT: fxols_ringing_not
*Nov 13 17:43:23.446 GMT: htsp_timer_stop
*Nov 13 17:43:23.446 GMT: htsp_timer_stop3 htsp_setup_ind
*Nov 13 17:43:23.450 GMT: [2/0] get_fxo_caller_id:Caller ID receive failed. par
seCallerIDString:no data.
*Nov 13 17:43:23.450 GMT: [2/0] get_local_station_id calling num= calling name=
calling time=11/13 17:43 orig called=
*Nov 13 17:43:23.466 GMT: htsp_process_event: [2/0, FXOLS_WAIT_SETUP_ACK, E_HTSP
_SETUP_ACK]
*Nov 13 17:43:23.466 GMT: fxols_wait_setup_ack:
*Nov 13 17:43:23.466 GMT: [2/0] set signal state = 0xC timestamp = 0fxols_check_
auto_call
*Nov 13 17:43:23.722 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_DSP_SIG_
1100]fxols_offhook_disc
*Nov 13 17:43:23.722 GMT: htsp_timer2 - 350 msec
*Nov 13 17:43:24.074 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_EVE
NT_TIMER2]fxols_disc_confirm
*Nov 13 17:43:24.074 GMT: htsp_timer_stop
*Nov 13 17:43:24.074 GMT: htsp_timer_stop2
*Nov 13 17:43:24.074 GMT: htsp_timer_stop3
*Nov 13 17:43:24.082 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_REL
EASE_REQ]fxols_offhook_release
*Nov 13 17:43:24.086 GMT: htsp_timer_stop
*Nov 13 17:43:24.086 GMT: htsp_timer_stop2
*Nov 13 17:43:24.086 GMT: htsp_timer_stop3
*Nov 13 17:43:24.086 GMT: [2/0] set signal state = 0x4 timestamp = 0
*Nov 13 17:43:24.086 GMT: htsp_timer - 2000 msec
*Nov 13 17:43:25.342 GMT: htsp_process_event: [2/0, FXOLS_GUARD_OUT, E_DSP_SIG_0
000]fxols_guard_out_ringing
*Nov 13 17:43:25.346 GMT: htsp_timer_stop fxols_onhook_ringing
*Nov 13 17:43:25.346 GMT: htsp_timer - 125 msec
*Nov 13 17:43:25.474 GMT: htsp_process_event: [2/0, FXOLS_WAIT_RING_MIN, E_HTSP_
EVENT_TIMER]fxols_wait_ring_min_timer
*Nov 13 17:43:25.474 GMT: htsp_timer - 10000 msec
*Nov 13 17:43:26.446 GMT: htsp_process_event: [2/0, FXOLS_RINGING, E_DSP_SIG_010
0]
*Nov 13 17:43:26.446 GMT: fxols_ringing_not
*Nov 13 17:43:26.446 GMT: htsp_timer_stop
*Nov 13 17:43:26.446 GMT: htsp_timer_stop3 htsp_setup_ind
*Nov 13 17:43:26.446 GMT: [2/0] get_fxo_caller_id:Caller ID receive failed. par
seCallerIDString:no data.
*Nov 13 17:43:26.446 GMT: [2/0] get_local_station_id calling num= calling name=
calling time=11/13 17:43 orig called=
*Nov 13 17:43:26.462 GMT: htsp_process_event: [2/0, FXOLS_WAIT_SETUP_ACK, E_HTSP
_SETUP_ACK]
*Nov 13 17:43:26.466 GMT: fxols_wait_setup_ack:
*Nov 13 17:43:26.466 GMT: [2/0] set signal state = 0xC timestamp = 0fxols_check_
auto_call
*Nov 13 17:43:26.718 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_DSP_SIG_
1100]fxols_offhook_disc
*Nov 13 17:43:26.718 GMT: htsp_timer2 - 350 msec
*Nov 13 17:43:27.074 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_EVE
NT_TIMER2]fxols_disc_confirm
*Nov 13 17:43:27.074 GMT: htsp_timer_stop
*Nov 13 17:43:27.074 GMT: htsp_timer_stop2
*Nov 13 17:43:27.074 GMT: htsp_timer_stop3
*Nov 13 17:43:27.082 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_REL
EASE_REQ]fxols_offhook_release
*Nov 13 17:43:27.086 GMT: htsp_timer_stop
*Nov 13 17:43:27.086 GMT: htsp_timer_stop2
*Nov 13 17:43:27.086 GMT: htsp_timer_stop3
*Nov 13 17:43:27.086 GMT: [2/0] set signal state = 0x4 timestamp = 0
*Nov 13 17:43:27.086 GMT: htsp_timer - 2000 msec
*Nov 13 17:43:28.342 GMT: htsp_process_event: [2/0, FXOLS_GUARD_OUT, E_DSP_SIG_0
000]fxols_guard_out_ringing
*Nov 13 17:43:28.342 GMT: htsp_timer_stop fxols_onhook_ringing
*Nov 13 17:43:28.342 GMT: htsp_timer - 125 msec
*Nov 13 17:43:28.470 GMT: htsp_process_event: [2/0, FXOLS_WAIT_RING_MIN, E_HTSP_
EVENT_TIMER]fxols_wait_ring_min_timer
*Nov 13 17:43:28.470 GMT: htsp_timer - 10000 msec
*Nov 13 17:43:29.454 GMT: htsp_process_event: [2/0, FXOLS_RINGING, E_DSP_SIG_010
0]
*Nov 13 17:43:29.458 GMT: fxols_ringing_not
*Nov 13 17:43:29.458 GMT: htsp_timer_stop
*Nov 13 17:43:29.458 GMT: htsp_timer_stop3 htsp_setup_ind
*Nov 13 17:43:29.458 GMT: [2/0] get_fxo_caller_id:Caller ID receive failed. par
seCallerIDString:no data.
*Nov 13 17:43:29.458 GMT: [2/0] get_local_station_id calling num= calling name=
calling time=11/13 17:43 orig called=
*Nov 13 17:43:29.474 GMT: htsp_process_event: [2/0, FXOLS_WAIT_SETUP_ACK, E_HTSP
_SETUP_ACK]
*Nov 13 17:43:29.478 GMT: fxols_wait_setup_ack:
*Nov 13 17:43:29.478 GMT: [2/0] set signal state = 0xC timestamp = 0fxols_check_
auto_call
*Nov 13 17:43:29.730 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_DSP_SIG_
1100]fxols_offhook_disc
*Nov 13 17:43:29.730 GMT: htsp_timer2 - 350 msec
*Nov 13 17:43:30.082 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_EVE
NT_TIMER2]fxols_disc_confirm
*Nov 13 17:43:30.082 GMT: htsp_timer_stop
*Nov 13 17:43:30.082 GMT: htsp_timer_stop2
*Nov 13 17:43:30.082 GMT: htsp_timer_stop3
*Nov 13 17:43:30.090 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_REL
EASE_REQ]fxols_offhook_release
*Nov 13 17:43:30.090 GMT: htsp_timer_stop
*Nov 13 17:43:30.090 GMT: htsp_timer_stop2
*Nov 13 17:43:30.094 GMT: htsp_timer_stop3
*Nov 13 17:43:30.094 GMT: [2/0] set signal state = 0x4 timestamp = 0
*Nov 13 17:43:30.094 GMT: htsp_timer - 2000 msec
*Nov 13 17:43:31.342 GMT: htsp_process_event: [2/0, FXOLS_GUARD_OUT, E_DSP_SIG_0
000]fxols_guard_out_ringing
*Nov 13 17:43:31.342 GMT: htsp_timer_stop fxols_onhook_ringing
*Nov 13 17:43:31.342 GMT: htsp_timer - 125 msec
*Nov 13 17:43:31.470 GMT: htsp_process_event: [2/0, FXOLS_WAIT_RING_MIN, E_HTSP_
EVENT_TIMER]fxols_wait_ring_min_timer
*Nov 13 17:43:31.470 GMT: htsp_timer - 10000 msec
*Nov 13 17:43:32.446 GMT: htsp_process_event: [2/0, FXOLS_RINGING, E_DSP_SIG_010
0]
*Nov 13 17:43:32.446 GMT: fxols_ringing_not
*Nov 13 17:43:32.446 GMT: htsp_timer_stop
*Nov 13 17:43:32.446 GMT: htsp_timer_stop3 htsp_setup_ind
*Nov 13 17:43:32.446 GMT: [2/0] get_fxo_caller_id:Caller ID receive failed. par
seCallerIDString:no data.
*Nov 13 17:43:32.446 GMT: [2/0] get_local_station_id calling num= calling name=
calling time=11/13 17:43 orig called=
*Nov 13 17:43:32.466 GMT: htsp_process_event: [2/0, FXOLS_WAIT_SETUP_ACK, E_HTSP
_SETUP_ACK]
*Nov 13 17:43:32.466 GMT: fxols_wait_setup_ack:
*Nov 13 17:43:32.466 GMT: [2/0] set signal state = 0xC timestamp = 0fxols_check_
auto_call
*Nov 13 17:43:32.722 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_DSP_SIG_
1100]fxols_offhook_disc
*Nov 13 17:43:32.722 GMT: htsp_timer2 - 350 msec
*Nov 13 17:43:33.074 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_EVE
NT_TIMER2]fxols_disc_confirm
*Nov 13 17:43:33.074 GMT: htsp_timer_stop
*Nov 13 17:43:33.074 GMT: htsp_timer_stop2
*Nov 13 17:43:33.074 GMT: htsp_timer_stop3
*Nov 13 17:43:33.082 GMT: htsp_process_event: [2/0, FXOLS_PROCEEDING, E_HTSP_REL
EASE_REQ]fxols_offhook_release
*Nov 13 17:43:33.086 GMT: htsp_timer_stop
*Nov 13 17:43:33.086 GMT: htsp_timer_stop2
*Nov 13 17:43:33.086 GMT: htsp_timer_stop3
*Nov 13 17:43:33.086 GMT: [2/0] set signal state = 0x4 timestamp = 0
*Nov 13 17:43:33.086 GMT: htsp_timer - 2000 msec
*Nov 13 17:43:35.086 GMT: htsp_process_event: [2/0, FXOLS_GUARD_OUT, E_HTSP_EVEN
T_TIMER]fxols_guard_out_timeout
*Nov 13 17:43:35.086 GMT: fxols_dsp_prealloc_clid_wait. Line reversal alerting D
SP preallocation done
*Nov 13 17:43:35.086 GMT: [2/0] htsp_start_caller_id_rx:ETSI
*Nov 13 17:43:35.090 GMT: [2/0] htsp_dsm_create_success returns 1
*Nov 13 17:43:35.090 GMT: [2/0] htsp_dsm_is_sig_done_cb
*Nov 13 17:43:35.094 GMT: htsp_process_event: [2/0, FXOLS_ONHOOK, E_DSP_SIG_0100

pholding1 · ‎11-23-2010

Hi Dilip, hopefully third time lucky. I've done another capture writing the file to flash rather directly to an FTP server. I've uploaded a copy of the pcm capture file and the output of debug vpm signal.

dksingh · ‎11-23-2010

Hey Paul,

Same thing with this capture as well....weird!

Can u pl. remove all commands from the FXO port

except cptone GB and try one more capture?

Pl. make sure to shut/no shut the port after making

config changes.

Thx.

DK

pholding1 · ‎11-23-2010

Hi Dilip,

Hopefully this capture will contain the streams. I've removed all of the commands from the voice port, although for some reason I'm unable to remove the impedence command. I've tried no impedance, no impedance complex2 and default impedance. The current config for the voice port is

voice-port 2/0
cptone GB
impedance complex2

Felipe Garrido · ‎11-23-2010

Paul,

I was able to decode the PCM capture, had to use an older version of the decoding software, but I still don't see a valid call. I see capture but all of them are less than a second in length. At this point, I would advise that you open a TAC SR to continue troubleshooting.

-Felipe

pholding1 · ‎11-23-2010

Hi Felipe/Dilip

The GW is used in a home lab for studying so I'm not able to raise a TAC SR.

It did occur to me that maybe I wasn't leaving enough time between starting the pcm capture, placing the call and then disabling the pcm capture. Could you please have a look at the attached capture to see whether the capture contains a valid call. This capture has been done using test voice port 2/0 pcm-dump caplog 7 duration 30

I'm using debug vpm signal to look for a see when the GW see the incoming call and when the GW sees the call terminate. Are there any other debugs I can run that will indicate when the capture is starting to record the call or contains the rtp streams?

Many Thanks

pholding1 · ‎11-23-2010

Forgot to upload the file ....

paolo bevilacqua · ‎11-26-2010

I have seen this happening so many times, and I know that you can go around and around without ever finding a solution.

In my opinion it's as simple as that - DSP firmware is buggy and cannot receive Caller ID in some cases.

pholding1 · ‎11-29-2010

Sorry to keep pushing this but would one of the guys from Cisco be able to analyse the latest PCM capture file I’ve uploaded (post 20) to see if the caller id tones are being transmitted. I’ve purchased a VIC2-2FXO card to replace and existing VIC-2FXO specifically to obtain the caller id, so I’m keen to get this new feature working.

Aside from using debug vpm signal, are there any other debugs I can run that will indicate when the capture is starting to record the call or contains the rtp streams?

Regarding the DSPWare, I’ve done a show voice dsp which reports the type is C549 and the version is 4.4.32. From various Google searches I believe that generally speaking the DSPWare image is embedded in the IOS, however is does appear to be possible to upload a later version of the DSPWare image to flash, which will be used in place of the version embedded in the IOS.

As I’m running 12.4(25c) IOS which is the latest IOS available for the mainline train that’s supported by a 1751-v gateway, does anyone know if 12.4T includes an updated DSPWare image?

If not, is version 4.4.32 the latest version available for C549?

Aside from raising a TAC SR, are there any other options I can investigate.

Many Thanks

paolo bevilacqua · ‎11-29-2010

Sorry to keep pushing this but would one of the guys from Cisco be able to analyse the latest PCM capture file I’ve uploaded (post 20) to see if the caller id tones are being transmitted.

It's not that difficult to find if tones are transmitted. You connect a regular phone with clid display to find out.

Chances are, the phone will recognize clid, while the router doesn't.

If you want 100% reliable clid and business-level call experience, use isdn bri.

pholding1 · ‎12-01-2010

Would anyone from Cisco be able to take a look at the PCM capture file in post 20 for me please.

Also does IOS version 12.4(15)T9 include a newer version of DSPWare than is available with IOS version 12.4(25c)?

pholding1 · ‎12-08-2010

Sorry to keep going on about the same issue but I’m hoping with some persistence the gateway can be made to obtain the caller-id of an incoming call.

In an attempt to rule out there being a problem with the IOS and DSPWare version I’ve changed the IOS on the gateway to 12.4(15)T9 and sh voice dsp reports that the DSPWare version is now 9.4.9 whereas with the mainline train IOS I was using the DSPWare version was 4.4.32.

I’ve made several test calls to the gateway trying each of the caller-id alerting options, however the gateway still fails to obtain the caller-id. I’ve attached another PCM capture which I’m hoping someone from Cisco would be kind enough to analyze and confirm whether the tones are being received by the gateway.

Out of interest what would be the typical size of a PCM capture that contains the hpi log and the 3 rtp streams? I’ve tried to obtain PCM captures in the past but for some reason the 3 rtp steams weren’t being recorded. If I know what size the file should be, I can continue testing with the gateway until a capture is created that’s roughly the right size before uploading it.

I’m tempted to try the VIC2-2FXO card in a Cisco 2811 router but I’d need to obtain a PVDM2 module first however I’m reluctant to do it if I’m throwing money at a lost cause.

infrastructureservices · ‎06-10-2013

Evening Paul,

Did you every get a resolution to this, I'm spent a couple of days googling and labbing to no avail?

Kind Regards

Jonathan

pholding1 · ‎11-29-2010

Sorry, guess I should have said received by the gateway and then interpreted by the DSP. Presumably if the PCM capture includes the tones then it will indicate that the DSP is failing to convert the tones into a caller id, or if the tones aren't present in the capture it will indicate that the tones are transmitted before the DSP sees the incoming call. Either way I'm not sure it will solve the problem but at least it will get me one step closer to fixing it.

I know the caller id is being transmitted as the number is displayed when I connect an analogue phone to the PSTN line.

As the gateway is part of my home lab, ISDN would be way too costly and I couldn't justify the monthly expense.

paolo bevilacqua · ‎11-29-2010

I whish you good luck. I rarely have seen resolution in these cases.

Fortunately it's a lab only, so no irate customers.