Solved: Re: Cisco 8851 to CUE (No Audio)

Luc Boudreau · ‎10-17-2021

Hey everyone. Just wondering if someone could look at this debug and sort out why I have no audio when calling CUE. I configured G711u on the dial peer and also the 8851 but I might have missed something. I saw a mention of g729 in the debug but can't see where that relates to my config. See Debug and config

All SIP Call tracing is enabled

VIGCME#

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x1862E8F4 with refCount = 1

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x12B3B94 with refCount = 1

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [192.168.30.100]:5060, local_address:[ - ]

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x1862E8F4

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

INVITE sip:2000@192.168.30.1;user=phone SIP/2.0

Via: SIP/2.0/UDP 192.168.30.100:5060;branch=z9hG4bK16b8f49e

From: "Dartmouth Reception" <sip:101@192.168.30.1>;tag=f8a5c59ce30e00522f57e1a2-26e4638d

To: <sip:2000@192.168.30.1>

Call-ID: f8a5c59c-e30e0026-230411df-696b2604@192.168.30.100

Max-Forwards: 70

Session-ID: 1e1cc56200105000a000f8a5c59ce30e;remote=00000000000000000000000000000000

Date: Mon, 18 Oct 2021 00:58:34 GMT

CSeq: 101 INVITE

User-Agent: Cisco-CP8851/12.1.1

Contact: <sip:10260-E57@192.168.30.100:5060;transport=udp>;+u.sip!devicename.ccm.cisco.com="SEPF8A5C59CE30E"

Expires: 180

Accept: application/sdp

Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE,INFO

Remote-Party-ID: "Dartmouth Reception" <sip:101@192.168.30.1>;party=calling;id-type=subscriber;privacy=off;screen=yes

Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1

Allow-Events: kpml,dialog

Recv-Info: conference

Recv-Info: x-cisco-conference

Content-Length: 352

Content-Type: application/sdp

Content-Disposition: session;handling=optional

v=0

o=Cisco-SIPUA 5068 0 IN IP4 192.168.30.100

s=SIP Call

b=AS:4064

t=0 0

m=audio 16548 RTP/AVP 0 8 116 18 101

c=IN IP4 192.168.30.100

b=TIAS:64000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:116 iLBC/8000

a=fmtp:116 mode=20

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=sendrecv

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x294A550) with key=[35] to table

*Oct 18 00:58:35.935: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init:

*Oct 18 00:58:35.935: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init:

*Oct 18 00:58:35.935: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised..

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.30.100,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 0, sip_vrfid 0, voice_vrfid 0

*Oct 18 00:58:35.935: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: ip_best_local_address 192.168.30.1 for SIP

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: bind_inuse: 0conn_reuse: 0

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 192.168.30.1

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/State/sipSPIChangeState: 0x294A550 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.30.100,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.30.100,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x12B3B94) counter, current msg->refCount = 2

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free:

Freeing NULL pointer!

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/verbose/4096/sipSPIAssignCcbLastRequest: Current ccb(0x294A550)->last_request = 0x12B3B94, refCount = 2

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/8192/sipSPIExtractSessionID: Parsed localuuid - 1e1cc56200105000a000f8a5c59ce30e remoteuuid - 00000000000000000000000000000000

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/notify/8192/sipSPI_Add_SessionIDtoTDContainer: localUUID - 1e1cc56200105000a000f8a5c59ce30eremoteUUID - 00000000000000000000000000000000

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/8192/sipSPIProcessSessionID: SessionID header is present- 1e1cc56200105000a000f8a5c59ce30e

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/info/2048/sipSPICheckIpip: VOIP dialpeer (peer=0x13474960) found for sip_user: 2000

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/2048/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/4096/sipSPISetCallingInfo: calling host comes from From: 192.168.30.1

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/verbose/32768/ccsip_ipip_media_forking_copy_prev_best_rpid: MF: This is best rpid..

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/verbose/4096/sipSPIUpdateCallingInfoUsingRpidOrFrom: Updating Calling Info with RPID header data

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/verbose/4096/sipSPISetInfoFromRpid: calling host comes from rpid 192.168.30.1

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/4096/sipSPISetInfoFromRpid: Received current remote name: Dartmouth Reception, current remote number: 101

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/4096/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/2048/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGTD: No GTD found in inbound container

*Oct 18 00:58:35.935: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentCSTA: No CSTA found in inbound container

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x294A550 key=f8a5c59c-e30e0026-230411df-696b2604@192.168.30.1002000 balance 1

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/8192/sipSPIMatchSrcIpGroup: Match not found on carrier id

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/critical/8192/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 2000

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/critical/8192/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 101

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/info/12288/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name Dartmouth Reception, number 101, Calling oct3 0x00, oct_3a 0x81, Called number 2000

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA URL:sip:192.168.30.100:5060, Host:192.168.30.100

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 101

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/critical/1024/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/critical/1024/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/critical/10240/sipSPIGetCallConfig: No match found for P-Called-Party-ID

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/65536/ccsip_sipline_set_vrf: Phone number 101 from ccb calling number

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/65536/ccsip_sipline_set_vrf: Obtained phone tag (1) from Dial-peer

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/65536/ccsip_sipline_set_vrf: Got vrf 0 for phone tag 1

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/8192/sipSPIGetCallConfig: VRF id = 0

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/2048/sipSPIGetCallConfig: Peer tag 40001 matched for incoming call

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 0, sip_vrfid 0, voice_vrfid 0

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: ip_best_local_address 192.168.30.1 for SIP

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: bind_inuse: 0conn_reuse: 0

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 192.168.30.1

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/2048/sipSPISetAudioForcedConfig: audio forced config is set to FALSE

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media Antitrombone disabled

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/notify/65536/sipSPISetMediaFlowMode: Forcing the flow mode to FLOW-THROUGH for SIP line

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder high-density disabled

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/4/update_video_params_from_config: Checking Video Type Rate=-1 video_codec_allowed=1F

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: STUN Usage is not enabled

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall: peer_callID=0

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg..

*Oc

VIGCME#t 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No defer BYE for last

call stats

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp configure for this leg.

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder.

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/32768/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done...

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/32768/ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/32768/ccsip_ipip_media_forking_get_forked_leg_config: MF: This leg is not forked call leg.

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/critical/11264/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/8192/sipSPIGetCallConfig: Initilise the DSCP policy

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/8192/sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/notify/8192/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Line

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/verbose/2048/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/notify/10240/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/4096/sipSPIContinueNewMsgInvite: Calling name Dartmouth Reception, number 101, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 2000, oct3 0x00

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/4096/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/critical/10240/sipSPIValidateRequestUri: Not Enabled

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/65536/UpdateSIPDirectVoiceMailNumber: Direct call from SIP line: called number 2000

*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/131072/sipSPIRscmsmAvail: Value returned by check is = 0

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/critical/4096/sipSPICheckOutBoundDpProvisioning: Cannot obtain the the header bitmap

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/critical/8192/sipSPI_ipip_IsSDPPassthruEnabled: - 0

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/8192/sipSPIExtractSessionID: Parsed localuuid - 1e1cc56200105000a000f8a5c59ce30e remoteuuid - 00000000000000000000000000000000

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/8192/sipSPI_Add_SessionIDtoTDContainer: localUUID - 1e1cc56200105000a000f8a5c59ce30eremoteUUID - 00000000000000000000000000000000

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/8192/sipSPIProcessSessionID: SessionID header is present- 1e1cc56200105000a000f8a5c59ce30e

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:4568421C

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/8192/Session-Timer/sipSTSLExtractSessionExpiresHdr: Not received session expires header

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/8192/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_LEG_BY_LEG, SE Value:0, SE Refresher:none, Min-SE Value:1800, flags:2000

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/8192/Session-Timer/sipSTSLMain:

SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4

Configured SE:1800, Configured Min-SE:1800

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/critical/1024/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/critical/1024/sipSPIProcessDiversionHeader: No diversion headers recvd from app container

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/critical/16384/sipSPIProcessReplacesHeader: No replaces hdr found

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/verbose/1024/sipSPIGetContentCPA: No CPA found in inbound container

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/verbose/1024/sipSPIProcessCPA: No x-cisco-cpa content found

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/verbose/1/sipSPIDoMediaNegotiation: Number of m-lines = 1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/verbose/1/sipSPIValidateConnectionAddress: Dest port = 16548

SIP: (23) Attribute mid, level 1 instance 1 not found.

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: peer_tag=40001

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 0, sip_vrfid 0, voice_vrfid 0

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: VRF id = 0

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: ip_best_local_address 192.168.30.1 for SIP

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: return addr 192.168.30.1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 192.168.30.1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/verbose/1/sipSPI_detect_media_loop: Number of media loops detected - 0

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(116) reserved for codec ilbc

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/critical/1/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/1/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/1/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/8/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/1/sipSPIDoDTMFRelayNegotiation: m-line index 1

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/1/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/1/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/32/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/1/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8193/sip_sdp_get_modem_relay_cap_params: ptype is 0

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8193/sip_sdp_get_modem_relay_cap_params: ptype is 8

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8193/sip_sdp_get_modem_relay_cap_params: ptype is 116

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8193/sip_sdp_get_modem_relay_cap_params: encname is iLBC

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8193/sip_sdp_get_modem_relay_cap_params: ptype is 18

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8193/sip_sdp_get_modem_relay_cap_params: ptype is 101

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8193/sip_sdp_get_modem_relay_cap_params: encname is telephone-event

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8209/sip_sdp_get_modem_relay_cap_params: mer_dtmf_found 0

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/info/8209/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/critical/8193/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/1/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/1/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1

payload_type=0, codec_bytes=160, codec=g711ulaw, dtmf_relay=rtp-nte

stream_type=voice+dtmf (1), dest_ip_address=192.168.30.100, dest_port=16548

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)

*Oct 18 00:58:35.939: //-1/xxxxxxxxxxxx/SIP/Info/sipSPI_Check_If_ICE_Needed: CANDIDATE attribute, level 1not found.

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Media/sipSPIUpdCallWithSdpInfo:

Preferred Codec : g711ulaw, bytes :160

Preferred DTMF relay : rtp-nte

Preferred NTE payload : 101

Early Media : No

Delayed Media : No

Bridge Done : No

New Media

VIGCME#: No

DSP DNLD Reqd : No

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 192.168.30.1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/4096/ccsip_offer_ans_handle_rcvd_sdp:

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_RCVD

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/4096/ccsip_offer_ans_is_invite_offer_valid: TRUE

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/4096/ccsip_offer_ans_common_offer_rcvd_hdlr:

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/4096/ccsip_iwf_handle_network_event:

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_RCVD_SDP

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/4096/sip_iwf_def_ed_rcvd_sdp_hdlr:

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/1/sipSPIAssignStreamCallId: Assigning streamid 23 to stream 1. Old streamid = -1

*Oct 18 00:58:35.939: //23/5B83358F804B/SIP/Info/info/1/sipSPI_initialize_audio_channelInfo_from_sdp: stream_callid = 23, peer_stream_callid = -1

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/8/sipSPI_ipip_init_stream_ex_caps_params: T38 version 0

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/8/sipSPI_ipip_init_stream_ex_caps_params: CCB fax rate 2 ipip_caps rate 14400

SIP: (23) setup attribute, level 1 instance 1 not found.

SIP: (23) connection attribute, level 1 instance 1 not found.

SIP: (23) Attribute label, level 1 instance 1 not found.

SIP: (23) a=framerate attribute, level 1 instance 1 not found.

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/1025/sipSPI_initialize_audio_channelInfo_from_sdp: Populating Address in channelInfo

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sipSPI_initialize_audio_channelInfo_from_sdp: Media dest addr for stream 1='192.168.30.100', port=16548

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = g711ulaw; PType = 0

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/1/codec_found: Codec to be matched: g711ulaw(5)

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/1/codec_found: Match Found at index 0.

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Add Channel for Codec g711ulaw

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/notify/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Media negotiation done for m-line=1: negotiated_ptime=0, negotiated_codec_bytes=160

*Oct 18 00:58:35.943: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sipSPI_ipip_update_codec_params_in_stream_channelInfo: Adding negotiated codec g711ulaw ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 1

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/131073/sipSPIBwCacCalcAudioBandwidth: calculated audio bandwidth : codec g711ulaw bw 64000

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = g711alaw; PType = 8

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/1/codec_found: Codec to be matched: g711alaw(6)

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/notify/1/codec_found: Match Not Found for g711alaw.

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = ilbc; PType = 116

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/1/codec_found: Codec to be matched: ilbc(33)

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/notify/1/codec_found: Match Not Found for ilbc.

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Media/sipSPISelectCodecVersion: Codec (g729r8) is not in preferred list

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/notify/1/sipSPI_ipip_update_static_codec_params: An exact codec match not configured, using interoperable codec g729r8

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = g729r8; PType = 18

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/1/codec_found: Codec to be matched: g729r8(16)

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/notify/1/codec_found: Match Not Found for g729r8.

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/32/sipSPI_ipip_upd_2833_dtmf_params: setting ipip_caps DTMF to RFC2833: callid = 23, dtmf = 6

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sip_iwf_sip_copy_audio_sdp_to_local_channelInfo: Processing Media line = 1; Codec = No Codec ; PType = 101

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/16/sipSPIGetPreferredSrtpSuiteForBw: Return : 0

*Oct 18 00:58:35.943: //-1/xxxxxxxxxxxx/SIP/Info/verbose/16/sipSPIBwCacGetSrtpOverhead: Return: 0

*Oct 18 00:58:35.943: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Media/sipSPIDisplayStreamInfo:

Stream type : voice+dtmf

Media line : 1

State : STREAM_ADDING (2)

Stream address type : 1

Callid : 23

Peer Callid : -1

RTP/SRTP Negotiated : 8

Negotiated Codec : g711ulaw, bytes :160

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

Negotiated DTMF relay : rtp-nte

Negotiated NTE payload : 101 (tx), 101 (rx)

Negotiated CN payload : 0

Media Srce Addr/Port : [192.168.30.1]:0

Media Dest Addr/Port : [192.168.30.100]:16548

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/verbose/4097/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/critical/1/sip_iwf_sip_copy_sdp_to_stream_channelInfo: Not updating call entry.

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/1/sip_iwf_def_ed_rcvd_sdp_hdlr: Setting media_direction to 4

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 0 flow mode flow-through

audio bw 80000 bps video bw 0 bps fax bw 0 bps total bw 80000 bps accounted bw 0 bps

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/131072/sipSPIBwCacUpdateInterfaceBw: bwcac acquiring interface GigabitEthernet0/0 bw 80

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial offer) accounted bw set to 80000

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_RCVD_AWAIT_PEER_EVENT

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_RCVD

*Oct 18 00:58:35.943: //23/5B83358F804B/SIP/Media/sipSPIUpdCallWithSdpInfo:

Stream type : voice+dtmf

Media line : 1

State : STREAM_ADDING (2)

Stream address type : 1

Callid : 23

Negotiated Codec : g711ulaw, bytes :160

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

Negotiated DTMF relay : rtp-nte

Negotiated NTE payload : 101 (tx), 101 (rx)

Negotiated CN payload : 0

Media Srce Addr/Port : [192.168.30.1]:0

Media Dest Addr/Port : [192.168.30.100]:16548

*Oct 18 00:58:35.999: //23/5B83358F804B/SIP/Info/info/4096/ccsip_offer_ans_handle_update_allowed: flag is set to consume early update

*Oct 18 00:58:35.999: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x457688E8

VIGCME#

*Oct 18 00:58:40.431: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x13E2F170 with refCount = 1

*Oct 18 00:58:40.431: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x100D2FC with refCount = 1

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [192.168.30.100]:5060, local_address:[ - ]

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x13E2F170

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

BYE sip:2000@192.168.30.1:5060 SIP/2.0

Via: SIP/2.0/UDP 192.168.30.100:5060;branch=z9hG4bK572f1647

From: "Dartmouth Reception" <sip:101@192.168.30.1>;tag=f8a5c59ce30e00522f57e1a2-26e4638d

To: <sip:2000@192.168.30.1>;tag=140E1C-F6F

Call-ID: f8a5c59c-e30e0026-230411df-696b2604@192.168.30.100

Max-Forwards: 70

Session-ID: 1e1cc56200105000a000f8a5c59ce30e;remote=4f5dec3b8be95001b71060d33ee95331

Date: Mon, 18 Oct 2021 00:58:39 GMT

CSeq: 102 BYE

User-Agent: Cisco-CP8851/12.1.1

Content-Length: 0

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x294A550

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x100D2FC) counter, current msg->refCount = 2

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.30.100,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 192.168.30.100,Port 5060, Transport 1, SentBy Port 5060vrfid 0

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/ccsip_set_release_source_for_peer: ownCallId[23], src[2]

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/4096/sipSPIStopHoldTimer: Stopping hold timer

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/sipSPIUreasonHeader_to_ccCause: Cause=0

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGTD: No GTD found in inbound container

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/critical/4096/sipSPIInitiateDisconnect: Initiate call disconnect(16) for incoming call

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x12B3B94) counter, current msg->refCount = 1

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQSIG: No QSIG Body found in inbound container

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQ931: No RawMsg Body found in inbound container

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 34

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg..

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/critical/10240/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/critical/8192/sipSPI_ipip_IsContentPassthruEnabled: - 0

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8192/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/1024/sipAddSipContainerToCallEntry: Unable to add passthru hdrs to container

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/State/sipSPIChangeState: 0x294A550 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x12B3B94

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x100D2FC) counter, current msg->refCount = 3

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/sipSPIAssignCcbLastRequest: Current ccb(0x294A550)->last_request = 0x100D2FC, refCount = 3

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x100D2FC) counter, current msg->refCount = 2

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 19

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_STATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_XCODER_RESET_STREAM

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/256/sipSPIResetXcoder: *****CLEANING UP XCODER RESOURCES*****

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/256/sipSPIResetXcoder: Xcoder resource already cleaned up

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: IPIPMS:next_state:S_IPIP_MEDIA_SERV_STATE_IDLE

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/ccsip_bridge_drop: ReSetting mid call signalling not supported

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for stream type 0

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nte

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nse

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for stream type 0

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nte

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nse

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/critical/1/sipSPIUpdateMediapolicy: media policy block does not exist

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Media/sipSPIUpdateRtpSession: Stun packet reporting for ICE disabled in sipSPIUpdateRtpSession

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:412C90B4

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 19

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_STATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_XCODER_RESET_STREAM

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/verbose/256/sipSPIResetXcoder: *****CLEANING UP XCODER RESOURCES*****

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/verbose/256/sipSPIResetXcoder: Xcoder resource already cleaned up

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/State/ccsip_cnfsm_debugs: IPIPMS:next_state:S_IPIP_MEDIA_SERV_STATE_IDLE

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/verbose/4096/ccsip_bridge_drop: ReSetting mid call signalling not supported

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for stream type 0

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nte

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nse

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for stream type 0

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nte

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/notify/8193/updateGccbTxRxValues: No interworking required for nse

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/critical/1/sipSPIUpdateMediapolicy: media policy block does not exist

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Media/sipSPIUpdateRtpSession: Stun packet reporting for ICE disabled in sipSPIUpdateRtpSession

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:4575CD5C

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/8192/ccsip_call_statistics: Stats are not supported for IPIP call.

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 34

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/critical/4096/ccsip_ipip_mf_create_xml_metadata_for_disconnect: MF: Not a Forked leg..

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg..

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/info/8192/ccsip_call_statistics: Stats are not supported for IPIP call.

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 34

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/critical/4096/ccsip_ipip_mf_create_xml_metadata_for_disconnect: MF: Not a Forked leg..

*Oct 18 00:58:40.435: //24/5B83358F804B/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg..

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/133120/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 40001 active bw 0 Kbps

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/131072/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface GigabitEthernet0/0 bw 80 Kbps

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/131072/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/4096/act_disconnecting_disconnect: Disconnect now.. no defer BYE..

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x12B3B94 with refCount = 1

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8192/sipSPIAddSessionID: localUUID - 1e1cc56200105000a000f8a5c59ce30e remoteUUID - 4f5dec3b8be95001b71060d33ee9533

VIGCME#1

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/8192/sipSPIAddSessionID: Session-ID header 4f5dec3b8be95001b71060d33ee95331;remote=1e1cc56200105000a000f8a5c59ce30e

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 3 event

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/4096/sipSPISendByeResponse: Associated container=0x4568421C to Bye Response

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Transport/sipSPISendByeResponse: Sending BYE Response to the transport layer

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Transport/sipSPITransportSendMessage: msg=0x12B3B94, addr=192.168.30.100, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x9F43F54

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*Oct 18 00:58:40.435: //23/5B83358F804B/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x12B3B94 to default port=5060

*Oct 18 00:58:40.435: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:192.168.30.100, rport:5060 with laddr:

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x294A550 is already on connection=0x23B6F10 context_list

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x12B3B94

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x12B3B94, addr=192.168.30.100, port=5060, local_addr=, connId=2 vrfid=0 for UDP

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/info/512/sentByeResponse: Sent 200ok to the BYE, tearing down the call

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/info/4096/sipSPISetCommonTimer: Started generic timer type 2 for 240000 millisecs

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/verbose/8192/sipSPIDeferCallClose: Not split dataplane, bail

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/verbose/8192/sipSPIWaitForStatsBforeCallClose: Not split dataplane, bail

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/verbose/4096/sipSPICallCloseAfterFinalStat:

sipSPICallCloseAfterFinalStat:

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/info/12288/sipSPIIcpifUpdate: CallState: 4 Playout: 0 DiscTime:131880 ConnTime 131435

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Media/sipSPIHandleDestroyRtpSession: stream:412C90B4

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x100D2FC) counter, current msg->refCount = 1

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/State/sipSPIChangeState: 0x294A550 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Call/sipSPICallInfo:

The Call Setup Information is:

Call Control Block (CCB) : 0x0x294A550

State of The Call : STATE_DEAD

TCP Sockets Used : NO

Calling Number : 101

Called Number : 2000

Source IP Address (Sig 192.168.30.1

Destn SIP Req Addr:Port : 192.168.30.100:5060

Destn SIP Resp Addr:Port : 192.168.30.100:5060

Destination Name : 192.168.30.100

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Call/sipSPIMediaCallInfo:

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 : 6

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

Source IP Address (Media): 192.168.30.1

Source IP Port (Media): 16420

Destn IP Address (Media): 192.168.30.100

Destn IP Port (Media): 16548

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

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Call/sipSPICallInfo:

Disconnect Cause (CC) : 16

Disconnect Cause (SIP) : 200

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id 17

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Return and SIP_TIMER_REMOVE_TRANSACTION timer will free this ccb=0x0294A550

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/133120/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 2000 active bw 0 Kbps

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/131072/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface GigabitEthernet0/0 bw 80 Kbps

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/131072/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/4096/act_active_disconnect: act_active_disconnect: Disconnect now..

no defer BYE..

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/4096/sipSPIStopHoldTimer: Stopping hold timer

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x45764AD8 with refCount = 1

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/notify/8192/sipSPIAddSessionID: localUUID - 4f5dec3b8be95001b71060d33ee95331 remoteUUID - 1e1cc56200105000a000f8a5c59ce30e

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/notify/8192/sipSPIAddSessionID: Session-ID header 1e1cc56200105000a000f8a5c59ce30e;remote=4f5dec3b8be95001b71060d33ee95331

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 3 event

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/4096/sipSPIStopHoldTimer: Stopping hold timer

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/4096/sipSPISendBye: mf_xml_metadata is NULL

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/4096/sipSPISendBye: Associated container=0x456834B4 to Bye

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Transport/sipSPITransportSendMessage: msg=0x45764AD8, addr=192.168.30.5, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x9F41B3C

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:192.168.30.5, rport:5060 with laddr:

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x2950CB8 is already on connection=0x23B7014 context_list

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x45764AD8

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x45764AD8, addr=192.168.30.5, port=5060, local_addr=, connId=3 vrfid=0 for UDP

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Info/info/512/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/State/sipSPIChangeState: 0x2950CB8 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)

*Oct 18 00:58:40.439: //23/5B83358F804B/SIP/Msg/ccsipDisplayMsg:

Sent:

SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.30.100:5060;branch=z9hG4bK572f1647

From: "Dartmouth Reception" <sip:101@192.168.30.1>;tag=f8a5c59ce30e00522f57e1a2-26e4638d

To: <sip:2000@192.168.30.1>;tag=140E1C-F6F

Date: Mon, 18 Oct 2021 00:58:40 GMT

Call-ID: f8a5c59c-e30e0026-230411df-696b2604@192.168.30.100

Server: Cisco-SIPGateway/IOS-15.7.3.M6

CSeq: 102 BYE

Reason: Q.850;cause=16

P-RTP-Stat: PS=0,OS=0,PR=159,OR=25122,PL=0,JI=0,LA=0,DU=4

Session-ID: 4f5dec3b8be95001b71060d33ee95331;remote=1e1cc56200105000a000f8a5c59ce30e

Content-Length: 0

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x12B3B94

*Oct 18 00:58:40.439: //24/5B83358F804B/SIP/Msg/ccsipDisplayMsg:

Sent:

BYE sip:2000@192.168.30.5:5060 SIP/2.0

Via: SIP/2.0/UDP 192.168.30.1:5060;branch=z9hG4bK17130F

From: "Dartmouth Reception" <sip:101@192.168.30.1>;tag=140E0C-1D89

To: <sip:2000@192.168.30.5>;tag=cue72eb687c

Date: Mon, 18 Oct 2021 00:58:35 GMT

Call-ID: 5B85A6C8-2EE511EC-8051EE15-4B84A76B@192.168.30.1

User-Agent: Cisco-SIPGateway/IOS-15.7.3.M6

Max-Forwards: 70

Timestamp: 1634518720

CSeq: 102 BYE

Reason: Q.850;cause=16

P-RTP-Stat: PS=159,OS=25122,PR=0,OR=0,PL=0,JI=0,LA=0,DU=4

Session-ID: 1e1cc56200105000a000f8a5c59ce30e;remote=4f5dec3b8be95001b71060d33ee95331

Content-Length: 0

*Oct 18 00:58:40.439: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x45764AD8

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x45764D80 with refCount = 1

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x12B3B94 with refCount = 1

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [192.168.30.5]:32776, local_address:[ - ]

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x45764D80

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invit

VIGCME#e Dialog

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/info/1024/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK17130F from via branch list

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x12B3B94) counter, current msg->refCount = 2

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Msg/ccsipDisplayMsg:

Received:

SIP/2.0 200 Ok

Via: SIP/2.0/UDP 192.168.30.1:5060;branch=z9hG4bK17130F

To: <sip:2000@192.168.30.5>;tag=cue72eb687c

From: "Dartmouth Reception" <sip:101@192.168.30.1>;tag=140E0C-1D89

Call-ID: 5B85A6C8-2EE511EC-8051EE15-4B84A76B@192.168.30.1

CSeq: 102 BYE

Content-Length: 0

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/1024/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/sact_disconnecting_new_message_response: [sact_disconnecting_new_message_response] Received Response Class [2] Method Code [103]

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/info/4096/sipSPISetCommonTimer: Started generic timer type 2 for 240000 millisecs

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/8192/sipSPIDeferCallClose: Not split dataplane, bail

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/8192/sipSPIWaitForStatsBforeCallClose: Not split dataplane, bail

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/4096/sipSPICallCloseAfterFinalStat:

sipSPICallCloseAfterFinalStat:

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/info/12288/sipSPIIcpifUpdate: CallState: 4 Playout: 0 DiscTime:131880 ConnTime 131434

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Media/sipSPIHandleDestroyRtpSession: stream:4575CD5C

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x425E41F8

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/State/sipSPIChangeState: 0x2950CB8 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Call/sipSPICallInfo:

The Call Setup Information is:

Call Control Block (CCB) : 0x0x2950CB8

State of The Call : STATE_DEAD

TCP Sockets Used : NO

Calling Number : 101

Called Number : 2000

Source IP Address (Sig 192.168.30.1

Destn SIP Req Addr:Port : 192.168.30.5:5060

Destn SIP Resp Addr:Port : 192.168.30.5:5060

Destination Name : 192.168.30.5

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Call/sipSPIMediaCallInfo:

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 : 8

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

Source IP Address (Media): 192.168.30.1

Source IP Port (Media): 16422

Destn IP Address (Media): 192.168.30.5

Destn IP Port (Media): 16934

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

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Call/sipSPICallInfo:

Disconnect Cause (CC) : 16

Disconnect Cause (SIP) : 200

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id 18

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[36] removed.

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/info/4096/sipSPIStopCommonTimer: Stopping Generic Timer 2

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x2950CB8 key=5B85A6C8-2EE511EC-8051EE15-4B84A76B@192.168.30.1

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Error/sipSPIFlushDeferredQueue:

Invalid deferredQueue

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x23B6930, addr=192.168.30.5, port=5060, local_addr=, unregistering context=0x2950CB8

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x2950CB8 from the connection=0x23B7014 context list

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x12B3B94) counter, current msg->refCount = 1

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Event/ccsip_api_initiate_subscription_termination: Queued event from SIP SPI : SIPSPI_EV_SUBSCRIPTION_TERMINATED

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer

*Oct 18 00:58:40.443: //24/5B83358F804B/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x2950CB8

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[36]

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x12B3B94

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 7 for event 210

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_spi_process_app_subscribe_event: Event [SIPSPI_EV_SUBSCRIPTION_TERMINATED] received in State [SUBSCRIBE_STATE_ACTIVE]

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/verbose/4096/act_subscription_terminated: Resetting server EDB flag

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/info/4096/sipSPITerminateEvent: 1 Events still active on this Subscription Dialog

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 7 for event 210

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_spi_process_app_subscribe_event: Event [SIPSPI_EV_SUBSCRIPTION_TERMINATED] received in State [SUBSCRIBE_STATE_ACTIVE]

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/verbose/4096/act_subscription_terminated: Resetting Client EDB flag

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/verbose/4096/sipSPIFreeOneEDB: There are 1 EDBs on edbQ

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/verbose/4096/sipSPIFreeOneEDB: DeQ'd EDB(0x29612F4)

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIFreeOneEDB: EnQing EDB(0x29612F4) for reuse

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/verbose/4096/sipSPITerminateEvent: Freeing SCB(0x16C55FD8), 0 active events present

*Oct 18 00:58:40.443: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[37] removed.

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/verbose/4096/sipSPIRemoveSCBFromClientTable: Removing SCB(0x16C55FD8) with Key(5B85A6C8-2EE511EC-8051EE15-4B84A76B@192.168.30.1140E0C-1D89) from Client Table

*Oct 18 00:58:40.443: //0/000000000000/SIP/Info/verbose/4096/sipSPIFreeOneSCB: EnQing SCB(0x16C55FD8) for reuse

CONFIG

version 15.7

service timestamps debug datetime msec

service timestamps log datetime msec

no service password-encryption

!

hostname VIGCME

!

boot-start-marker

boot-end-marker

!

! card type command needed for slot/vwic-slot 0/0

enable secret 5 $1$Z265$k7aI7smCRAqVghX7D4VYQ0

!

no aaa new-model

!

crypto pki trustpoint TP-self-signed-694046112

enrollment selfsigned

subject-name cn=IOS-Self-Signed-Certificate-694046112

revocation-check none

rsakeypair TP-self-signed-694046112

!

crypto pki certificate chain TP-self-signed-694046112

certificate self-signed 01 nvram:IOS-Self-Sig#1.cer

!

ip dhcp excluded-address 192.168.30.1 192.168.30.99

!

ip dhcp pool Voice

network 192.168.30.0 255.255.255.0

dns-server 192.168.30.10

default-router 192.168.30.1

option 150 ip 192.168.30.1

option 66 ip 192.168.30.1

lease 7

!

ip cef

no ipv6 cef

!

multilink bundle-name authenticated

!

voice-card 0

!

voice service voip

allow-connections h323 to sip

allow-connections sip to h323

allow-connections sip to sip

no supplementary-service sip moved-temporarily

no supplementary-service sip refer

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

sip

registrar server expires max 600 min 60

g729 annexb-all

!

voice register global

mode cme

source-address 192.168.30.1 port 5060

timeouts interdigit 2

max-dn 200

max-pool 100

timezone 14

voicemail 2000

tftp-path flash:

file text

create profile sync 0004021753180415

network-locale CA

auto-register

!

voice register dn 1

number 101

call-forward b2bua busy 2000

call-forward b2bua noan 2000 timeout 20

name Dartmouth Reception

label Dartmouth Reception

mwi

!

voice register pool 1

busy-trigger-per-button 2

id mac F8A5.C59C.E30E

type 8851

number 1 dn 1

presence call-list

dtmf-relay rtp-nte

codec g711ulaw

!

vxml logging-tag

license udi pid CISCO2951/K9 sn FTX1737AJN7

license accept end user agreement

hw-module pvdm 0/0

!

hw-module sm 1

!

file privilege 0

username admin privilege 15 password 0 cisco

!

redundancy

!

interface Embedded-Service-Engine0/0

no ip address

!

interface GigabitEthernet0/0

no ip address

duplex auto

speed auto

!

interface GigabitEthernet0/0.20

encapsulation dot1Q 20

ip address 192.168.30.1 255.255.255.0

!

interface GigabitEthernet0/1

no ip address

shutdown

duplex auto

speed auto

!

interface GigabitEthernet0/2

ip address dhcp

duplex auto

speed auto

!

interface Integrated-Service-Engine1/0

ip unnumbered GigabitEthernet0/0.20

service-module ip address 192.168.30.5 255.255.255.0

!Application: CUE Running on NME

service-module ip default-gateway 192.168.30.1

no keepalive

!

ip forward-protocol nd

!

ip http server

ip http access-class 50

ip http authentication local

ip http secure-server

ip http timeout-policy idle 60 life 86400 requests 10000

ip http path flash0:/CME-GUI-12.0

!

ip route 192.168.30.5 255.255.255.255 Integrated-Service-Engine1/0

!

ipv6 ioam timestamp

!

nls resp-timeout 1

cpd cr-id 1

!

access-list 50 permit 192.168.3.0 0.0.0.255

access-list 50 permit 192.168.30.0 0.0.0.255

access-list 50 remark

!

control-plane

!

voice-port 0/1/0

!

voice-port 0/1/1

!

voice-port 0/1/2

!

voice-port 0/1/3

!

mgcp behavior rsip-range tgcp-only

mgcp behavior comedia-role none

mgcp behavior comedia-check-media-src disable

mgcp behavior comedia-sdp-force disable

!

mgcp profile default

!

dial-peer voice 2000 voip

destination-pattern 2000

session protocol sipv2

session target ipv4:192.168.30.5

dtmf-relay sip-notify

codec g711ulaw

no vad

!

dial-peer voice 3000 voip

destination-pattern 3000

session protocol sipv2

session target ipv4:192.168.30.5

dtmf-relay sip-notify

codec g711ulaw

no vad

!

sip-ua

!

gatekeeper

shutdown

!

telephony-service

authentication credential voicemail voicemail

max-ephones 100

max-dn 100

ip source-address 192.168.30.1 port 2000

url services http://10.1.1.2/voiceview/common/login.do

url authentication http://10.1.1.1/CCMCIP/authenticate.asp

voicemail 2000

max-conferences 8 gain -6

web admin system name voicemail password voicemail

dn-webedit

time-webedit

transfer-system full-consult

create cnf-files version-stamp 7960 Oct 17 2021 22:49:19

!

line con 0

exec-timeout 0 0

line aux 0

line 2

no activation-character

no exec

transport preferred none

transport output lat pad telnet rlogin lapb-ta mop udptn v120 ssh

stopbits 1

line 67

no activation-character

no exec

transport preferred none

transport input all

transport output lat pad telnet rlogin lapb-ta mop udptn v120 ssh

line vty 0 4

password **********

logging synchronous

login

transport input telnet

!

scheduler allocate 20000 1000

ntp server pool.ntp.org

ntp server

!

pnp profile pnp_cco_profile

transport https ipv4

end

Luc Boudreau · ‎10-31-2021

After more troubleshooting, a software update on the CUE module has resolved the issue. Was running 7.0.6 and now running 8.6.1. All working as expected now.

View solution in original post

Maren Mahoney · ‎10-18-2021

Your config in the CME router looks good except for needing:

sip-ua
 mwi-server ipv4:192.168.30.5 unsolicited

But that would only affect MWI and not call setup to CUE.

The debug does show that the call is set up with the G711ulaw codec, rtp-nte, and no vad which is exactly right. But the call is not being sent to the CUE.

We see the INVITE come in for the voicemail call, but the SIP description of the dial-peer selection notes that dial-peer voice 2000 is a potential target, but does not use that to complete the call. If it did, we should see an INVITE going from CME to CUE. If I'm reading the debug right, it seems that the router is instead finding the next best match which is destination-pattern (cme virtual dial-peer 40001) against incoming calling party (101).

