Buy or Renew
Buy or Renew
Cisco + Splunk: It’s a new day for your data. Learn more.
 
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
1380
Views
0
Helpful
2
Replies

CUBE to IPTSP provider

MD KAFINUZZAMAN
Level 1
Level 1

‎07-16-2016 10:17 PM - edited ‎03-17-2019 07:33 AM

Dear Expert,

My CUBE Router this error. When I dial outside number. My ip phone 1st giving a dial tone then giving busy tone.

Router#
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: cr      eated msg=0x257267C0 with refCount = 1
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: cr      eated msg=0x2747D114 with refCount = 1
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4Socket      Reads: Msg enqueued for SPI with IP addr: [172.16.145.3]:5060, local_address:[17      2.16.128.7]
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Free      d msg=0x257267C0
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_q      ueue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewCon      nMsg: context=0x0
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:01959700860@172.16.128.7:5060 SIP/2.0
Via: SIP/2.0/UDP 172.16.145.3:5060;branch=z9hG4bKc3632bab131
From: "x" <sip:9613400400@172.16.145.3>;tag=10192~a0937ad5-4be7-4d93-b8c0-0d5b06      693de8-17377082
To: <sip:01959700860@172.16.128.7>
Date: Sun, 17 Jul 2016 05:02:05 GMT
Call-ID: 99ad0a00-78b1114d-bcc-39110ac@172.16.145.3
Supported: timer,resource-priority,replaces
Min-SE:  1800
User-Agent: Cisco-CUCM11.0
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE,       NOTIFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence, kpml
Supported: X-cisco-srtp-fallback,X-cisco-original-called
Call-Info: <sip:172.16.145.3:5060>;method="NOTIFY;Event=telephone-event;Duration      =500"
Call-Info: <urn:x-cisco-remotecc:callinfo>;x-cisco-video-traffic-class=DESKTOP
Session-ID: d8c5114d1a284522844805577aa10191;remote=0000000000000000000000000000      0000
Cisco-Guid: 2578254336-0000065536-0000001323-0059838636
Session-Expires:  1800
P-Asserted-Identity: "x" <sip:9613400400@172.16.145.3>
Remote-Party-ID: "x" <sip:9613400400@172.16.145.3>;party=calling;screen=yes;priv      acy=off
Contact: <sip:9613400400@172.16.145.3:5060>
Max-Forwards: 69
Content-Length: 0


Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_prepr      ocessor: Checking Invite Dialog
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToT      able: Added context(0x288953F0) with key=[53] to table
Jul 17 11:02:14.005: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_servi      ce_init:
Jul 17 11:02:14.005: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_serv      ice_init:
Jul 17 11:02:14.005: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_f      orking_init: MF: Queue is initialised..
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: D      ialog Transaction Address 172.16.145.3,Port 5060, Transport 1, SentBy Port 5060v      rfid 0
Jul 17 11:02:14.005: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address      _to_bind: VRF id = 0
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: i      p_address IPv4 172.16.128.7 for SIP
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_      bind: ip_get_ifaddress IPv4 172.16.128.7 for SIP
Jul 17 11:02:14.005: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address      _to_bind: signaling bind address : 172.16.128.7
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address      _to_bind: return addr 172.16.128.7
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/State/sipSPIChangeState: 0x288953F0 :       State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: D      ialog Transaction Address 172.16.145.3,Port 5060, Transport 1, SentBy Port 5060v      rfid 0
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader      : Clock Time Zone is UTC, same as GMT: Using GMT
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: D      ialog Transaction Address 172.16.145.3,Port 5060, Transport 1, SentBy Port 5060v      rfid 0
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Incr      ement msg (0x2747D114) counter, current msg->refCount = 2
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free:
 Freeing NULL pointer!
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/4096/sipSPIAssignCcbLast      Request: Current ccb(0x288953F0)->last_request = 0x2747D114, refCount = 2
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/2048/sipSPICheckIpip: VOIP       dialpeer (peer=0x9F5F2C4) found for sip_user: 01959700860
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/2048/sipSPICheckAssertedIdC      onfig: Dialpeer match is not yet done
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/36864/sipSPIUpdateIdentity:       MF: PAI url is present & make a copy..
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/4096/sipSPIUpdateIdentity:       SIP->PSTN: Setting Calling Name to x
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/4096/sipSPIUpdateIdentity:       PAI  genUrl is present..
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/4096/sipSPIUpdateIdentity:       SIP->PSTN: Setting Calling Number to 9613400400
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/4096/sipSPIUpdateIdentity:       PAI host = 172.16.145.3
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/4096/sipSPISetCallingInfo:       calling host comes from From: 172.16.145.3
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/2048/sipSPICheckAssertedIdC      onfig: Dialpeer match is not yet done
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGT      D: No GTD found in inbound container
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentCS      TA: No CSTA found in inbound container
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTabl      e: Added to table. ccb=0x288953F0 key=99ad0a00-78b1114d-bcc-39110ac@172.16.145.3      01959700860 balance 1
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8192/sipSPIMatchSrcIpGroup:       Match not found on carrier id
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/8192/sipSPIMatchSrcIpGr      oup: Match not found on Incoming called number: 01959700860
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/8192/sipSPIMatchSrcIpGr      oup: Match not found on destination pattern: 9613400400
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/12288/ccsipUpdateIncomingCa      llParams: ccCallInfo: Calling name x, number 9613400400, Calling oct3 0x00, oct_      3a 0x81, Called number 01959700860
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/1024/sipSPIGetViaHostInU      RLFormat: VIA URL:sip:172.16.145.3:5060, Host:172.16.145.3
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/67584/sipSPIGetShrlPeer:       Try match incoming dialpeer for Calling number: : 9613400400
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/1024/sipSPIGetFromCalle      dPartyId: P-Called-Party-ID header not found
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/1024/sipSPIGetPeerByCal      ledPartyId: P-Called-Party-ID not found or parse error
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/10240/sipSPIGetCallConf      ig: No match found for P-Called-Party-ID
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/1024/ccsip_validate_and_upd      ate_calling_info: PAI/PPI not configuredi for this dial-peer(2364), use RPID/FRO      M header data
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/4096/sipSPIUpdateCalling      InfoUsingRpidOrFrom: Updating Calling Info with FROM header data
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/2048/sipSPIGetCallConfig: P      eer tag 2364 matched for incoming call
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/1024/sipSPIGetCallConfig      : Precondition tag absent in Require/Supported header
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8192/resolve_sig_ip_address      _to_bind: VRF id = 0
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: i      p_address IPv4 172.17.5.250 for SIP
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_      bind: ip_get_ifaddress IPv4 172.17.5.250 for SIP
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8192/resolve_sig_ip_address      _to_bind: signaling bind address : 172.17.5.250
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address      _to_bind: return addr 172.17.5.250
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/1024/sipSPIGetCallConfig      : Precondition tag absent in Require/Supported header
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/2048/sipSPIGetCallConfig      : Media Antitrombone disabled
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8192/sipSPISetMediaFlowMode      : Storing the configured mode as FLOW-THROUGH
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/2304/sipSPISetMediaFlowMode      : xcoder high-density disabled
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8192/sipSPISetMediaFlowMode      : Flow Mode set to FLOW_THROUGH
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/1/sipSPIGetCallConfig: Usin      g Voice Class Codec, tag = 99 and offer-all is = FALSE
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Media/sipSPICopyStunConfigFromPeerToC      CB: Firewall traversal is not enabled
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/12288/sipSPIGetModemInfo      PerCall: peer_callID=0
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/32768/ccsip_ipip_media_      forking_update_preferred_codec: MF: Not a Forked SIP leg..
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8704/sipSPIGetCallConfig: I      ncoming: No defer BYE for last
                              call stats
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/1/ccsip_set_srtp_config:       No Srtp configure for this leg.
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8192/sipSPIGetCallConfig: M      edia forking disabled
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/34816/ccsip_ipip_media_fork      ing_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/34816/ccsip_ipip_media_fork      ing_anchor_leg_config: MF: Dial-peer has no media class recorder.
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/36864/sipSPIMFChangeState:       MF: Prev state = 0 & New state = -1
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/32768/ccsip_ipip_media_fork      ing_anchor_leg_reset: MF: Anchor leg config reset done...
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/32768/ccsip_ipip_media_fork      ing_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass       = 0
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/32768/ccsip_ipip_media_fork      ing_get_forked_leg_config: MF: This leg is not forked call leg.
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/11264/ccsipInitDSCPPoli      cyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/8192/sipSPIGetCallConfig      : Initilise the DSCP policy
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/8192/sipSPICheckFAAnatAs      symetricOrDO2EO: Not a SIP-SIP call or not in FA mode
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/notify/2049/populate_vcc_data: U      sing Voice Class Codec, tag = 99 and offer-all is = FALSE
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/notify/8192/sipSPISetOverlapConf      iguration: Overlap signaling: FALSE: Endpt: SIP Trunk
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/verbose/10240/sipSPI_ipip_GetHdr      PassthruCfg: Hdr passthrough config:1 tag:0
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/verbose/2048/sipSPI_ipip_GetCopy      ListCfg: Copy-list config:2 tag:0
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/info/2048/sipSPIGetExtensionCfg:       SIP extension config:1, check sys cfg:1
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/notify/10240/sipSPI_ipip_build_c      onsolidated_header_list: Both passthru and copylist are disabled
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/info/4096/sipSPIContinueNewMsgIn      vite: Calling name x, number 9613400400, Calling oct3 0x00, oct_3a 0x80, ext_pri      v 0x00, Called number 01959700860, oct3 0x00
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/info/4096/sipSPIContinueNewMsgIn      vite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp       NONE
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/critical/10240/sipSPIValidateReq      uestUri: Not Enabled
Jul 17 11:02:14.007: //-1/99AD0A000000/SIP/Info/info/131072/sipSPIRscmsmAvail: V      alue returned by check is = 0
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/4096/sipSPICheckOutBoun      dDpProvisioning: Cannot obtain the the header bitmap
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/8192/sipSPI_ipip_IsSDPP      assthruEnabled:  - 0
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Event/Session-Timer/sipSTSLMain: Even      t: E_STSL_SESSION_REFRESH_REQ
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Event/Session-Timer/sipSTSLMain: dir:      2, method:102, resp_code:0, container:289B8D90
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/8192/Session-Timer/sipSTSLE      xtractSessionExpiresHdr:
Session-Expires value: 1800 refresher: none
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/8192/Session-Timer/sipSTSLE      xtractMinSEHdr: Min-SE Duration: 1800
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/10240/Session-Timer/sipSTSL      AdjustConfigIntervals: Changing config min-se:360 to 1800
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/10240/Session-Timer/sipSTSL      AdjustConfigIntervals: Changing config se:360 to 1800
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/8192/Session-Timer/sipSTSLG      etInternalSREvent: E_STSL_INITIAL_SR_REQ
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/8192/Session-Timer/sipST      SLInitialSRReqPeerEventGen: sending received session expires to the peer leg
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Event/Session-Timer/sipSTSLPrintTDCon      tainer: Peer-Event: E_STSL_PASS_ST_PARAMS, SE Value:1800, SE Refresher:none, Min      -SE Value:1800, flags:2001
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/8192/Session-Timer/sipSTSLM      ain:
        SE: 1800;refresher:none peer refresher:none, flags:2001, posted event:E_      STSL_INVALID_PEER_EVENT, reason:4
        Configured SE:1800, Configured Min-SE:1800
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/1024/sipSPIProcessHisto      ryInfoHeader: No HI headers recvd from app container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/1024/sipSPIProcessDiver      sionHeader: No diversion headers recvd from app container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/1024/sipSPIProcessNotify      CallInfoHeader: Callinfo parsed - Destination url = <sip:172.16.145.3:5060>, dur      ation = 500

Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/16384/sipSPIProcessRepl      acesHeader: No replaces hdr found
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/verbose/1024/sipSPIGetContentCPA      : No CPA found in inbound container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/1024/sipSPIProcessCPA: N      o x-cisco-cpa content found
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContentSDP      : No SDP found in inbound container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131072/sipSPIDoQoSNegotiati      onWithNoMediaLine: Local Precondition: 1, Remote Precondition: 1
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/notify/131072/sipSPICanSetFallba      ckFlag: Local Fallback is not active
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/1/sip_iwf_def_copy_sdp_t      o_channelInfo:
CallID 53, sdp 0x25FCF33C channels 0x28896D10
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/131073/sip_iwf_def_copy      _sdp_to_channelInfo: bwcac no sdp
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131074/sipSPIBwCacCalcMaxAu      dioBandwidth: calculating max bw from preffered codecs (local offer)
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Error/sipSPICheckAnatGroupPresent:
 NULL sdp
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131074/sipSPIBwCacCalcMaxAu      dioBandwidth: max bw (excluding pak overhead) from preffered codecs: codec g711u      law      bw 64000        index 0
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/verbose/16/sipSPIBwCacGetSrtpOve      rhead: Return: 0
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_      ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131074/sipSPIBwCacCalcMaxAu      dioBandwidth:  max bw (including pak overhead) from preffered codecs: codec g711      ulaw     bw 80000
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131086/sipSPIBwCacCalcDialP      eerBandwidth: bwcac dial-peer audio bw 80000 bps video bw 0 bpsfax bw 0 bps
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131072/sipSPIBwCacUpdateAcc      ountedBw: 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
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131072/sipSPIBwCacUpdateInt      erfaceBw: bwcac acquiring interface GigabitEthernet0/0 bw 80
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131072/sipSPIBwCacUpdateAcc      ountedBw: bwcac update accounted bw (initial offer) accounted bw set to 80000
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/133120/sipSPIBwCacIsDialPee      rBwAvailable: bwcac NOP dial-peer bw available tag 2364
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/notify/1/sipSPIBwCacIsInterfaceB      wAvailable: bwcac interface bw threshold not configured
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/131072/sipSPIBwCacVerifyBwT      hreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/8192/sipSPIUpdateSrcSdpFixe      dPart: Delayed media case...creating new stream
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/notify/6/sipSPIValidateStreamAdd      rType: stream:1, Mode : 1
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/513/resolve_media_ip_add      ress_to_bind: peer_tag=2364
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_addre      ss_to_bind: VRF id = 0
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: i      p_address IPv4 172.17.5.250 for SIP
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_      bind: ip_get_ifaddress IPv4 172.17.5.250 for SIP
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Media/sipSPISetMediaSrcAddr: Media sr      c addr for stream 1 = 172.17.5.250
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved       port 16488 for stream 1
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/1/sipSPIUpdateSrcSdpFixe      dPart: Reserving rtp port for stream 1, src_port=16488
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Media/sipSPIAddSDPMediaPayload: Prefe      rred method of dtmf relay is: 6, with payload: 101
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_      ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_      ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPIAddBillingInf      oToCcb: sipCallId for billing records = 99ad0a00-78b1114d-bcc-39110ac@172.16.145      .3
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/ccsip_api_call_setu      p_ind: Headers from INVITE added to callInfo container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/16384/sipSPI_ipip_AddInv      DataToTDContainer: req_uri = sip:01959700860@172.16.128.7:5060
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/16384/sipSPI_ipip_AddInv      DataToTDContainer: to = <sip:01959700860@172.16.128.7>
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/16384/ccsip_api_call_set      up_ind: retVal = 0

Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/10240/sipSPI_ipip_GetHdr      PassthruCfg: Hdr passthrough config:1 tag:0
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/10240/sipSPI_ipip_Extra      ctPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not confi      gured and no headers are present in hdr_hash_queue
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/8192/sipSPI_ipip_IsCont      entPassthruEnabled:  - 0
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/notify/8192/sipSPI_ipip_ExtractP      assthruContentFromSipContainer: Passthru Content Not Enabled
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/4096/ccsip_api_call_set      up_ind: Unable to add unsupp headers to container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPICopyAuthentic      ationHeadersToContainer: sipAuthInfo Initialized
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPICopyAuthentic      ationHeadersToContainer: Set Authentication Tag to Container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/ccsip_api_call_setu      p_ind: Set Protocol information
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/ccsip_ipip_media_se      rvice_get_event_data: Event id = 27
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPI_ipip_store_c      hannel_info: Store channelInfo in CallInfo
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/2080/sipSPI_ipip_store_chan      nel_info: negotiated dtmf not available, using dialpeer config dtmf = 8
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/2048/sipSPI_ipip_store_c      onfig_info: Setting mid_call_config_info = 0x0 for callid = 53
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Media/sipSPIDisplayStreamInfo:
          Stream type            : voice+dtmf
          Media line             : 1
          State                  : STREAM_IDLE (1)
          Stream address type    : 1
          Callid                 : -1
          Peer Callid            : -1
          RTP/SRTP Negotiated     : 0
          Negotiated Codec       : No Codec   , bytes :0
          Nego. Codec payload    : 255 (tx), 255 (rx)
          Negotiated DTMF relay  : inband-voice
          Negotiated NTE payload : 0 (tx), 0 (rx)
          Negotiated CN payload  : 0
          Media Srce Addr/Port   : [172.17.5.250]:16488
          Media Dest Addr/Port   : [ - ]:0

Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4097/sipSPI_ipip_calcula      te_channel_count: Number of streams to report = 0
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/1/sipSPI_ipip_store_chan      nel_info: Setting CHANNEL_COUNT = 0 for callid 53
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/67584/sipSPIShrlCall: Ch      eck peer: 2364 for Shared-Line call, callid: 53
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/8192/ccsip_set_bearer_capab      ility:   Bearer Capability: Speech (0x00)
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQS      IG: No QSIG Body found in inbound container
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQ9      31: No RawMsg Body found in inbound container
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/critical/12288/sipSPICreateNewRa      wMsg: No Data to form The Raw Message

Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/4096/sipSPIContinueNewMsgIn      vite: ccsip_api_call_setup_ind returned: SIP_SUCCESS_DELAYED_MEDIA
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPIUaddccCallIdT      oTable: Adding call id 35 to table
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/2/sipSPIUpdateCallEntry:
Call 53 set InfoType to SPEECH
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPISendInviteRes      ponse: Dialog State: [0]
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: cr      eated msg=0x256F0968 with refCount = 1
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Event/Session-Timer/sipSTSLMain: Even      t: E_STSL_SESSION_REFRESH_RESP
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Event/Session-Timer/sipSTSLMain: dir:      1, method:102, resp_code:100, container:289BAE90
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/critical/8192/Session-Timer/sipS      TSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/8192/sipSPIPresendProces      sing: Presend Processing called for 3 event
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/notify/4096/sipSPI_ipip_GetPasst      hruCopyListDataFromTdContainer: Could not get any elements from TD Container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/notify/4096/sipSPI_ipip_GetPasst      hruCopyListDataFromTdContainer: Could not get any elements from TD Container
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/6144/addAllowHeaderKpml:       KPML Subscriptions allowed.
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/4096/sipSPISendInviteRespon      se: Associated container=0x289BAE90 to Invite Response 100
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleCont      ainerBody: sipSPIAppHandleContainerBody len 0
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Transport/sipSPITransportSendMessage:       msg=0x256F0968, addr=172.16.145.3, port=5060, sentBy_port=5060, local_addr=172.      17.5.250, is_req=0, transport=1, switch=0, callBack=0x0
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/2048/sipSPIGetExtensionCfg:       SIP extension config:1, check sys cfg:1
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/info/2048/sipSPIGetExtensionCfg:       SIP extension config:1, check sys cfg:1
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Transport/sipSPITransportSendMessage:       Proceedable for sending msg immediately
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Transport/sipTransportLogicSendMsg: T      rying to send resp=0x256F0968 to default port=5060
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConn      ection: connection required for raddr:172.16.145.3, rport:5060 with laddr:172.17      .5.250

Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId:       Registering gcb=0x288953F0 with connection=0x271812B0 context list
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Transport/sipTransportLogicSendMsg: C      onnection obtained...sending msg=0x256F0968
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage      : Posting send for msg=0x256F0968, addr=172.16.145.3, port=5060, local_addr=172.      17.5.250, connId=5 vrfid=0 for UDP
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/State/sipSPIChangeState: 0x288953F0 :       State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_RECD_INVITE, SUBSTATE_      NONE)
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4608/sipSPIProcessContac      tInfo: Previous Hop 172.16.145.3:5060
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.145.3:5060;branch=z9hG4bKc3632bab131
From: "x" <sip:9613400400@172.16.145.3>;tag=10192~a0937ad5-4be7-4d93-b8c0-0d5b06      693de8-17377082
To: <sip:01959700860@172.16.128.7>
Date: Sun, 17 Jul 2016 11:02:14 GMT
Call-ID: 99ad0a00-78b1114d-bcc-39110ac@172.16.145.3
CSeq: 101 INVITE
Allow-Events: kpml, telephone-event
Server: Cisco-SIPGateway/IOS-15.5.1.T2
Content-Length: 0


Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Free      d msg=0x256F0968
Jul 17 11:02:14.007: //53/99AD0A000000/SIP/Info/verbose/4096/ccsip_call_copy_num      bers: Number Translation Set For Called-Number
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event f      rom SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
Jul 17 11:02:14.007: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToT      able: Added context(0x2887BCF0) with key=[54] to table
Jul 17 11:02:14.007: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_servi      ce_init:
Jul 17 11:02:14.007: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_serv      ice_init:
Jul 17 11:02:14.007: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_f      orking_init: MF: Queue is initialised..
Jul 17 11:02:14.009: //54/000000000000/SIP/State/sipSPIChangeState: 0x2887BCF0 :       State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg:       SIP extension config:1, check sys cfg:1
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_      forking_read_from_TDContainer: MF: Unable to read data from TD Container..
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_      forking_forked_leg_config: MF: TD container cannot be read/container is NULL. Se      tting of forked call leg failed..
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi      _event_to_iwf_event: Event Category: 1, Event Id: EV_UNDEFINED
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi      _event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_MODE
Jul 17 11:02:14.009: //54/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_con      tainer:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, eve      nt:E_SIP_IWF_EV_SET_MODE
Jul 17 11:02:14.009: //54/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_con      tainer:sip_iwf_main_container
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm      _set_mode_ev:
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md_snr      :
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm      _set_mode_ev:
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed_snr      :
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm      _set_mode_ev:
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md:
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm      _set_mode_ev:
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed:
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/verbose/8192/sip_iwf_sip_ed_set_      mode_hdlr: Setting SPI mode to SIP-SIP
Jul 17 11:02:14.009: //54/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_con      tainer:sip_iwf_sip_early_dialog_container
Jul 17 11:02:14.009: //54/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:next_st      ate:CNFSM_NO_STATE_CHANGE
Jul 17 11:02:14.009: //54/000000000000/SIP/Info/info/4096/ccsip_iwf_handle_peer_      event: Return value: SIP_IWF_SUCCESS2.17.5.250:5060>
Call-Info: <sip:172.17.5.250:5060>;method="NOTIFY;Event=telephone-event;Duration      =500"
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-15.5.1.T2
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 246

v=0
o=CiscoSystemsSIP-GW-UserAgent 191 7754 IN IP4 172.17.5.250
s=SIP Call
c=IN IP4 172.17.5.250
t=0 0
m=audio 16488 RTP/AVP 0 101
c=IN IP4 172.17.5.250
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

Jul 17 11:02:14.091: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Free      d msg=0x23645BA8
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: cr      eated msg=0x23645BA8 with refCount = 1
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: cr      eated msg=0x25791EE0 with refCount = 1
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4Socket      Reads: Msg enqueued for SPI with IP addr: [172.16.145.3]:5060, local_address:[17      2.16.128.7]
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Free      d msg=0x23645BA8
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_q      ueue_event: ccsip_spi_get_msg_type returned: 2 for event 1
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewCon      nMsg: context=0x0
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
CANCEL sip:01959700860@172.16.128.7:5060 SIP/2.0
Via: SIP/2.0/UDP 172.16.145.3:5060;branch=z9hG4bKc3632bab131
From: "x" <sip:9613400400@172.16.145.3>;tag=10192~a0937ad5-4be7-4d93-b8c0-0d5b06      693de8-17377082
To: <sip:01959700860@172.16.128.7>
Date: Sun, 17 Jul 2016 05:02:05 GMT
Call-ID: 99ad0a00-78b1114d-bcc-39110ac@172.16.145.3
User-Agent: Cisco-CUCM11.0
CSeq: 101 CANCEL
Max-Forwards: 70
Session-ID: d8c5114d1a284522844805577aa10191;remote=4037e106e19341fc27cf7e842ab1      0192
Content-Length: 0


Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_prepr      ocessor: Checking Invite Dialog
Jul 17 11:02:16.733: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPIFindCcbUASReq      Table: *****CCB found in UAS Request table. ccb=0x288953F0
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Incr      ement msg (0x25791EE0) counter, current msg->refCount = 2
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: S      ubsq Transaction Address 172.16.145.3,Port 5060, Transport 1, SentBy Port 5060vr      fid 0
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader      : Clock Time Zone is UTC, same as GMT: Using GMT
Jul 17 11:02:16.733: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: S      ubsq Transaction Address 172.16.145.3,Port 5060, Transport 1, SentBy Port 5060vr      fid 0
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/info/4096/sipSPISetCallingInfo:       calling host comes from From: 172.16.145.3
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/4096/sipSPIUpdateCalling      InfoUsingRpidOrFrom: Updating Calling Info with FROM header data
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/4096/ccsip_set_release_s      ource_for_peer: ownCallId[53], src[2]
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/State/sipSPIChangeState: 0x288953F0 :       State change from (STATE_RECD_INVITE, SUBSTATE_NONE)  to (STATE_DISCONNECTING,       SUBSTATE_NONE)
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: cr      eated msg=0x23645BA8 with refCount = 1
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Transport/sipSPISendCancelResponse: S      ending CANCEL Response to the transport layer
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Transport/sipSPITransportSendMessage:       msg=0x23645BA8, addr=172.16.145.3, port=5060, sentBy_port=5060, local_addr=172.      17.5.250, is_req=0, transport=1, switch=0, callBack=0x0
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/info/2048/sipSPIGetExtensionCfg:       SIP extension config:1, check sys cfg:1
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/info/2048/sipSPIGetExtensionCfg:       SIP extension config:1, check sys cfg:1
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Transport/sipSPITransportSendMessage:       Proceedable for sending msg immediately
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Transport/sipTransportLogicSendMsg: T      rying to send resp=0x23645BA8 to default port=5060
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConn      ection: connection required for raddr:172.16.145.3, rport:5060 with laddr:172.17      .5.250

Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId:       gcb=0x288953F0 is already on connection=0x271812B0 context_list
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Transport/sipTransportLogicSendMsg: C      onnection obtained...sending msg=0x23645BA8
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage      : Posting send for msg=0x23645BA8, addr=172.16.145.3, port=5060, local_addr=172.      17.5.250, connId=5 vrfid=0 for UDP
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGT      D: No GTD found in inbound container
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/critical/4096/sipSPIInitiateDisc      onnect: Initiate call disconnect(16) for incoming call
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decr      ement msg (0x2747D114) counter, current msg->refCount = 1
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQS      IG: No QSIG Body found in inbound container
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentQ9      31: No RawMsg Body found in inbound container
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/4096/ccsip_ipip_media_se      rvice_get_event_data: Event id = 29
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/critical/32768/ccsip_ipip_media_      forking_post_event: MF: Not a Anchor SIP leg..
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/10240/sipSPI_ipip_GetHdr      PassthruCfg: Hdr passthrough config:1 tag:0
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/critical/10240/sipSPI_ipip_Extra      ctPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not confi      gured and no headers are present in hdr_hash_queue
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/critical/8192/sipSPI_ipip_IsCont      entPassthruEnabled:  - 0
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/notify/8192/sipSPI_ipip_ExtractP      assthruContentFromSipContainer: Passthru Content Not Enabled
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/info/1024/sipAddSipContainerToCa      llEntry: Unable to add passthru hdrs to container
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/State/sipSPIChangeState: 0x288953F0 :       State change from (STATE_DISCONNECTING, SUBSTATE_NONE)  to (STATE_DISCONNECTING      , SUBSTATE_NONE)
Jul 17 11:02:16.735: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decr      ement msg (0x25791EE0) counter, current msg->refCount = 1
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/4096/ccsip_ipip_media_se      rvice_get_event_data: Event id = 18
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_      container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_S      TATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_XCODER_RESET_STREAM
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/256/sipSPIResetXcoder: *      ****CLEANING UP XCODER RESOURCES*****
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/256/sipSPIResetXcoder: *      ****CLEANING UP XCODER RESOURCES*****
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/verbose/256/sipSPIResetXcoder: X      coder resource already cleaned up
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/State/ccsip_cnfsm_debugs: IPIPMS:next      _state:S_IPIP_MEDIA_SERV_STATE_IDLE
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for stream type 1
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for nte
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for nse
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for stream type 0
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for nte
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for nse
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/critical/1/sipSPIUpdateMediapoli      cy: media policy block does not exist
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Media/sipSPIUpdateRtpSession: stun is       disabled for stream:2747CB04
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/Info/verbose/4096/ccsip_ipip_media_se      rvice_get_event_data: Event id = 18
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_      container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_S      TATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_XCODER_RESET_STREAM
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/Info/verbose/256/sipSPIResetXcoder: *      ****CLEANING UP XCODER RESOURCES*****
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/Info/verbose/256/sipSPIResetXcoder: *      ****CLEANING UP XCODER RESOURCES*****
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/Info/verbose/256/sipSPIResetXcoder: X      coder resource already cleaned up
Jul 17 11:02:16.735: //54/99AD0A000000/SIP/State/ccsip_cnfsm_debugs: IPIPMS:next      _state:S_IPIP_MEDIA_SERV_STATE_IDLE
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for stream type 0
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for nte
Jul 17 11:02:16.735: //53/99AD0A000000/SIP/Info/notify/8193/updateGccbTxRxValues      : No interworking required for nse ACK sip:4001@182.16.159.6:5060 SIP/2.0
Via: SIP/2.0/UDP 172.17.5.250:5060;branch=z9hG4bK1A19F5
From: "x" <sip:9613400400@172.17.5.250>;tag=2E9CBA-413
To: <sip:4001@182.16.159.6>;tag=aqxpylro3zggjzfd.i
Date: Sun, 17 Jul 2016 11:02:14 GMT
Call-ID: C0747ED5-4B4411E6-80A38B0D-ED495C90@172.17.5.250
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: kpml, telephone-event
Content-Length: 0


Jul 17 11:02:16.767: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Free      d msg=0x256F0ED4
Router#
Router#
Router#
Jul 17 11:02:32.893: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing      : Holder=0x25791364 Connection=0x271812B0, addr=172.16.145.3, port=5060, connid=      5 has been REFRESHED
Jul 17 11:02:32.893: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer:       Aging timer initiated for holder=0x25791364,addr=172.16.145.3
Jul 17 11:02:37.973: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing      : Holder=0x25723F98 Connection=0x271810E0, addr=182.16.159.6, port=5060, connid=      4 has been REFRESHED
Jul 17 11:02:37.973: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer:       Aging timer initiated for holder=0x25723F98,addr=182.16.159.6
Router#
Router#
Jul 17 11:02:48.767: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContext      FromTable: Context for key=[54] removed.
Jul 17 11:02:48.767: //54/99AD0A000000/SIP/Info/info/4096/sipSPIStopCommonTimer:       Stopping Generic Timer 2
Jul 17 11:02:48.767: //54/99AD0A000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFro      mTable: Deleting from table. ccb=0x2887BCF0 key=C0747ED5-4B4411E6-80A38B0D-ED495      C90@172.17.5.250
Jul 17 11:02:48.767: //54/99AD0A000000/SIP/Info/verbose/4096/sipSPIFlushEventBuf      ferQueue: There are 0 events on the internal queue that are going to be free'd
Jul 17 11:02:48.767: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregis      terCtxtInConnection: gConnTab=0x2717FD20, addr=182.16.159.6, port=5060, local_ad      dr=172.17.5.250, unregistering context=0x2887BCF0
Jul 17 11:02:48.767: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInCo      nnection: Purging context gcb=0x2887BCF0 from the connection=0x271810E0 context       list
Jul 17 11:02:48.767: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Free      d msg=0x2747CB04
Jul 17 11:02:48.767: //54/99AD0A000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec      _profile: Codec Profiles Freed
Jul 17 11:02:48.767: //54/99AD0A000000/SIP/Info/info/8192/sipSPIStopOverlapInfoT      imer: Stopping Overlap Info Timer
Jul 17 11:02:48.767: //54/99AD0A000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB:       Freeing ccb 0x2887BCF0

