10-03-2012 07:37 AM - edited 03-16-2019 01:30 PM
Hi Guys,
I have setup a FXO interface with MGCP, after the call is received on the router a fast busy tone is received with a error cause value=47 . I know cause value=47 in some cases are transcoder issue but I don't have Transcoder resource because all the way is only use G.711Ulaw, at CUCM service parameter Intraregion/Interregion are forced to G.711/G7.22 so I really don't know why on earth could be tryng to use transcoding or another kind of Media Resoruces.
CallMExpress#
*Oct 3 13:03:59.178: EIGRP-IPv4(1): Neighbor 192.168.7.1 not on common subnet for FastEthernet0/1
*Oct 3 13:04:04.086: //-1/xxxxxxxxxxxx/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x4B5DC5A4, Interface Type=6, Destination=98092201111, Mode=0x9,
Call Params(Calling Number=,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=98092201111(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=, FinalDestinationFlag=FALSE, Outgoing Dial-peer=0, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=A000000001ab04e7000000F5)
*Oct 3 13:04:04.086: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 3 13:04:04.086: :cc_get_feature_vsa malloc success
*Oct 3 13:04:04.086: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 3 13:04:04.086: cc_get_feature_vsa count is 1
*Oct 3 13:04:04.086: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 3 13:04:04.086: :FEATURE_VSA attributes are: feature_name:0,feature_time:1294008000,feature_id:49
*Oct 3 13:04:04.086: //49/A44CDE5D801A/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Oct 3 13:04:04.086: //49/A44CDE5D801A/CCAPI/ccCallSetContext:
Context=0x490C03C8
*Oct 3 13:04:04.086: //-1/xxxxxxxxxxxx/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x4B02FDF0, Interface Type=9, Destination=0.0.0.0, Mode=0x9,
Call Params(Calling Number=,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=, FinalDestinationFlag=FALSE, Outgoing Dial-peer=0, Call Count On=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=A000000001ab04e7000000F5)
*Oct 3 13:04:04.086: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 3 13:04:04.090: :cc_get_feature_vsa malloc success
*Oct 3 13:04:04.090: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 3 13:04:04.090: cc_get_feature_vsa count is 2
*Oct 3 13:04:04.090: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
*Oct 3 13:04:04.090: :FEATURE_VSA attributes are: feature_name:0,feature_time:1294007776,feature_id:50
*Oct 3 13:04:04.090: //50/A44CDE5D801A/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=9, FlowMode=1
*Oct 3 13:04:04.090: //50/A44CDE5D801A/CCAPI/ccCallSetContext:
Context=0x490C0108
*Oct 3 13:04:04.094: //50/A44CDE5D801A/CCAPI/cc_api_call_connected:
Interface=0x4B02FDF0, Data Bitmask=0x0, Progress Indication=NULL(0),
Connection Handle=0
*Oct 3 13:04:04.094: //50/A44CDE5D801A/CCAPI/cc_api_call_connected:
Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
*Oct 3 13:04:04.098: //49/A44CDE5D801A/CCAPI/cc_api_call_proceeding:
Interface=0x4B5DC5A4, Progress Indication=NULL(0)
*Oct 3 13:04:13.122: EIGRP-IPv4(1): Neighbor 192.168.7.1 not on common subnet for FastEthernet0/1
*Oct 3 13:04:14.094: //49/A44CDE5D801A/CCAPI/cc_api_call_disconnected:
Cause Value=16, Interface=0x4B5DC5A4, Call Id=49
*Oct 3 13:04:14.094: //49/A44CDE5D801A/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
*Oct 3 13:04:14.094: //50/A44CDE5D801A/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Oct 3 13:04:14.094: //50/A44CDE5D801A/CCAPI/ccCallDisconnect:
Cause Value=47, Call Entry(Responsed=TRUE, Cause Value=47)
*Oct 3 13:04:14.094: //49/A44CDE5D801A/CCAPI/ccCallDisconnect:
Cause Value=47, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
*Oct 3 13:04:14.094: //49/A44CDE5D801A/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Oct 3 13:04:14.094: //49/A44CDE5D801A/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Oct 3 13:04:14.098: //50/A44CDE5D801A/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x4B02FDF0, Tag=0x0, Call Id=50,
Call Entry(Disconnect Cause=47, Voice Class Cause Code=0, Retry Count=0)
*Oct 3 13:04:14.098: //50/A44CDE5D801A/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Oct 3 13:04:14.098: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 3 13:04:14.098: :cc_free_feature_vsa freeing 4D20FDD8
*Oct 3 13:04:14.098: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 3 13:04:14.098: vsacount in free is 1
*Oct 3 13:04:14.102: //49/A44CDE5D801A/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x4B5DC5A4, Tag=0x0, Call Id=49,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Oct 3 13:04:14.106: //49/A44CDE5D801A/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Oct 3 13:04:14.106: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 3 13:04:14.106: :cc_free_feature_vsa freeing 4D20FEB8
*Oct 3 13:04:14.106: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
*Oct 3 13:04:14.106: vsacount in free is 0
CallMExpress#
show voice dsp group all
dsp 1:
State: UP, firmware: 28.3.3
Max signal/voice channel: 8/8
Max credits: 160
num_of_sig_chnls_allocated: 6
Transcoding channels allocated: 0
Group: FLEX_GROUP_VOICE, complexity: FLEX
Shared credits: 160, reserved credits: 0
Signaling channels allocated: 6
Voice channels allocated: 0
Credits used (rounded-up): 0
dsp 5:
State: UP, firmware: 28.3.3
Max signal/voice channel: 8/8
Max credits: 160
num_of_sig_chnls_allocated: 0
Transcoding channels allocated: 0
Group: FLEX_GROUP_VOICE, complexity: FLEX
Shared credits: 160, reserved credits: 0
Signaling channels allocated: 0
Voice channels allocated: 0
Credits used (rounded-up): 0
DSP groups on slot 1:
This command is not applicable to slot 1
DSP groups on slot 2:
This command is not applicable to slot 2
0 DSP resource allocation failure
CallMExpress#
Any advance would be appreciated
Regards
MGCP, CCNA, CCNA Voice certified
10-03-2012 09:42 AM
Ok I was tired to think why the call is needing resources so I registered some transcoding resoruces, right now the call is established using codec G711 so WHY the call is requiring transcoding? I have tried using a IP communicator and Cisco 7965.
_____________________________
MGCP, CCNA, CCNA Voice certified
10-03-2012 09:09 PM
Leo,
Most likely the transcoder is used for MTP purposes. Cause code 47 does not necesarily mean its a transcoder issue, it could also be a MTP problem.
What is your setup like? MTP usually are used for dtmf mismatch...If you send over cucm traces, We will see what the transcoder is used for. Please let me know the called and calling number
Please rate all useful posts
"'Nature is too thin a screen, the glory of the omnipresent God bursts through it everywhere"-Ralph Waldo Emerson
10-05-2012 12:52 PM
My scenario is as follow:
CUCM with MGCP fxo using a router 2911, fxo is conected to a PSTN line. Call is dialed from softphone (IP Communicator), the call is received at GW who send teh call to the PSTN line.
CUCM MGCP GW (2911) FXO Line PSTN
---------------------> ----------------> <--------------
Attached the CUCM's calls logs
Thanks in advance
_____________________________
MGCP, CCNA, CCNA Voice certified
10-05-2012 10:08 PM
Hi Leo,
Can you attach the show tech and version of cucm being used here..
Debug mgcp packets
debug voip vtsp all
debug vpm signal
Try re-creating the issue and capture these debugs.
I see a strange behaviour though its hitting the dial-peer 0 which is the default dial-peer.
It should not be hitting that dial-peer (DP: 0) if its registered as MGCP.
Regards,
Kevin
10-10-2012 08:24 AM
10-10-2012 05:57 PM
Hey Leo,
can you capture the debugs again and let me know the calling and called party number.
show tech
debug mgcp packets
debug vpm signal
debug voip vtsp all
Regards,
Kevin
10-10-2012 06:11 PM
Hi Leo,
Try applying the following:
Router4.90(config)#mgcp
Router4.90(config)#no mgcp fax t38 inhibit
Router4.90(config)#no mgcp default-package fxr-package
Let me know how it goes.
Regards,
Kevin
10-12-2012 01:53 AM
Hi Leo,
Just wanted to know if the above solution worked for you.
Let me know the same.
Regards,
Kevin Monteiro
07-21-2014 01:23 AM
guys... i have same issue..
i have 3925 router...with 4 port fxo card...
incoming working...but outgoing giving buy tone and disconnect..
called number: called num:5011471
----------------------------------
QCCI-CME-001#
QCCI-CME-001#
Jul 21 11:24:03 Qatar: //-1/xxxxxxxxxxxx/VTSP:(0/2/0):-1:-1:-1/vtsp_allocate_cdb:
CDB=0x14DC38F0
Jul 21 11:24:03 Qatar: //-1/xxxxxxxxxxxx/VTSP:(0/2/0):-1:-1:-1/vtsp_insert_cdb:
Jul 21 11:24:03 Qatar: //-1/xxxxxxxxxxxx/VTSP:(0/2/0):-1:-1:-1/vtsp_process_event:
[state:INVALID STATE MACHINE, event:E_CC_SETUP_REQ]
Jul 21 11:24:03 Qatar: htsp_timer_stop3
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:-1:-1/vtsp_og_call_req:
Echo Cancel=TRUE, Gain Control=0
Auto Gain Control=FALSE, Dual Tone Detect Mask=0x0, Seq Tone Detect=FALSE
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:-1:-1/vtsp_do_call_setup_req:
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_dsm_opened_cb:
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_REQ_PEND, event:E_VTSP_DSM_OPEN_SUCCESS]
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_setup_req_pend_succ:
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_request_call:
Mode=9, Peer=0
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_create_call_active_on_setup_req:
Target Carrier ID=
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_create_call_active_on_setup_req:
Source Carrier ID=htsp_setup_req
Jul 21 11:24:03 Qatar: Orig called num:50114712
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_request_call:
Progress Indication=0, Info Trans Capability=0
Calling Number=, TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed
Called Number=50114712, TON=Unknown, NPI=Unknown
Jul 21 11:24:03 Qatar: htsp_process_event: [0/2/0, FXOGS_ONHOOK, E_HTSP_SETUP_REQ]fxogs_onhook_setup
Jul 21 11:24:03 Qatar: [0/2/0] set signal state = 0x0 timestamp = 0
Jul 21 11:24:03 Qatar: htsp_timer - 10000 msec
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_REQUEST, event:E_TSP_PROCEEDING]
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_setup_pend_proceeding:
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_timer:
Timer Start Time=7717154, Timer Value=25000(ms)
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_setup_pend_proceeding:
Peer=0, Progress Indication=0, Return Code=2
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_dsm_opened_cb:
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_NULL, event:E_VTSP_DSM_OPEN_SUCCESS]
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_setup_req_wait_pend_success:
Event=76
Jul 21 11:24:03 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=7717154
Jul 21 11:24:13 Qatar: htsp_process_event: [0/2/0, FXOGS_WAIT_TIP_GROUND, E_HTSP_EVENT_TIMER]fxogs_offhook_disc
Jul 21 11:24:13 Qatar: htsp_timer_stop
Jul 21 11:24:13 Qatar: [0/2/0] set signal state = 0x4 timestamp = 0
Jul 21 11:24:13 Qatar: htsp_timer - 1000 msec
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_SETUP_REQ_PROC, event:E_TSP_DISCONNECT_IND]
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_setup_pend_release_ind:
Cause Value=16
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_ring_noan_timer_stop:
Timer Stop Time=7718154
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_cc_call_disconnected:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_cc_call_disconnected:
Cause Value=16
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_set_release_source:
Release Direction=PSTN, Release Source=Called Party-PSTN
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_setup_pend_release_ind:
Peer=0
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_HOST_DISC, event:E_CC_DISCONNECT]
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_host_disc_cleanup:
dsm_indicate_error=0, short_cleardown_timeout=1, Mode=9
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_dsm_save_fax_config:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_dsm_save_fax_config:
Call Entry=NULL, Call Id=-1
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_host_disc_cleanup:
Exit State=16
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_dsm_get_levels_done_cb:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_STATS, event:E_VTSP_DSM_STATS_COMPLETE]
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_dsm_dsp_stats_complete:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_timer:
Timer Start Time=7718154, Timer Value=5000(ms)
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_RELEASE, event:E_VTSP_DSM_STATS_COMPLETE]
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
Unexpected EVENT [E_VTSP_DSM_STATS_COMPLETE] Received For STATE [S_WAIT_RELEASE];
Previous STATE [0.16 ]
Jul 21 11:24:13 Qatar: htsp_process_event: [0/2/0, FXOGS_ONHOOK, E_HTSP_RELEASE_REQ]fxogs_onhook_release
Jul 21 11:24:13 Qatar: htsp_timer_stop2
Jul 21 11:24:13 Qatar: htsp_timer_stop3
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_process_event:
[state:S_WAIT_RELEASE, event:E_TSP_DISCONNECT_CONF]
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/act_wrelease_release:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_play_busy_timer_stop:
Timer Stop Time=7718154
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_timer_stop:
Timer Stop Time=7718154
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_do_call_history:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_do_call_history:
Coder Rate=-1
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:1:1/vtsp_is_valid_dsm_handle:
DMGR=0x2E9008C, VTSP CDB=0x14DC38F0
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:-1:-1/vtsp_dsm_closed_cb:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:-1:-1/vtsp_process_event:
[state:S_CLOSE_DSPRM, event:E_VTSP_DSM_CLOSE_COMPLETE]
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:-1:-1/act_terminate:
Jul 21 11:24:13 Qatar: //315/880E90F28097/VTSP:(0/2/0):-1:-1:-1/vtsp_timer_stop:
Timer Stop Time=7718154
Jul 21 11:24:13 Qatar: //-1/880E90F28097/VTSP:(0/2/0):-1:-1:-1/vtsp_free_cdb:
CDB=0x14DC38F0
Jul 21 11:24:13 Qatar: htsp_process_event: [0/2/0, FXOGS_ONHOOK, E_DSP_SIG_0110]
Jul 21 11:24:13 Qatar: fxogs_line_reversal_clid_wait. On_hook line reversal detected possibily due to crossed cable
Jul 21 11:24:14 Qatar: htsp_process_event: [0/2/0, FXOGS_ONHOOK, E_HTSP_EVENT_TIMER]
QCCI-CME-001#
QCCI-CME-001#
QCCI-CME-001#u all
All possible debugging has been turned off
QCCI-CME-001#
QCCI-CME-001#
QCCI-CME-001#
QCCI-CME-001#
07-21-2014 08:28 AM
Hi,
I solved the issue upgrading the router's IOS. It was a IOS bug, at last that worked for me.
Regards
07-21-2014 08:16 AM
Grab the CallManager traces for one of these calls.
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide