Continuous noise with background of fast busy on FXO Lines
hi, i really appreciate if you can help me with the problem in this scenario.
IP Phone<------>CUCM<-------->Router<-------->PSTN
ip phone is registered via SCCP Protocol in CUCM 8.6.1
The IOS version of router is c2800nm-adventerprisek9-mz.124-24.T.bin
the model of router is 2811 containing one 2-16 PVDM with 2 VIC2-4FXO modules.
CUCM and router are connected via H.323.
the problem is: when the ip phone tries to call a PSTN after dialing the number
the phone shows connected state in the LCD and it plays continuous loud noise
with the background of fast busy(i checked that it get stuck on router)
when i dial from PSTN the call comes to the router and it successfully diverts the call
to the defined DN of ip phone with connection plar and the phone rings but when i hangup
a call again it plays continuous loud noise with the background of fast busy.
i suspect the signaling or codec mismatch.
here is the configuration of router:
!
voice call send-alert
voice rtp send-recv
!
voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
redirect ip2ip
fax protocol cisco
h323
no h225 timeout keepalive
!
voice class codec 1
codec preference 1 g711ulaw
codec preference 2 g711alaw
codec preference 3 g729r8
!
voice class h323 1
h225 timeout tcp establish 3
h225 timeout setup 2
call start fast
!
voice-card 0
!
interface FastEthernet0/0
ip address 10.1.1.17 255.255.255.0
duplex auto
speed auto
h323-gateway voip interface
h323-gateway voip bind srcaddr 10.1.1.17
!
voice-port 0/0/0
groundstart auto-tip delay 2
signal groundStart
connection plar 100
caller-id enable
!
dial-peer voice 1 pots
description outgoing-PSTN
destination-pattern 9.T
port 0/0/0
!
dial-peer voice 2 pots
description incoming-PSTN
incoming called-number .
port 0/0/0
!
dial-peer voice 9 voip
description outgoing-CUCM
destination-pattern 1..
session target ipv4:10.1.1.14
dtmf-relay h245-alphanumeric
codec g711ulaw
no vad
!
gateway
timer receive-rtp 1200
====================================
also here's a debug output:
router#debug vpm all
Sep 26 10:58:50.947: htsp_timer_stop3 htsp_setup_req
*Sep 26 10:58:50.951: htsp_process_event: [0/1/3, FXOGS_ONHOOK, E_HTSP_SETUP_REQ]fxogs_onhook_setup
*Sep 26 10:58:50.951: [0/1/3] set signal state = 0x0 timestamp = 0
*Sep 26 10:58:50.951: dsp_set_sig_state: [0/1/3] packet_len=12 channel_id=135 packet_id=39 state=0x0 timestamp=0x0
*Sep 26 10:58:50.951: TGRM: reg_invoke_tgrm_call_update(0, 1, 3, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
*Sep 26 10:58:50.951: htsp_timer - 10000 msec
*Sep 26 10:58:51.095: htsp_process_event: [0/1/3, FXOGS_WAIT_TIP_GROUND, E_DSP_SIG_0100]fxogs_start_dial
*Sep 26 10:58:51.095: htsp_timer_stop
*Sep 26 10:58:51.095: [0/1/3] set signal state = 0xC timestamp = 0
*Sep 26 10:58:51.095: dsp_set_sig_state: [0/1/3] packet_len=12 channel_id=135 packet_id=39 state=0xC timestamp=0x0
*Sep 26 10:58:51.095: htsp_timer - 1000 msec
*Sep 26 10:58:52.095: htsp_process_event: [0/1/3, FXOGS_WAIT_DIAL_TONE, E_HTSP_EVENT_TIMER]fxogs_wait_dial_timer htsp_dial
*Sep
26 10:58:54.347: htsp_process_event: [0/1/3, FXOGS_WAIT_DIAL_DONE,
E_DSP_DIALING_DONE]fxogs_wait_dial_donehtsp_connect: no_offhook 0
call_connected 0htsp_alert
*Sep 26 10:58:54.347: htsp_timer - 350 msec
*Sep 26 10:58:54.347: htsp_process_event: [0/1/3, FXOGS_WAIT_CUT_THRU, E_HTSP_CONNECT]
*Sep 26 10:58:54.347: [0/1/3, FXOGS_WAIT_CUT_THRU, E_HTSP_CONNECT] -> ERROR: INVALID INPUT
*Sep 26 10:58:54.347: htsp_call_bridged invoked
*Sep 26 10:58:54.375: mars_flex_dsprm_current_codec_comp:DSP:0 FLEX Complexity Codec
*Sep 26 10:58:54.375: flex_dsprm_forking_mixing_support:
*Sep 26 10:58:54.379: htsp_process_event: [0/1/3, FXOGS_WAIT_CUT_THRU, E_HTSP_VOICE_CUT_THROUGH]fxogs_handle_cut_thru
*Sep 26 10:58:54.379: htsp_timer_stop
*Sep 26 10:58:54.379: dsp_req_sig_state: [0/1/3] packet_len=8 channel_id=135 packet_id=40
*Sep 26 10:58:54.379: htsp_process_event: [0/1/3, FXOGS_OFFHOOK, E_DSP_SIG_0100]
*Sep 26 10:58:54.379: fxogs_stop_disc_timer
*Sep 26 10:58:54.383: htsp_timer_stop2
*Sep 26 10:58:58.707: htsp_timer_stop3 htsp_release_req: cause 16, no_onhook 0
*Sep 26 10:58:58.731: htsp_process_event: [0/1/3, FXOGS_OFFHOOK, E_HTSP_RELEASE_REQ]fxogs_offhook_release
*Sep 26 10:58:58.731: htsp_timer_stop
*Sep 26 10:58:58.731: htsp_timer_stop2
*Sep 26 10:58:58.731: htsp_timer_stop3
*Sep 26 10:58:58.731: [0/1/3] set signal state = 0x4 timestamp = 0
*Sep 26 10:58:58.731: dsp_set_sig_state: [0/1/3] packet_len=12 channel_id=135 packet_id=39 state=0x4 timestamp=0x0
*Sep 26 10:58:58.731: htsp_timer - 2000 msec
*Sep 26 10:59:00.731: htsp_process_event: [0/1/3, FXOGS_WAIT_ONHOOK, E_HTSP_EVENT_TIMER]fxogs_waitonhook_timer
*Sep 26 10:59:00.731: htsp_timer_stop
*Sep 26 10:59:00.731: dsp_req_sig_state: [0/1/3] packet_len=8 channel_id=135 packet_id=40
*Sep 26 10:59:00.731: TGRM: reg_invoke_tgrm_call_update(0, 1, 3, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
*Sep 26 10:59:00.731: TGRM: reg_invoke_tgrm_call_update(0, 1, 3, 65535, 1, TGRM_CALL_BUSY, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
*Sep 26 10:59:00.731: TGRM: reg_invoke_tgrm_call_update(0, 1, 3, 65535, 1, TGRM_CALL_IDLE, TGRM_CALL_VOICE, TGRM_DIRECTION_OUT)
*Sep 26 10:59:00.735: htsp_process_event: [0/1/3, FXOGS_PARK, E_DSP_SIG_1100]
*Sep 26 10:59:00.735: fxogs_no_tipgnd
*Sep 26 10:59:00.735: htsp_timer_stop
*Sep 26 10:59:00.735: htsp_timer_stop2
*Sep 26 10:59:00.735: htsp_timer2 - 350 msec
*Sep 26 10:59:00.735: flex_dsprm_close_cleanup
*Sep 26 10:59:01.087: htsp_process_event: [0/1/3, FXOGS_PARK, E_HTSP_EVENT_TIMER2]fxogs_park_onhook
==============================================
Router#debug voip ccapi inout
*Sep 26 11:00:04.867: //-1/003D5DC84E00/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=130
----- ccCallInfo IE subfields -----
cisco-ani=130
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=909125026198
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
cisco-rdntype=-1
cisco-rdnplan=-1
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
*Sep 26 11:00:04.871: //-1/003D5DC84E00/CCAPI/cc_api_call_setup_ind_common:
Interface=0x49DC5EC8, Call Info(
Calling Number=130,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=909125026198(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=9, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=186
*Sep 26 11:00:04.871: //-1/003D5DC84E00/CCAPI/ccCheckClipClir:
In: Calling Number=130(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 26 11:00:04.871: //-1/003D5DC84E00/CCAPI/ccCheckClipClir:
Out: Calling Number=130(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 26 11:00:04.871: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Sep 26 11:00:04.871: :cc_get_feature_vsa malloc success
*Sep 26 11:00:04.871: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Sep 26 11:00:04.871: cc_get_feature_vsa count is 1
*Sep 26 11:00:04.871: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Sep 26 11:00:04.871: :FEATURE_VSA attributes are: feature_name:0,feature_time:1256013808,feature_id:126
*Sep 26 11:00:04.871: //186/003D5DC84E00/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=130(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=909125026198(TON=Unknown, NPI=Unknown))
*Sep 26 11:00:04.871: //186/003D5DC84E00/CCAPI/cc_process_call_setup_ind:
Event=0x4A4F9B68
*Sep 26 11:00:04.875: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 909125026198
*Sep 26 11:00:04.875: //186/003D5DC84E00/CCAPI/ccCallSetContext:
Context=0x4AD4DD94
*Sep 26 11:00:04.875: //186/003D5DC84E00/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 186 with tag 9 to app "_ManagedAppProcess_Default"
*Sep 26 11:00:04.875: //186/003D5DC84E00/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Sep 26 11:00:04.879: //186/003D5DC84E00/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=1, Params=0x4AD503F4, Progress Indication=NULL(0)
*Sep 26 11:00:04.879: //186/003D5DC84E00/CCAPI/ccCheckClipClir:
In: Calling Number=130(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 26 11:00:04.879: //186/003D5DC84E00/CCAPI/ccCheckClipClir:
Out: Calling Number=130(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 26 11:00:04.879: //186/003D5DC84E00/CCAPI/ccCallSetupRequest:
Destination Pattern=9.T, Called Number=909125026198, Digit Strip=TRUE
*Sep 26 11:00:04.879: //186/003D5DC84E00/CCAPI/ccCallSetupRequest:
Calling Number=130(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=909125026198(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=130, Final Destination Flag=TRUE,
Guid=003D5DC8-0B17-4124-4E00-A0010A01016A, Outgoing Dial-peer=1
*Sep 26 11:00:04.879: //186/003D5DC84E00/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=130
----- ccCallInfo IE subfields -----
cisco-ani=130
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=909125026198
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
cisco-rdntype=-1
cisco-rdnplan=-1
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0
*Sep 26 11:00:04.879: //186/003D5DC84E00/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x4A54E7EC, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=130,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=909125026198(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Sep 26 11:00:04.879: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Sep 26 11:00:04.879: :cc_get_feature_vsa malloc success
*Sep 26 11:00:04.879: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Sep 26 11:00:04.879: cc_get_feature_vsa count is 2
*Sep 26 11:00:04.883: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Sep 26 11:00:04.883: :FEATURE_VSA attributes are: feature_name:0,feature_time:1256013584,feature_id:127
*Sep 26 11:00:04.883: //187/003D5DC84E00/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Sep 26 11:00:04.883: //187/003D5DC84E00/CCAPI/ccCallSetContext:
Context=0x4AD503A4
*Sep 26 11:00:04.883: //186/003D5DC84E00/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=1
*Sep 26 11:00:04.887: //187/003D5DC84E00/CCAPI/cc_api_call_proceeding:
Interface=0x4A54E7EC, Progress Indication=NULL(0)
*Sep 26 11:00:08.287: //187/003D5DC84E00/CCAPI/cc_api_call_alert:
Interface=0x4A54E7EC, Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1)
*Sep 26 11:00:08.287: //187/003D5DC84E00/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Sep 26 11:00:08.291: //186/003D5DC84E00/CCAPI/ccCallAlert:
Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1)
*Sep 26 11:00:08.291: //186/003D5DC84E00/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, Alert Sent=TRUE)
*Sep 26 11:00:08.291: //187/003D5DC84E00/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Sep 26 11:00:08.291: //186/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x49E63564, callID1=0xBA, callID2=0xBB, tag=0x0)
*Sep 26 11:00:08.291: //186/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x49E63564, callID1=0xBA, gcid=0-0-0-0, tag=0x0)
*Sep 26 11:00:08.291: //187/xxxxxxxxxxxx/CCAPI/ccConferenceCreate:
(confID=0x49E63564, callID2=0xBB, gcid=0-0-0-0, tag=0x0)
*Sep 26 11:00:08.291: //186/003D5DC84E00/CCAPI/ccConferenceCreate:
Conference Id=0x49E63564, Call Id1=186, Call Id2=187, Tag=0x0
*Sep 26 11:00:08.291: //186/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:
*Sep 26 11:00:08.291: cc_api_get_xcode_stream : 4534
*Sep 26 11:00:08.291: //186/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0x37, Source Interface=0x49DC5EC8, Source Call Id=186,
Destination Call Id=187, Disposition=0x0, Tag=0x0
*Sep 26 11:00:08.291: //187/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done:
Conference Id=0x37, Source Interface=0x4A54E7EC, Source Call Id=187,
Destination Call Id=186, Disposition=0x0, Tag=0xFFFFFFFF
*Sep 26 11:00:08.291: //186/003D5DC84E00/CCAPI/cc_generic_bridge_done:
Conference Id=0x37, Source Interface=0x4A54E7EC, Source Call Id=187,
Destination Call Id=186, Disposition=0x0, Tag=0xFFFFFFFF
*Sep 26 11:00:08.295: //186/003D5DC84E00/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x37, Destination Call Id=187)
*Sep 26 11:00:08.295: //187/003D5DC84E00/CCAPI/ccConferenceCreate:
Call Entry(Conference Id=0x37, Destination Call Id=186)
*Sep 26 11:00:08.295: //187/003D5DC84E00/CCAPI/cc_api_caps_ind:
Destination Interface=0x49DC5EC8, Destination Call Id=186, Source Call Id=187,
Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1,
Modem=0x2, Codec Bytes=20, Signal Type=3)
*Sep 26 11:00:08.295: //187/003D5DC84E00/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=1000(ms), Fax Nom=300(ms))
*Sep 26 11:00:08.295: //186/003D5DC84E00/CCAPI/cc_api_get_delay_xport:
CallInfo(delay xport=FALSE)
*Sep 26 11:00:08.299: //186/003D5DC84E00/CCAPI/cc_process_notify_bridge_done:
Conference Id=0x37, Call Id1=186, Call Id2=187
*Sep 26 11:00:08.299: //186/003D5DC84E00/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=186
*Sep 26 11:00:08.299: //187/003D5DC84E00/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Sep 26 11:00:08.315: //186/003D5DC84E00/CCAPI/cc_api_caps_ind:
Destination Interface=0x4A54E7EC, Destination Call Id=187, Source Call Id=186,
Caps(Codec=0x1, Fax Rate=0x2, Vad=0x2,
Modem=0x0, Codec Bytes=160, Signal Type=2)
*Sep 26 11:00:08.315: //186/003D5DC84E00/CCAPI/cc_api_caps_ind:
Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
Playout Max=1000(ms), Fax Nom=300(ms))
*Sep 26 11:00:08.315: //186/003D5DC84E00/CCAPI/cc_api_caps_ack:
Destination Interface=0x4A54E7EC, Destination Call Id=187, Source Call Id=186,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=719)
*Sep 26 11:00:08.319: //187/003D5DC84E00/CCAPI/cc_api_caps_ack:
Destination Interface=0x49DC5EC8, Destination Call Id=186, Source Call Id=187,
Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),
Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=719)
*Sep 26 11:00:08.319: //187/003D5DC84E00/CCAPI/cc_api_voice_mode_event:
Call Id=187
*Sep 26 11:00:08.323: //187/003D5DC84E00/CCAPI/cc_api_voice_mode_event:
Call Entry(Context=0x4AD503A4)
*Sep 26 11:00:08.323: //187/003D5DC84E00/CCAPI/cc_api_call_connected:
Interface=0x4A54E7EC, Data Bitmask=0x1, Progress Indication=DESTINATION IS NON ISDN(2),
Connection Handle=0
*Sep 26 11:00:08.323: //187/003D5DC84E00/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Sep 26 11:00:08.323: //186/003D5DC84E00/CCAPI/ccCallConnect:
Progress Indication=DESTINATION IS NON ISDN(2), Data Bitmask=0x1
*Sep 26 11:00:08.327: //187/003D5DC84E00/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Sep 26 11:00:08.327: //186/003D5DC84E00/CCAPI/ccCallConnect:
Call Entry(Connected=TRUE, Responsed=TRUE)
*Sep 26 11:00:08.327: //186/003D5DC84E00/CCAPI/ccCallNotify:
Data Bitmask=0x7, Call Id=186
*Sep 26 11:00:08.327: //187/003D5DC84E00/CCAPI/cc_api_get_called_ccm_detected:
CallInfo(ccm detected=0)
*Sep 26 11:00:11.207: //186/003D5DC84E00/CCAPI/cc_api_call_disconnected:
Cause Value=16, Interface=0x49DC5EC8, Call Id=186
*Sep 26 11:00:11.207: //186/003D5DC84E00/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
*Sep 26 11:00:11.207: //186/003D5DC84E00/CCAPI/ccConferenceDestroy:
Conference Id=0x37, Tag=0x0
*Sep 26 11:00:11.207: //186/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x37, Source Interface=0x49DC5EC8, Source Call Id=186,
Destination Call Id=187, Disposition=0x0, Tag=0x0
*Sep 26 11:00:11.207: //187/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done:
Conference Id=0x37, Source Interface=0x4A54E7EC, Source Call Id=187,
Destination Call Id=186, Disposition=0x0, Tag=0x0
*Sep 26 11:00:11.207: //186/003D5DC84E00/CCAPI/cc_generic_bridge_done:
Conference Id=0x37, Source Interface=0x4A54E7EC, Source Call Id=187,
Destination Call Id=186, Disposition=0x0, Tag=0x0
*Sep 26 11:00:11.211: //186/003D5DC84E00/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
*Sep 26 11:00:11.211: //186/003D5DC84E00/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Sep 26 11:00:11.211: //186/003D5DC84E00/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Sep 26 11:00:11.211: //187/003D5DC84E00/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Sep 26 11:00:11.211: //187/003D5DC84E00/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Sep 26 11:00:11.211: //187/003D5DC84E00/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Sep 26 11:00:11.227: //186/003D5DC84E00/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Sep 26 11:00:11.231: //186/003D5DC84E00/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x49DC5EC8, Tag=0x0, Call Id=186,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Sep 26 11:00:11.231: //186/003D5DC84E00/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Sep 26 11:00:11.231: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Sep 26 11:00:11.231: :cc_free_feature_vsa freeing 4ADD3FE8
*Sep 26 11:00:11.231: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Sep 26 11:00:11.231: vsacount in free is 1
*Sep 26 11:00:13.239: //187/003D5DC84E00/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x4A54E7EC, Tag=0x0, Call Id=187,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Sep 26 11:00:13.239: //187/003D5DC84E00/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Sep 26 11:00:13.239: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Sep 26 11:00:13.239: :cc_free_feature_vsa freeing 4ADD3F08
*Sep 26 11:00:13.243: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Sep 26 11:00:13.243: vsacount in free is 0
====================
router#debug rtpspi all
*Sep 26 11:02:09.535: rtpspi_process_timers: Timer 0x483DE2E8 expired.
*Sep 26 11:02:09.535: rtpspi_process_timers: timer expired for type(0x6): RTP_GLOBAL_INACTIVITY_TIMER
*Sep 26 11:02:09.535: rtpspi_handle_rtp_global_timer_expiry: Entered
*Sep 26 11:02:09.535: rtpspi_handle_rtp_global_timer_expiry: rtpspi_count_ccb_with_rtptimeout:0 Nothing to do
*Sep 26 11:02:09.535: rtpspi_start_rtp_global_timer
*Sep 26 11:02:31.535: :rtp_udp_unreachable:Entered: ICMP unreachable for dest port16971
=================================
router#show call active voice brief
<ID>:
<CallID> <start>ms.<index> +<connect>
pid:<peer_id> <dir> <addr> <state>
dur hh:mm:ss tx:<packets>/<bytes> rx:<packets>/<bytes>
IP <ip>:<udp> rtt:<time>ms pl:<play>/<gap>ms lost:<lost>/<early>/<late>
delay:<last>/<min>/<max>ms <codec>
media inactive detected:<y/n> media cntrl rcvd:<y/n> timestamp:<time>
long duration call detected:<y/n> long duration call duration :<sec> timestamp:<time>
MODEMPASS <method> buf:<fills>/<drains> loss <overall%> <multipkt>/<corrected>
last <buf event time>s dur:<Min>/<Max>s
FR <protocol> [int dlci cid] vad:<y/n> dtmf:<y/n> seq:<y/n>
<codec> (payload size)
ATM <protocol> [int vpi/vci cid] vad:<y/n> dtmf:<y/n> seq:<y/n>
<codec> (payload size)
Tele <int> (callID) [channel_id]
tx:<tot>/<v>/<fax>ms <codec> noise:<l>
acom:<l> i/o:<l>/<l> dBm
MODEMRELAY
info:<rcvd>/<sent>/<resent>
xid:<rcvd>/<sent>
total:<rcvd>/<sent>/<drops>
speeds(bps): local <rx>/<tx> remote <rx>/<tx>
Proxy <ip>:<audio udp>,<video
udp>,<tcp0>,<tcp1>,<tcp2>,<tcp3> endpt:
<type>/<manf>
bw: <req>/<act> codec: <audio>/<video>
tx: <audio pkts>/<audio bytes>,<video pkts>/<video bytes>,<t120 pkts>/<t120 bytes>
rx: <audio pkts>/<audio bytes>,<video pkts>/<video bytes>,<t120 pkts>/<t120 bytes>
Telephony call-legs: 1
SIP call-legs: 0
H323 call-legs: 1
Call agent controlled call-legs: 0
SCCP call-legs: 0
Multicast call-legs: 0
Total call-legs: 2
1324 : 197 11159430ms.1 +3440 pid:9 Answer 130 active
dur 00:01:08 tx:3436/549760 rx:3434/549440
IP 10.1.1.106:26628 SRTP: off rtt:0ms pl:66810/0ms lost:0/0/0 delay:55/55/65ms g711ulaw TextRelay: off
media inactive detected:n media contrl rcvd:n/a timestamp:n/a
long duration call detected:n long duration call duration:n/a timestamp:n/a
1324 : 198 11159440ms.1 +3420 pid:1 Originate 909125026198 active
dur 00:01:08 tx:3434/576912 rx:3437/549920
Tele 0/1/3 (198) [0/1/3] tx:68740/68740/0ms g711ulaw noise:0 acom:6 i/0:-3/-82 dBm
Telephony call-legs: 1
SIP call-legs: 0
H323 call-legs: 1
Call agent controlled call-legs: 0
SCCP call-legs: 0
Multicast call-legs: 0
Total call-legs: 2
Comments
Can you tell me what would happen if you connect the POTS service to an analogue handset and make a test call?
i can successfully make a call to any number,outgoing to and incomming from analog phone without any problem
If you can make and receive calls when connecting the POTS service to an analogue phone without any issues (e.g. noise) then the issue might be on your card or FXO port settings. With regards to the FXO settings it really depends on which country you are in. For example in Australia, this is the FXO settings.
voice-port 0/1/1
supervisory disconnect dualtone mid-call
signal loopstart
compand-type a-law
no comfort-noise
cptone AU
timeouts interdigit 3
timeouts call-disconnect 3
timeouts wait-release 3
connection plar opx 832106
impedance complex3
description ** FXO port **
caller-id enable
May i also refer you to this document for troubleshooting.
hxxp://www.cisco.com/en/US/tech/tk652/tk653/technologies_tech_note09186a00803736c1.shtml
thank you for your reply and your recommendation.i
also removed the codec preferences but with the same error.for this project the PSTN is
located in Tehran/Iran.all outgoing and incomming calls are local.i also
tested the line with another IP PBX (Asterisk + digium analog gateway)
and the result both incomming and outgoing calls were successful.
in
the debug rtpspi command it mentined rtp_udp_unreachable and i thought a
network issues like NAT that preventing rtp string going through CUCM,
so i set up a CME on the router and i connected the pc(with CIPC
installed) to the router .
PC(with CIPC)<------------>Router(with FXO)<---------->PSTN
i tried to call PSTN but again i encountered the same issue(continuous noise with fast busy)
i also removed all the configuration settings from voice-port, again the same issue.
all
the router and FXO and PVDM are original(the percent of hardware
failure is rare) but i test the FXO and PVDM on another router
maybe the PSTN use a nonlinear PCM and this causes a faulty error.
I'm suspecting two reasons behind this:
1. It's the signaling mismatch issue between the router & your telco. Each country have it's own characteristics of signaling configuration, specially the frequency, cadence & cptone value, I have seen it needs to be modified at most of the cases. You try to get the proper configs from your telco or any of your friend who have done deployment at your region.
2. It's a bug hit which is related to your DSP, in a big picture to your IOS. You can check the bug id#CSCsj89073 as it's related to your symptom though the user behavior is different here. You can check it by changing your IOS to a known release recommended there.
Let us know how it goes. HTH.
thank you very much for taking your time to solve this problem.
for your first suspection i tested different signaling and cptones but nothing changed.
i investigated hop by hop path from router to PSTN.i noticed an interesting issue.in the basement there is a box that all anaog lines coming from PSTN to it and on the other hand the analog lines go to the patch panel of rack and connecting to the router.
router (with FXO)<--->KAFO(centralized analog lines comming from PSTN)<---> PSTN
maybe this creepy stuff causes this issue(noise with fast busy)
for the second case that you mentioned regarding the IOS versions and bug i tested 2 different versions including 124-3.T and 124-24.T but again all attempts were in vain.
But you said it's working fine with Asterisk & Digium combination!
yeah,it works fine with asterisk and digium card.
i'm also working on your second suspection trying other IOS
and also changing the router and fxo modules.
Problem resolved.
solution: change and use the following IOS(https://tools.cisco.com/bugsearch/bug/CSCsj89073#details)
thank you guys for helping me to solve this creepy issue,especially rejohn and MijanurRahman for giving me all the related information and personal experiences.
although i tested 5 different types of IOS versions but all of them had a bug.just use the IOS versions that cisco confirms and bug fixed.
as cisco recommends i use one of the them: c2800nm-adventerprisek9-mz.124-15.T2.bin
i hope that this thread help others to find and resolve the same problem more quickly.