Labels:
0 Helpful
2 Replies 2

Rishabh Ghai
Level 1
Level 1

‎07-16-2016 11:34 PM

Hi,

Can you please verify the dial-peer configs once again. Seems CUBE is unable to find / select the outbound dial-peer to route out the call which results in the SIP CANCEL message and hence a busy tone:

Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/2048/sipSPICheckAssertedIdC      onfig: Dialpeer match is not yet done
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentGT      D: No GTD found in inbound container
Jul 17 11:02:14.005: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sipSPIGetContentCS      TA: No CSTA found in inbound container
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTabl      e: Added to table. ccb=0x288953F0 key=99ad0a00-78b1114d-bcc-39110ac@172.16.145.3      01959700860 balance 1
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/8192/sipSPIMatchSrcIpGroup:       Match not found on carrier id
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/8192/sipSPIMatchSrcIpGr      oup: Match not found on Incoming called number: 01959700860
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/8192/sipSPIMatchSrcIpGr      oup: Match not found on destination pattern: 9613400400
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/12288/ccsipUpdateIncomingCa      llParams: ccCallInfo: Calling name x, number 9613400400, Calling oct3 0x00, oct_      3a 0x81, Called number 01959700860
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/1024/sipSPIGetViaHostInU      RLFormat: VIA URL:sip:172.16.145.3:5060, Host:172.16.145.3
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/67584/sipSPIGetShrlPeer:       Try match incoming dialpeer for Calling number: : 9613400400
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/1024/sipSPIGetFromCalle      dPartyId: P-Called-Party-ID header not found
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/1024/sipSPIGetPeerByCal      ledPartyId: P-Called-Party-ID not found or parse error
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/critical/10240/sipSPIGetCallConf      ig: No match found for P-Called-Party-ID
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/1024/ccsip_validate_and_upd      ate_calling_info: PAI/PPI not configuredi for this dial-peer(2364), use RPID/FRO      M header data
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/verbose/4096/sipSPIUpdateCalling      InfoUsingRpidOrFrom: Updating Calling Info with FROM header data
Jul 17 11:02:14.005: //-1/99AD0A000000/SIP/Info/info/2048/sipSPIGetCallConfig: P      eer tag 2364 matched for incoming call

0 Helpful

Dennis Mink
VIP Alumni
VIP Alumni

‎07-17-2016 04:40 PM

please add your cvonfig and debug voip dialpeer and post.

the SIP CANCEL is coming from your CUBE so it must be unable to route the call to an outbound call leg.

cheer

Please remember to rate useful posts, by clicking on the stars below.

0 Helpful
Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community:

Customers Also Viewed These Support Documents