Re: CUCME to CUCME Calls only work one way

Chris Campbell · ‎05-27-2020

I have two routers setup in my lab now. Router A has everything working fine. I can make calls between phones in the house and out to the PSTN, as well as receiving PSTN calls. It has two 7821 phones attached.

the second router i just set up has one 8841. When I call from router A to router B, everything works. When I go the other way, the call fails. I'm trying to figure out why, as the configuration is simple and also identical in the pools and dn. Debugging info indicates the call from the router B phone is reaching router A.

Routers are connected with SIP.

Roger Kallberg · ‎05-27-2020

Since it’s CME maybe you should start by attaching the configuration for both routers so that we have a chance to look through your configuration. Possibly it would also be good to share any output from debugs that you’ve made as part of your troubleshooting.

Chris Campbell · ‎05-28-2020

Good idea. Also, I just noticed that the time is off. Not sure if that could cause such an issue, but I'll get it set.

Router A

cts logging verbose

voice-card 0

dspfarm

dsp services dspfarm

!

voice service pots

!

voice service voip

allow-connections sip to sip

no supplementary-service sip moved-temporarily

fax protocol t38 version 0 ls-redundancy 0 hs-redundancy 0 fallback none

sip

bind control source-interface GigabitEthernet0/2

bind media source-interface GigabitEthernet0/2

registrar server expires max 600 min 60

!

voice class codec 1

codec preference 1 g711ulaw

!

voice register global

mode cme

source-address 10.0.0.229 port 5060

max-dn 20

max-pool 10

load 7821 sip78xx.11-7-1-17.loads

timezone 8

time-format 24

tftp-path flash:

create profile sync 0002059441215591

auto-register

!

voice register dn 1

number 4001

name 7821-1

!

voice register dn 2

number 4002

name 7821-2

!

voice register dn 3

number 2074

name outside line

shared-line

!

voice register dn 4

number 4000

pickup-group 1

name park slot

!

voice register dn 10

number 10

!

voice register dn 11

number 11

auto-answer

intercom

!

voice register dn 12

number 12

auto-answer

intercom

!

voice register pool 1

busy-trigger-per-button 2

id mac D42C.4485.9C5F

type 7821

number 1 dn 3

number 2 dn 1

number 4 dn 3

no digit collect kpml

description 4001

codec g711ulaw

no vad

paging-dn 1

!

voice register pool 2

busy-trigger-per-button 2

id mac DCCE.C1D5.45C4

type 7821

number 1 dn 3

number 2 dn 2

number 3 dn 12

number 4 dn 1

no digit collect kpml

description 4002

codec g711ulaw

no vad

paging-dn 1

!

dial-peer voice 1 pots

description local

destination-pattern 2......

no digit-strip

port 0/1/0

forward-digits 7

!

dial-peer voice 3 pots

description Long Distance

destination-pattern 1..........

no digit-strip

port 0/1/0

forward-digits 11

!

dial-peer voice 4 voip

destination-pattern 400.

session protocol sipv2

!

dial-peer voice 9 pots

description local mobile

destination-pattern 4......

no digit-strip

port 0/1/0

!

dial-peer voice 5 voip

incoming called-number .

!

dial-peer voice 60 voip

destination-pattern 6001

session protocol sipv2

session target ipv4:10.0.0.230

codec g711ulaw

!

Router B

voice service voip

allow-connections sip to sip

no supplementary-service sip moved-temporarily

fax protocol t38 version 0 ls-redundancy 0 hs-redundancy 0 fallback none

sip

bind control source-interface GigabitEthernet0/1

bind media source-interface GigabitEthernet0/1

registrar server

!

voice class codec 1

codec preference 1 g711ulaw

!

voice register global

mode cme

source-address 10.0.0.230 port 5060

max-dn 4

max-pool 4

load 8841 sip88xx.12-7-1-0001-393.loads

timezone 8

time-format 24

tftp-path flash:

create profile sync 0013531685529146

auto-register

!

voice register dn 1

number 6001

name router2-ph1

!

voice register pool 1

busy-trigger-per-button 2

id mac 00EB.D5CC.0D11

type 8841

number 1 dn 1

no digit collect kpml

description 8841

codec g711ulaw

no vad

dial-peer voice 4000 voip

destination-pattern 4000

session protocol sipv2

session target ipv4:10.0.0.229

codec g711ulaw

!

