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.

Sign In or Register to comment.