FXO no longer transferring to internal extension/fast busy

jeremy-ramirez · ‎06-30-2010

A really strange thing has occurred on a 2811 with a 2-port FXO card installed. When dialing in to the pots lines is would connect to a shared line in the office but after a power outage/storm is rings in then goes to fast busy. I've attached a show run along with a debug of what I see when it dials in (see no matching destination pattern, etc). The backend is an OLD CM 4.x server. Any ideas?? Worked fine then fritzed out... Thanks!!

!
voice-port 0/1/0
timing hookflash-out 50
connection plar 2925
!
voice-port 0/1/1
timing hookflash-out 50
connection plar 2925
!
ccm-manager fallback-mgcp
ccm-manager redundant-host 192.168.1.2
ccm-manager mgcp
ccm-manager music-on-hold
ccm-manager config server 192.168.1.2
ccm-manager config
!
mgcp
mgcp call-agent 192.168.1.3 2427 service-type mgcp version 0.1
mgcp dtmf-relay voip codec all mode out-of-band
mgcp rtp unreachable timeout 1000 action notify
mgcp modem passthrough voip mode nse
mgcp package-capability rtp-package
no mgcp package-capability res-package
mgcp package-capability sst-package
no mgcp package-capability fxr-package
mgcp package-capability pre-package
no mgcp timer receive-rtcp
mgcp sdp simple
mgcp fax t38 inhibit
no mgcp explicit hookstate
mgcp rtp payload-type g726r16 static
mgcp bind control source-interface Serial0/0/0
mgcp bind media source-interface Serial0/0/0
!
mgcp profile default
!
!
!
dial-peer voice 1 pots
destination-pattern 8.T
incoming called-number .
port 0/1/0
!
dial-peer voice 2 pots
destination-pattern 8.T
port 0/1/1
!
dial-peer voice 999010 pots
service mgcpapp
port 0/1/0
!
dial-peer voice 999011 pots
service mgcpapp
port 0/1/1
!
!
!
call-manager-fallback
secondary-dialtone 8
max-conferences 8 gain -6
transfer-system full-consult
ip source-address 192.168.4.1 port 2000
max-ephones 10
max-dn 10
default-destination 2925
voicemail 87922900#
date-format dd-mm-yy
!

DEBUG INFO:

1d06h: //-1/xxxxxxxxxxxx/RXRULE/regxrule_get_profile_from_trunkgroup_internal: Voice port 0x4680319C does not belong to any trunk group
1d06h: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=, Called Number=, Voice-Interface=0x4680319C,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOICE, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
1d06h: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_PORT; Incoming Dial-peer=1
1d06h: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_allocate_cdb:
   CDB=0x45961630
1d06h: //-1/xxxxxxxxxxxx/VTSP:(0/1/0):-1:-1:-1/vtsp_do_call_setup_ind:
   Event=E_TSP_SETUP_IND
   Progress Indication=3, CarrierIDCode=, Info Trans Capability=144, Source Carrier ID=, tg_label_flag=0
1d06h: //-1/DD67A95D8211/VTSP:(0/1/0):-1:-1:-1/vtsp_timer:
   Timer Start Time=10938852, Timer Value=180000(ms)
1d06h: //-1/DD67A95D8211/VTSP:(0/1/0):-1:-1:-1/vtsp_insert_cdb:
1d06h: //-1/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
   [state:S_SETUP_IND_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
1d06h: //-1/DD67A95D8211/VTSP:(0/1/0):-1:1:1/act_setup_ind_pend_success:
1d06h: //-1/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_realloc_cdb:
   CDB=0x45961630
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_insert_cdb:
1d06h: //-1/DD67A95D8211/RXRULE/regxrule_stack_pop_RegXruleNumInfo: stack=0x476AC938; count=1
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_timer:
   Timer Start Time=10938852, Timer Value=180000(ms)
1d06h: //-1/DD67A95D8211/RXRULE/regxrule_stack_push_RegXruleNumInfo: stack=0x476AC938; count=0
1d06h: //-1/DD67A95D8211/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=2925, Peer Info Type=DIALPEER_INFO_SPEECH
1d06h: //-1/DD67A95D8211/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=2925
1d06h: //-1/DD67A95D8211/DPM/dpMatchPeersCore:
   No Outgoing Dial-peer Is Matched; Result=NO_MATCH(-1)
1d06h: //-1/DD67A95D8211/DPM/dpMatchPeersMoreArg:
   Result=NO_MATCH(-1)
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
   [state:S_SETUP_INDICATED, event:E_CC_PROCEEDING]
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/act_proceeding:
   Progress Indication=0
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=10938853
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
   [state:S_PROCEEDING, event:E_CC_DISCONNECT]
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/act_pre_con_disconnect:
   Cause Value=1, Hairpin=FALSE
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=10938853
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_ring_noan_timer_stop:
   Timer Stop Time=10938853
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_timer:
   Timer Start Time=10938853, Timer Value=30000(ms)
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/act_pre_con_disconnect:
   Tone=Fast Busy, Tone Timeout=30(s), Progress Indication Sent=0
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
   [state:S_WAIT_RELEASE_NC, event:E_TSP_DISCONNECT_IND]
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/act_pre_con_disc_rel:
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/act_pre_con_disc_rel:
   Cause Value=1
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
   [state:S_WAIT_RELEASE_RESP, event:E_TSP_DISCONNECT_CONF]
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/act_wrelease_release:
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_play_busy_timer_stop:
   Timer Stop Time=10939101
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:1:1/vtsp_timer_stop:
   Timer Stop Time=10939101
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:-1:-1/vtsp_process_event:
   [state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:-1:-1/act_terminate:
1d06h: //134/DD67A95D8211/VTSP:(0/1/0):-1:-1:-1/vtsp_timer_stop:
   Timer Stop Time=10939101
1d06h: //-1/DD67A95D8211/RXRULE/regxrule_stack_pop_RegXruleNumInfo: stack=0x476AC938; count=1
1d06h: //-1/DD67A95D8211/VTSP:(0/1/0):-1:-1:-1/vtsp_free_cdb:
   CDB=0x45961630

Brandon Buffin · ‎06-30-2010

Are you using H.323 or MGCP? Looks like there is config for both. From the debugs, the call is using H.323, but there is no outbound dial peer to CCM. There should be a dial peer such as:

dial-peer voice 10 voip

destination-pattern 2925 (This would only route 2925, may be 29.., 2..., etc.)

session target ipv4:1.1.1.1 (IP address of CCM)

Hope this helps.

Brandon

jeremy-ramirez · ‎06-30-2010

Tried what you sent over, different error in debug...

Calling Number=, Called Number=2925, Peer Info Type=DIALPEER_INFO_SPEECH
1d08h: //-1/73F65BB28251/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=2925
1d08h: //-1/73F65BB28251/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
1d08h: //-1/73F65BB28251/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=10
1d08h: //-1/73F65BB28251/RXRULE/regxrule_stack_push_RegXruleNumInfo: stack=0x476AC938; count=1
1d08h: //-1/73F65BB28251/RXRULE/regxrule_dp_translate: No profile found in peer 10 for outgoing direction
1d08h: //-1/73F65BB28251/RXRULE/regxrule_dp_translate: calling_number= calling_octet=0x0
        called_number=2925 called_octet=0x80
        redirect_number= redirect_type=0 redirect_plan=0        redirect_PI=0 redirect_SI=0
1d08h: //153/73F65BB28251/VTSP:(0/1/0):-1:1:1/vtsp_process_event:
   [state:S_SETUP_INDICATED, event:E_CC_PROCEEDING]

Brandon Buffin · ‎06-30-2010

What codec is CCM expecting? Default for voip dial peers is g.729. You can try changing to g.711:

dial-peer voice 10 voip

codec g711ulaw

Hope this helps.

Brandon

jeremy-ramirez · ‎07-01-2010

That didn't work either... Still getting:

1d08h: //-1/73F65BB28251/RXRULE/regxrule_dp_translate: No profile found in peer 10 for outgoing direction
1d08h: //-1/73F65BB28251/RXRULE/regxrule_dp_translate: calling_number= calling_octet=0x0
called_number=2925 called_octet=0x80

Brandon Buffin · ‎07-01-2010

Can you make sure this H.323 gateway is configured in CUCM and that it has a calling search space configured under Inbound Calls that has access to the called DN?

Brandon