dial-peer voice 2000 voip

destination-pattern 2...

session protocol sipv2

session target ipv4:10.0.0.229

codec g711ulaw

!

dial-peer voice 2074 voip

destination-pattern 2074

session protocol sipv2

session target ipv4:10.0.0.229

codec g711ulaw

!

Output from router A when I try to call from a router B attached phone to router A:

*May 28 18:37:37.203: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Connection=0x2D03CD0, addr=10.0.22.2, port=5060, connid=4 has been aged out

*May 28 18:37:37.203: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting UDP conn close for addr=10.0.22.2, port=5060, local_addr=10.0.0.229, connid=4

*May 28 18:37:37.203: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnInstance: Deleted conn=0x2D03CD0, connid=4, addr=10.0.22.2, port=5060, local_addr=10.0.0.229, transport=UDP

*May 28 18:37:37.203: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x1D5F1604,addr=10.0.22.2

*May 28 18:37:37.203: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopAgeingTimer: Aging timer stopped for holder=0x1D5F1604,addr=10.0.22.2

*May 28 18:37:37.203: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnHolder: Deleted holder=0x1D5F1604, addr=10.0.22.2, count=0

*May 28 18:39:09.626: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Connection=0x16BE8054, addr=10.0.22.3, port=5060, connid=3 has been aged out

*May 28 18:39:09.626: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostCloseConnection: Posting UDP conn close for addr=10.0.22.3, port=5060, local_addr=10.0.0.229, connid=3

*May 28 18:39:09.626: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnInstance: Deleted conn=0x16BE8054, connid=3, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, transport=UDP

*May 28 18:39:09.626: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x18390E38,addr=10.0.22.3

*May 28 18:39:09.626: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopAgeingTimer: Aging timer stopped for holder=0x18390E38,addr=10.0.22.3

*May 28 18:39:09.626: //-1/xxxxxxxxxxxx/SIP/Transport/sipDeleteConnHolder: Deleted holder=0x18390E38, addr=10.0.22.3, count=0

*May 28 18:39:22.038: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*May 28 18:39:22.038: //-1/xxxxxxxxxxxx/CCAPI/cc_get_call_entry:

CALL_ERROR_INFORMATIONAL; Call Id Is Invalid=-1

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.0.22.3,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.0.22.3,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Event/sact_idle_new_message_register:

ccsip_api_register_ind return value : SIP_SUCCESS

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_REGISTER_RESP

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Transport/sipSPISendResponse: Sending INFO Response to the transport layer

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Transport/sipSPITransportSendMessage: msg=0x13E53714, addr=10.0.22.3, port=5060, sentBy_port=5060, local_addr=10.0.0.229, is_req=0, transport=1, switch=0, callBack=0x9F50EB0

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x13E53714 to default port=5060

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x1D5F1604,addr=10.0.22.3

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnHolder: Created new holder=0x1D5F1604, addr=10.0.22.3; nailed=FALSE

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=10.0.22.3, port=5060, context=0x2D027A8

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x2D03FDC,addr=10.0.22.3, port=5060

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer:

Wait Conn Timer started for 5000 msec

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0x2D03FDC, connid=-1, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, transport=UDP, vrfid = 0

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.22.3, rport:5060 with laddr:10.0.0.229

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x3A7FFB0 with connection=0x2D03FDC

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Transport/sipTransportLogicSendMsg: Waiting for Connection for sending msg=0x13E53714

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Transport/sipSPITransportSendMessage: Deferred sending msg=0x13E53714

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWConnectionCreated: context=0x2D027A8

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: gConnTab=0x2D027A8, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, connid=3, transport=UDP

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: connection instance created for addr:10.0.22.3, port:5060 local_addr=10.0.0.229 local_port=57226

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopConnWaitTimer: Wait timer stopped for connection=0x2D03FDC,addr=10.0.22.3, port=5060

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnectionCreated: Moving connection=0x2D03FDC, connid=3 state to established. local_addr=10.0.0.229, local_port=57226

*May 28 18:39:22.042: //21673/61B361EC96FD/SIP/Transport/sipTransportPostInternalMsg: Posting Internal Msg type=0

*May 28 18:39:22.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x13E53714, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, connId=3 vrfid=0 for UDP

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/CCAPI/cc_get_call_entry:

CALL_ERROR_INFORMATIONAL; Call Id Is Invalid=-1

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.0.22.3,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.0.22.3,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*May 28 18:39:22.066: //21674/61B70B7496FE/SIP/Event/sact_idle_new_message_register:

ccsip_api_register_ind return value : SIP_SUCCESS

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_REGISTER_RESP

*May 28 18:39:22.066: //21674/61B70B7496FE/SIP/Transport/sipSPISendResponse: Sending INFO Response to the transport layer

*May 28 18:39:22.066: //21674/61B70B7496FE/SIP/Transport/sipSPITransportSendMessage: msg=0x13E53714, addr=10.0.22.3, port=5060, sentBy_port=5060, local_addr=10.0.0.229, is_req=0, transport=1, switch=0, callBack=0x9F50EB0

*May 28 18:39:22.066: //21674/61B70B7496FE/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*May 28 18:39:22.066: //21674/61B70B7496FE/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x13E53714 to default port=5060

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.22.3, rport:5060 with laddr:10.0.0.229

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x3A79848 with connection=0x2D03FDC context list

*May 28 18:39:22.066: //21674/61B70B7496FE/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x13E53714

*May 28 18:39:22.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x13E53714, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, connId=3 vrfid=0 for UDP

*May 28 18:39:54.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x2D027A8, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, unregistering context=0x3A7FFB0

*May 28 18:39:54.042: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x3A7FFB0 from the connection=0x2D03FDC context list

*May 28 18:39:54.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x2D027A8, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, unregistering context=0x3A79848

*May 28 18:39:54.066: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x3A79848 from the connection=0x2D03FDC context list

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/CCAPI/cc_get_call_entry:

CALL_ERROR_INFORMATIONAL; Call Id Is Invalid=-1

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateTCBResponseInfo: Dialog Transaction Address 10.0.22.3,Port 5060, Transport 1, SentBy Port 5060

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Event/ccsip_call_subscribe_response: Queued event from SIP SPI : SIPSPI_EV_CC_SUBSCRIBE_RESP

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.22.3, rport:5060 with laddr:10.0.0.229

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x1743BCBC with connection=0x2D03FDC context list

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x1E3F57C0, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, connId=3 vrfid=0 for UDP

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Event/ccsip_call_notify_event: Queued event from SIP SPI : SIPSPI_EV_CC_NOTIFY

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateTCBRequestInfo: Dialog Transaction Address 10.0.22.3,Port 5060, Port Present: TRUE, Transport 1, FQDN 235709248

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.22.3, rport:5060 with laddr:10.0.0.229

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x1743BCBC is already on connection=0x2D03FDC context_list

*May 28 18:41:17.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x13E53714, addr=10.0.22.3, port=5060, local_addr=10.0.0.229, connId=3 vrfid=0 for UDP

*May 28 18:41:17.285: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*May 28 18:41:17.285: //-1/xxxxxxxxxxxx/CCAPI/cc_get_call_entry:

CALL_ERROR_INFORMATIONAL; Call Id Is Invalid=-1

Output from router B:

*May 28 18:49:32.701: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*May 28 18:49:32.701: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.0.0.212,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*May 28 18:49:32.705: //-1/CDAE864880C6/CCAPI/cc_api_display_ie_subfields:

cc_api_call_setup_ind_common:

cisco-username=6001

----- ccCallInfo IE subfields -----

cisco-ani=6001

cisco-anitype=0

cisco-aniplan=0

cisco-anipi=0

cisco-anisi=1

dest=4001

cisco-desttype=0

cisco-destplan=0

cisco-rdie=FFFFFFFF

cisco-rdn=

cisco-rdntype=0

cisco-rdnplan=0

cisco-rdnpi=-1

cisco-rdnsi=-1

cisco-redirectreason=-1 fwd_final_type =0

final_redirectNumber =

hunt_group_timeout =0

*May 28 18:49:32.705: //-1/CDAE864880C6/CCAPI/cc_api_call_setup_ind_common:

Interface=0x1547D488, Call Info(

Calling Number=6001,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

Called Number=4001(TON=Unknown, NPI=Unknown),

Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,

Incoming Dial-peer=40001, Progress Indication=NULL(0), Calling IE Present=TRUE,

Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=99

*May 28 18:49:32.705: //-1/CDAE864880C6/CCAPI/ccCheckClipClir:

In: Calling Number=6001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*May 28 18:49:32.705: //-1/CDAE864880C6/CCAPI/ccCheckClipClir:

Out: Calling Number=6001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 28 18:49:32.705: :cc_get_feature_vsa malloc success

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 28 18:49:32.705: cc_get_feature_vsa count is 1

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*May 28 18:49:32.705: :FEATURE_VSA attributes are: feature_name:0,feature_time:17040704,feature_id:31

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/cc_api_call_setup_ind_common:

Set Up Event Sent;

Call Info(Calling Number=6001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),

Called Number=4001(TON=Unknown, NPI=Unknown))

*May 28 18:49:32.705: //99/CDAE864880C6/SIP/Transport/sipSPITransportSendMessage: msg=0x41A790F8, addr=10.0.0.212, port=5060, sentBy_port=5060, local_addr=10.0.0.230, is_req=0, transport=1, switch=0, callBack=0x0

*May 28 18:49:32.705: //99/CDAE864880C6/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*May 28 18:49:32.705: //99/CDAE864880C6/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x41A790F8 to default port=5060

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.0.212, rport:5060 with laddr:10.0.0.230

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x2B236B0 with connection=0x41674394 context list

*May 28 18:49:32.705: //99/CDAE864880C6/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x41A790F8

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x41A790F8, addr=10.0.0.212, port=5060, local_addr=10.0.0.230, connId=3 vrfid=0 for UDP

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/cc_process_call_setup_ind:

Event=0x29982A0

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:

Try with the demoted called number 4001

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/ccCallSetContext:

Context=0x18B41F84

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/cc_process_call_setup_ind:

>>>>CCAPI handed cid 99 with tag 40001 to app "_ManagedAppProcess_Default"

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/ccCallProceeding:

Progress Indication=NULL(0)

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/ccCallDisconnect:

Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/ccCallDisconnect:

Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)

*May 28 18:49:32.705: //99/CDAE864880C6/SIP/Transport/sipSPITransportSendMessage: msg=0x41A78C50, addr=10.0.0.212, port=5060, sentBy_port=5060, local_addr=10.0.0.230, is_req=0, transport=1, switch=0, callBack=0x9F4B570

*May 28 18:49:32.705: //99/CDAE864880C6/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*May 28 18:49:32.705: //99/CDAE864880C6/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x41A78C50 to default port=5060

*May 28 18:49:32.705: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.0.0.212, rport:5060 with laddr:10.0.0.230

*May 28 18:49:32.709: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2B236B0 is already on connection=0x41674394 context_list

*May 28 18:49:32.709: //99/CDAE864880C6/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x41A78C50

*May 28 18:49:32.709: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x41A78C50, addr=10.0.0.212, port=5060, local_addr=10.0.0.230, connId=3 vrfid=0 for UDP

*May 28 18:49:32.713: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*May 28 18:49:32.713: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.0.0.212,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*May 28 18:49:32.713: //99/CDAE864880C6/CCAPI/cc_api_call_disconnect_done:

Disposition=0, Interface=0x1547D488, Tag=0x0, Call Id=99,

Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)

*May 28 18:49:32.713: //99/CDAE864880C6/CCAPI/cc_api_call_disconnect_done:

Call Disconnect Event Sent

*May 28 18:49:32.713: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*May 28 18:49:32.713: :cc_free_feature_vsa freeing 1040538

*May 28 18:49:32.713: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*May 28 18:49:32.713: vsacount in free is 0

*May 28 18:49:32.713: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x25648E4, addr=10.0.0.212, port=5060, local_addr=10.0.0.230, unregistering context=0x2B236B0

*May 28 18:49:32.713: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x2B236B0 from the connection=0x41674394 context listsh clock

*18:51:27.404 UTC Thu May 28 2020

Roger Kallberg · ‎05-29-2020

You are getting back an unallocated number in router B.

*May 28 18:49:32.705: //99/CDAE864880C6/CCAPI/ccCallDisconnect:

Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)

Can you please outline the path of the call from calling to called device, including as much information as you can. Especially include calling and called number and IP address of the same, plus any IP address for each hop between CME.
I usually try to visualize the call flow by typing it out like this. Caller device -> Dial peer used for inbound -> any transformations of called/calling number -> Called Number -> Dial peer used for outbound -> any transformations of called/calling number -> Source GW -> Destination GW -> Dial peer used for inbound -> any transformations of called/calling number -> Dial peer used for outbound -> Called device. Not all steps may be applicable to you.