*Oct 18 00:58:35.935: //-1/5B83358F804B/SIP/Info/critical/8192/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 2000
   **and this line**
*Oct 18 00:58:35.939: //-1/5B83358F804B/SIP/Info/info/2048/sipSPIGetCallConfig: Peer tag 40001 matched for incoming call

We don't see the router reaching out to CUE (192.168.30.5) at all until after the BYE message is issued from the originating device. The odd thing (to me) is that the BYE message is relayed to the CUE when an INVITE was never issued.

So, first, check the status of the CUE dial-peer using show dial-peer voice summary Is dial-peer 2000 showing up?

Regardless, I think the issue is not in your CME config but rather in the CUE config. If you choose to post that, please do so as an attached file instead of pasting the config.

Maren

Luc Boudreau · ‎10-18-2021

Thank you for your assistance Maren,

The show dial-peer voice summary is as follows:

VIGCME#show dial-peer voice summary

dial-peer hunt 0

AD PRE PASS SESS-SER-GRP\ OUT

TAG TYPE MIN OPER PREFIX DEST-PATTERN FER THRU SESS-TARGET STAT PORT KEEPALIVE VRF

2000 voip up up 2000 0 syst ipv4:192.168.30.5 NA

3000 voip up up 3000 0 syst ipv4:192.168.30.5 NA

40001 voip up up 101$ 0 syst ipv4:192.168.30.100: NA

Not sure why 40001 is there or should be there.

CUE Config is as follows:

VIG-CUE# sh conf

clock timezone America/Halifax

hostname VIG-CUE

line console

exit

system language preferred "en_US"

ip name-server 192.168.30.1

ntp server 192.168.30.1 prefer

software download server url "ftp://127.0.0.1/ftp" credentials hidden "6u/dKTN/hsEuSAEfw40XlF2eFHnZfyUTSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmP"

log trace local enable

site name local

phone-authentication credentials hidden "drsG4RYdBv7YJzZdkFqAGA55cpYFhifeSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmP"

site-hostname 192.168.30.1

web credentials hidden "drsG4RYdBv7YJzZdkFqAGA55cpYFhifeSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmP"

end site

privilege ManagePrompts create

privilege ManagePublicList create

privilege ViewPrivateList create

privilege vm-imap create

privilege local-broadcast create

privilege broadcast create

privilege ViewRealTimeReports create

privilege ViewHistoricalReports create

privilege manage-passwords create

privilege manage-users create

groupname Broadcasters create

username admin create

username dartmouthreception create

privilege ManagePrompts description "Privilege to create, modify, or delete system prompts"

privilege ManagePublicList description "Privilege to manage public lists"

privilege ViewPrivateList description "Privilege to view private list"

privilege vm-imap description "Privilege to manage personal voicemail via IMAP client"

privilege local-broadcast description "Privilege to send local broadcast messages"

privilege broadcast description "Privilege to send local or remote broadcast messages"

privilege ViewRealTimeReports description "Privilege to view realtime reports"

privilege ViewHistoricalReports description "Privilege to view historical reports"

privilege manage-passwords description "Privilege to reset user passwords"

privilege manage-users description "Privilege to create, modify, and delete users and groups"

privilege ManagePrompts operation system.debug

privilege ManagePrompts operation prompt.modify

privilege ManagePublicList operation voicemail.lists.public

privilege ManagePublicList operation system.debug

privilege ViewPrivateList operation voicemail.lists.private.view

privilege vm-imap operation voicemail.imap.user

privilege local-broadcast operation broadcast.local

privilege local-broadcast operation system.debug

privilege broadcast operation broadcast.local

privilege broadcast operation broadcast.remote

privilege broadcast operation system.debug

privilege ViewRealTimeReports operation report.realtime

privilege ViewHistoricalReports operation report.historical.view

privilege manage-passwords operation user.password

privilege manage-passwords operation user.pin

privilege manage-passwords operation system.debug

privilege manage-users operation group.configuration

privilege manage-users operation user.configuration

privilege manage-users operation user.notification

privilege manage-users operation user.password

privilege manage-users operation user.remote

privilege manage-users operation user.mailbox

privilege manage-users operation user.pin

privilege manage-users operation system.debug

groupname Administrators member admin

groupname Broadcasters privilege broadcast

username dartmouthreception phonenumber "101"

restriction msg-notification create

restriction msg-notification min-digits 1

restriction msg-notification max-digits 30

restriction msg-notification dial-string preference 1 pattern * allowed

backup server url "ftp://127.0.0.1/ftp" credentials hidden "EWlTygcMhYmjazXhE/VNXHCkplVV4KjescbDaLa4fl4WLSPFvv1rWUnfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmPSd8ZZNgd+Y9J3xlk2B35j0nfGWTYHfmP"

calendar biz-schedule systemschedule

open day 1 from 00:00 to 24:00

open day 2 from 00:00 to 24:00

open day 3 from 00:00 to 24:00

open day 4 from 00:00 to 24:00

open day 5 from 00:00 to 24:00

open day 6 from 00:00 to 24:00

open day 7 from 00:00 to 24:00

end schedule

ccn application autoattendant aa

description "autoattendant"

enabled

maxsessions 16

script "aa.aef"

parameter "busClosedPrompt" "AABusinessClosed.wav"

parameter "holidayPrompt" "AAHolidayPrompt.wav"

parameter "welcomePrompt" "AAWelcome.wav"

parameter "disconnectAfterMenu" "false"

parameter "dialByFirstName" "false"

parameter "allowExternalTransfers" "false"

parameter "MaxRetry" "3"

parameter "dialByExtnAnytime" "false"

parameter "busOpenPrompt" "AABusinessOpen.wav"

parameter "businessSchedule" "systemschedule"

parameter "dialByExtnAnytimeInputLength" "4"

parameter "operExtn" "0"

end application

ccn application ciscomwiapplication aa

description "ciscomwiapplication"

enabled

maxsessions 16

script "setmwi.aef"

parameter "CallControlGroupID" "0"

parameter "strMWI_OFF_DN" "8001"

parameter "strMWI_ON_DN" "8000"

end application

ccn application msgnotification aa

description "msgnotification"

enabled

maxsessions 16

script "msgnotify.aef"

parameter "logoutUri" "http://localhost/voicemail/vxmlscripts/mbxLogout.jsp"

parameter "DelayBeforeSendDTMF" "1"

end application

ccn application promptmgmt aa

description "promptmgmt"

enabled

maxsessions 1

script "promptmgmt.aef"

end application

ccn application voicemail aa

description "voicemail"

enabled

maxsessions 16

script "voicebrowser.aef"

parameter "logoutUri" "http://localhost/voicemail/vxmlscripts/mbxLogout.jsp"

parameter "uri" "http://localhost/voicemail/vxmlscripts/login.vxml"

end application

ccn engine

end engine

ccn reporting historical

database local

description "se-10-1-1-2"

end reporting

ccn subsystem email

end subsystem

ccn subsystem fax

end subsystem

ccn subsystem sip

gateway address "192.168.30.1"

mwi sip unsolicited sub-notify

end subsystem

ccn trigger http urlname msgnotifytrg

application "msgnotification"

enabled

maxsessions 2

end trigger

ccn trigger http urlname mwiapp

application "ciscomwiapplication"

enabled

maxsessions 1

end trigger

ccn trigger sip phonenumber 2000

application "voicemail"

enabled

maxsessions 16

end trigger

ccn trigger sip phonenumber 3000

application "autoattendant"

enabled

maxsessions 16

end trigger

service phone-authentication

end phone-authentication

service voiceview

enable

end voiceview