Chris Campbell · ‎05-29-2020

Oh, it looks like I didn't get the dial peer portion for router B included.

Router B has a phone with number 6001 and a dial peer to connect to "400."

For this simple scenario, both routers are on the same subnet and A has an IP address of 10.0.0.229. B has an IP address of 10.0.0.230.

I'll double check when I get home but I believe the 7821 phones are on a separate VLAN of 10.0.22.0/24, while the 8841 (on router B) is on the same VLAN as router B.

I'll look it over and post the call flow in the format you requested.

Chris Campbell · ‎05-29-2020

I am convinced now that I have a codec problem. When I call from a router A-attached phone to a router B attached phone, debug output on both routers shows g711ulaw codec. When I call from a router B-attached phone to a router A-attached phone, B says g711ulaw, but A says g729r8:

Router B

Number of Media Streams: 1

Media Stream : 1

Negotiated Codec : g711ulaw

Negotiated Codec Bytes : 160

Nego. Codec payload : 0 (tx), 0 (rx)

Negotiated Dtmf-relay : 0

Dtmf-relay Payload : 0 (tx), 0 (rx)

Source IP Address (Media): 10.0.0.230

Source IP Port (Media): 16412

Destn IP Address (Media): 10.0.0.212

Destn IP Port (Media): 32204

Orig Destn IP Address:Port (Media): [ - ]:0

Router A

Number of Media Streams: 1

Media Stream : 1

Negotiated Codec : g729r8

Negotiated Codec Bytes : 0

Nego. Codec payload : 255 (tx), 255 (rx)

Negotiated Dtmf-relay : 0

Dtmf-relay Payload : 0 (tx), 0 (rx)

Source IP Address (Media): 10.0.0.229

Source IP Port (Media): 0

Destn IP Address (Media): 10.0.0.230

Destn IP Port (Media): 16414

Orig Destn IP Address:Port (Media): [ - ]:0

I went in and changed a bunch of codec lines in the configuration to say g729r8, and now I have the exact opposite situation with calls. I thought I had everything set to use g711ulaw before, but for some reason, it wasn't sticking.

Chris Campbell · ‎05-29-2020

I added a voice class like this:

voice class codec 1

codec preference 1 g729r8

codec preference 2 g711ulaw

and then set all the phones (pools) and dial peers on both routers to use that instead of an explicit codec statement, like this:

voice register pool 1

no codec g711ulaw

voice-class codec 1

Now calls work in both directions. I still don't understand why the routers were using different codecs as they're the same model on the same version of IOS. I want to figure this out, but for now, at least I know it is a codec issue that I was dealing with and that creating a voice class and applying it to the pools and dial peers will make things work.

Roger Kallberg · ‎05-29-2020

Your last reply made me convinced that it is dial peer 0 that is used in the inbound direction for calls from B to A. If you look at the codec used for these calls it’s very likely g729 and if you look at the same for calls in the other direction it’s likely g711. You should create a dial peer in A that is used for the inbound direction so that it doesn’t use the default non configurable DP0.

Roger Kallberg · ‎06-01-2020

Hi @Chris Campbell
Looking through the posted configurations once more made me notice that you have a dial peer on router A that doesn't have any mention of codec or codec list. That dial peer, #5, is used for your inbound voip call leg, this would explain why you get codec g729. So it did not use dial peer 0 as I thought at first, it would be this dial peer that is used. Please add the below changes to router A and see if that makes the call be g711 in both directions.

dial-peer voice 5 voip
description Inbound calls from CME
session protocol sipv2
incoming called-number .
voice-class codec 1
dtmf-relay rtp-nte sip-kpml
no vad

Also change this in both routers.

voice class codec 1
codec preference 1 g711ulaw
codec preference 2 g711alaw
codec preference 3 g729r8

In general you should configure use of "no vad" on any place where it can be set, aka dial peer, voice register and so on. Rule of thumb is VAD=BAD.

Roger Kallberg · ‎05-29-2020

Check that when the call hit router A what dial peer is used for the inbound direction. From your description it sounds like it would be using dial peer 0. That’s a dial peer that doesn’t show in configuration and has g729 as the codec that is hard coded, aka can’t be changed. If this is true you need to correct the configuration so that there is a dial peer that is used in the inbound direction in router A. One other advice, where you can configure use of a codec list do so instead of setting one specific codec. This makes changes much easier.