voicemail broadcast recording time 300

voicemail default messagesize 240

voicemail notification restriction msg-notification

voicemail mailbox owner "dartmouthreception" size 3927

description "dartmouthreception mailbox"

no fax enable

end mailbox

end

Maren Mahoney · ‎10-18-2021

Dial-peer 40001 represents the dial-peer automatically created by the CME for the 101 DN. Each new SIP DN in CME will create a new dial-peer counting up from 40001. (SCCP DNs in CME are in the 20001 and up range).

The CUE config looks okay to me, so I'm not sure what's going on here. Can you run the following two debugs and post the output?

debug ccsip messages

debug voice dialpeer

Those two debugs will show us the exchange of SIP messages, and also the dial-peer selection process. This will tell us if the CME is sending the call to CUE at all. And, if so, the parameters of the call.

*PLEASE* post the output of the debug as an attached file to your reply. Simply pasting the output into your reply requires some reformatting before analysis. Thanks.

Maren

Luc Boudreau · ‎10-20-2021

Hi Maren,

Wondering if you had a chance to review the debugs I posted. Thanks!

Maren Mahoney · ‎10-20-2021

So first, I was wrong about the dial-peer selection. The debug voice dialpeer and the debug ccsip messages both clearly show the call flowing through the router to the CUE.

The SDP in the debug ccsip messages also clearly shows g711ulaw being negotiated. I do see the phone's call leg negotiating rtp-nte while the CUE is negotiating sip-notify. They need to match. When I've set up CME/CUE in the past I've used rtp-nte.

In CUE:
ccn subsystem sip
 dtmf-relay rtp-nte

In CME:
dial-peer voice 2000/3000
 dtmf-relay rtp-nte

The thing I don't see - and I don't know why I missed it in the first place - are the SIP bind commands. Everything else looks hunky-dory. Try adding the following. If this doesn't work, we may need to dig into a CUE debug, which I'm hoping we don't have to do:

voice service voip
 sip
 bind all source-interface GigabitEthernet0/0.20

Let us know how it goes.

Maren

Luc Boudreau · ‎10-20-2021

Thanks again Maren,

Unfortunately still the same after those modifications. My Debug CCSIP Error shows the following:

*Oct 20 16:27:40.472: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free: 
 Freeing NULL pointer!
SIP: (1207) Attribute mid, level 1 instance 1 not found.
SIP: (1207) setup attribute, level 1 instance 1 not found.
SIP: (1207) connection attribute, level 1 instance 1 not found.
SIP: (1207) Attribute label, level 1 instance 1 not found.
SIP: (1207) a=framerate attribute, level 1 instance 1 not found.
*Oct 20 16:27:40.480: //-1/xxxxxxxxxxxx/SIP/Error/voipCodec_to_rtpAvpCodec: 
 Unexpected VoIPCodec Type :No Codec   
*Oct 20 16:27:40.480: //-1/xxxxxxxxxxxx/SIP/Error/voipCodec_to_rtpAvpCodec: 
 Unexpected VoIPCodec Type :No Codec   
*Oct 20 16:27:40.480: //-1/xxxxxxxxxxxx/SIP/Error/voipCodec_to_rtpAvpCodec: 
 Unexpected VoIPCodec Type :No Codec   
*Oct 20 16:27:40.480: //-1/xxxxxxxxxxxx/SIP/Error/voipCodec_to_rtpAvpCodec: 
 Unexpected VoIPCodec Type :No Codec   
SIP: (1208) Group (a= group line) attribute, level 65535 instance 1 not found.
SIP: (1208) Group (a= group line) attribute, level 65535 instance 1 not found.
SIP: (1208) Group (a= group line) attribute, level 65535 instance 1 not found.
*Oct 20 16:27:40.488: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_reg_search_reg_number_table: 
 No entry found in reg Number Table for 101
VIGCME#
*Oct 20 16:27:40.488: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_reg_search_reg_number_table: 
 No entry found in reg Number Table for 2000
*Oct 20 16:27:40.488: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_validate_own_ip_addr: 
 ReqLine IP addr does not match with host IP addr
SIP: Attribute mid, level 1 instance 1 not found.
SIP: setup attribute, level 1 instance 1 not found.
SIP: connection attribute, level 1 instance 1 not found.
SIP: Attribute label, level 1 instance 1 not found.
SIP: a=framerate attribute, level 1 instance 1 not found.
*Oct 20 16:27:40.496: //1208/7AABEEB98320/SIP/Error/sipSPIGetNewLocalMediaDirection: 
 Unknown media direction (0) from remote end
VIGCME#
*Oct 20 16:27:44.648: //1208/7AABEEB98320/SIP/Error/sipSPIFlushDeferredQueue: 
 Invalid deferredQueue
VIGCME#
*Oct 20 16:28:05.392: //1202/753EC660831F/SIP/Error/sipSPIFlushDeferredQueue: 
 Invalid deferredQueue
VIGCME#
*Oct 20 16:28:09.356: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_reg_search_call_id_table: 
 No entry found in sipCallID Table
*Oct 20 16:28:09.356: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_validate_own_ip_addr: 
 ReqLine IP addr does not match with host IP addr
*Oct 20 16:28:09.356: //-1/xxxxxxxxxxxx/SIP/Error/check_supported_header_for_matching_tag: 
 Unable to access supported header values
*Oct 20 16:28:09.356: //-1/xxxxxxxxxxxx/SIP/Error/check_supported_header_for_matching_tag: 
 Unable to access supported header values
*Oct 20 16:28:09.856: //1209/8BE348508327/SIP/Error/ccsip_spi_register_incoming_registration: 
 Registration Authorization failed with authorization header=
*Oct 20 16:28:09.856: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_PassthruContentContainerFreeHelper: 
 Null ContentQ - Exit
*Oct 20 16:28:09.856: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_rpcb_search_cc_call_id_table: 
 No entry found in ccCallID Table
*Oct 20 16:28:09.860: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_reg_search_call_id_table: 
 No entry found in sipCallID Table
*Oct 20 16:28:09.860: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_validate_own_ip_addr: 
 ReqLine IP addr does not match with host IP addr
*Oct 20 16:28:09.860: //-1/xxxxxxxxxxxx/SIP/Error/check_supported_header_for_matching_tag: 
 Unable to access supported header values
*Oct 20 16:28:09.860: //-1/xxxxxxxxxxxx/SIP/Error/check_supported_header_for_matching_tag: 
 Unable to access supported header values
*Oct 20 16:28:10.364: //1209/8BE348508327/SIP/Error/ccsip_spi_register_incoming_registration: 
 Registration Authorization failed with authorization header=Digest username="", realm="", nonce="A898C107015EC814", qop=auth, cnonce="gzvXlbKPk5PIsx6", nc=00000001, uri="sip:192.168.30.1:5060", response="2f4b060852eab6d00a757c20da892126", algorithm=MD5
*Oct 20 16:28:10.364: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_PassthruContentContainerFreeHelper: 
 Null ContentQ - Exit

Not Sure if this helps at all.

Maren Mahoney · ‎10-20-2021

I'm not sure what is registering there. It's possible the bind commands are requiring a reset of SIP on the router. Try this to see if the registration errors stop.

voice service voip
 sip
  call service stop
  no call service stop

In the original debug ccsip messages it shows that the phone is sending RTP to the router and the router is sending RTP to CUE. But CUE is not sending RTP back. (That is shown in the P-RTP-Stat line in the BYE/OK messages.) So I believe the problem is in CUE. What is the licensing status in CUE? If you can get to the CUE GUI, what does it show for system/license/etc. status?

Maren

Luc Boudreau · ‎10-20-2021

Hi Maren,

The registration failure is actually a Polycom conference phone I was testing but all good, you can ignore that.

The license and system info is as follows for CUE

VIG-CUE# sh software licenses
Installed license files:
 - voicemail_lic.sig : 250 MAILBOX LICENSE
 - ivr_lic.sig : 8 PORT IVR BASE LICENSE

Core:
 - Application mode: CCME
 - Total usable system ports: 24

Voicemail/Auto Attendant:
 - Max system mailbox capacity time: 18000
 - Default # of general delivery mailboxes: 25
 - Default # of personal mailboxes: 250

 - Max # of configurable mailboxes: 275

Interactive Voice Response:
 - Max # of IVR sessions: 8

Languages:
 - Max installed languages: 5
 - Max enabled languages: 5

VIG-CUE# show software packages

Installed Packages:

 - Installer (Installer application) (7.0.6.0)
 - Thirdparty (Service Engine Thirdparty Code) (7.0.6)
 - Bootloader (Primary) (Service Engine Bootloader) (2.1.14)
 - Infrastructure (Service Engine Infrastructure) (7.0.6)
 - Global (Global manifest) (7.0.6)
 - Service Engine license (License for the Service Engine) (2.1.2.0)
 - Auto Attendant (Service Engine Telephony Infrastructure) (7.0.6)
 - Voice Mail (Voicemail application) (7.0.6)
 - Bootloader (Secondary) (Service Engine Bootloader) (2.1.14.0)
 - Core (Service Engine OS Core) (7.0.6)
 - GPL Infrastructure (Service Engine GPL Infrastructure) (7.0.6)

Installed Plug-ins:

 - CUE Voicemail Language Support (Languages global pack) (7.0.6)
 - CUE Voicemail Latin American Spanish (Latin American Spanish language pack) (7.0.6)
 - CUE Voicemail US English (English language pack) (7.0.6)

VIG-CUE# sh tech-su

------------------ show interfaces ------------------
GigabitEthernet 0 is up, line protocol is up
  Internet address is 192.168.30.5 mask 255.255.255.0 (configured on router)
     16097 packets input, 1795496 bytes
     0 input errors, 0 dropped, 0 overrun, 0 frame errors
     16869 packets output, 2369254 bytes
     0 output errors, 0 dropped, 0 overrun, 0 collision errors
     0 output carrier detect errors

GigabitEthernet 1 is up, line protocol is down
     0 packets input, 0 bytes
     0 input errors, 0 dropped, 0 overrun, 0 frame errors
     0 packets output, 0 bytes
     0 output errors, 0 dropped, 0 overrun, 0 collision errors
     0 output carrier detect errors

IDE hd0 is up, line protocol is up
     7242 reads, 126507008 bytes
     0 read errors
     3208 write, 44122112 bytes
     0 write errors


------------------ show java version ------------------
java version "J2ME Foundation Specification v1.1"
IBM J9 2.3 Linux x86-32  (JIT enabled)
J9VM - 20061023_08962_lHdFGQ
JIT  - 20060629_1804ifx1_r8
GC   - 200609_15
JCL  - 20070212_2313,foun11

Licensed Materials - Property of IBM

J9 - VM for the Java(TM) platform, Version 2.3
(c) Copyright IBM Corp. 1991, 2006  All Rights Reserved
Target: 20061023_08962_lHdFGQ (Linux 2.6.11.11cisco x86)
JIT  - 20060629_1804ifx1_r8

IBM is a registered trademark of IBM Corp.
Java and all Java-based marks and logos are trademarks or registered
trademarks of Sun Microsystems, Inc.


Apgee Delivery ID: "2008.May.30.j9231.foun11.j14.x86.lnx.tar.gz"
                   "2008.May.30.classpath090.j9231.foun11.x86.lnx.tar.gz"

------------------ show memory ------------------
SDRAM (MByte):                512
Total Memory (kB):            512312
Active Memory (kB):           269160
Inactive Memory (kB):         36648
Other Memory (kB):            24380
MemoryPool (kB):              182124

Kernel Memory
MAXUSED(S) INUSE(S) INUSE(O) MAXUSED(O)     ERR TYPE            
      4252     4184     4027       4107       0 fs              
     14532    14108    13244      13749       0 other           
       308      240      201        282       0 net             
S - Slab memory
O - Object memory

------------------ show processes memory ------------------
   VSZ   RSS   SHR   PVT    RD    RW   EXE   DAT   STK  %PVT CMD             
 12728  1428  1040   388     0     0   100  2784     0   0.1 syslog-ng       
 22756  1440  1152   288     0     0    64 12832     0   0.1 platform_config 
 10432  1188   996   192     0     0    28   540     0   0.0 rbcp            
 16372  2600  1276  1324     0     0    20  4656     0   0.3 trace           
  2564  1220  1008   212     0     0   572   468     0   0.0 monitor         
 18892  1440  1164   276     0     0   216  8808     0   0.1 ntp             
 23556  3844  1484  2360     0     0    20 11840     0   0.5 downloader      
 10388  1124   960   164     0     0    12   536     0   0.0 probe           
 16664     0     0     0     0     0     0     0     0   0.0 sql             
 18004  4028  2656  1372     0     0    80  6004     0   0.3 ldap            
 82176 46076  3504 42572     0     0    44 68216     0   8.3 http            
 82176 46076  3504 42572     0     0    44 68216     0   8.3 mgmt            
 82176 46076  3504 42572     0     0    44 68216     0   8.3 snmp            
 75948 39776  3136 36640     0     0    44 63808     0   7.2 superthread     
 75948 39776  3136 36640     0     0    44 63808     0   7.2 entitymanager   
 75948 39776  3136 36640     0     0    44 63808     0   7.2 SubsystemEditorExpress
 75948 39776  3136 36640     0     0    44 63808     0   7.2 webapp          
 75948 39776  3136 36640     0     0    44 63808     0   7.2 umg-registration
 75948 39776  3136 36640     0     0    44 63808     0   7.2 cli             
 75948 39776  3136 36640     0     0    44 63808     0   7.2 umg-directory   
 75948 39776  3136 36640     0     0    44 63808     0   7.2 llama           
 75948 39776  3136 36640     0     0    44 63808     0   7.2 sitemanager     
 96352 54588  2728 51860     0     0    44 83344     0  10.1 ccn             
 75948 39776  3136 36640     0     0    44 63808     0   7.2 usermanager2    
 82176 46076  3504 42572     0     0    44 68216     0   8.3 imap

Maren Mahoney · ‎10-20-2021

Give a try with the call service stop/no call service stop commands to reset the SIP UA after the bind to see if that fixes things.

If not, I am out of ideas. I do think the issue is in CUE, but I am not skilled at reading CUE trace files. It might be time to call TAC for assistance.

Maren

Luc Boudreau · ‎10-31-2021

After more troubleshooting, a software update on the CUE module has resolved the issue. Was running 7.0.6 and now running 8.6.1. All working as expected now.

Luc Boudreau · ‎10-18-2021

Thanks Maren,

I realized the dial-peer creation for the DNs after I had already posted my comment. Guess I didn't have enough coffee this morning.

Attached are the two debugs.

Steven L · ‎10-20-2021

Try adding "supplementary-service media-renego" under voice service voip and then test

Luc Boudreau · ‎10-20-2021

Thanks,

That did not work unfortunately. Still no audio. The call connects but just dead air. The CCSIP Error debug shows "No Codec" on some lines. Very odd issue. First time i've run into it.