SIP CUBE sees DTMF * and # parsed as the number 1

cowherjohn · ‎03-03-2010

I am integrating a third party ippbx to Cisco Cube all working but with the UCCX, because when I send the * or # dtmf digits the cube sees them as the number 1 dtmf digit

I have verified with wireshark that vendor system is sending correctly but cube reads/interprets it as the number 1 any help would be appreciated

cowherjohn · ‎03-04-2010

If you can see the attached, I dialed 1234#

and the cube sent 12341

AAPUSVAARPTVG02#
009451: Mar 4 12:51:20.798: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[201] removed.
009452: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
009453: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4A0D64B0 key=04E7289C@10.107.177.954095
009454: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
009455: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x4A0D64B0 key=04E7289C@10.107.177.95244E6CF0-262D
009456: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
009457: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/ccsip_qos_cleanup: Entry
009458: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
009459: Mar 4 12:51:20.798: //32189/48265AD0BE6D/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 4A0D64B0
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
009460: Mar 4 12:51:54.243: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
009461: Mar 4 12:51:54.243: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
009462: Mar 4 12:51:54.243: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
009463: Mar 4 12:51:54.243: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:4095@172.25.30.21:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+ccab88001db7a774e18a6626099dfafe+10.107.177.95+8
Allow-Events: refer
Allow-Events: message-summary
Allow-Events: dialog
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>
CSeq: 392882336 INVITE
Expires: 180
Supported: replaces
Contact: "Manager"<100>
Content-Type: application/sdp
Content-Length: 195
User-Agent: Wave/10.5.3021.2152

v=0
o=InstantOffice 785 0 IN IP4 10.107.177.95
s=phone-call
c=IN IP4 10.107.177.95
t=0 0
m=audio 16746 RTP/AVP 0 18
a=rtpmap:0 pcmu/8000/1
a=rtpmap:18 g729/8000/1
a=ptime:20
a=sendrecv

009464: Mar 4 12:51:54.243: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
009465: Mar 4 12:51:54.247: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4A0E0A28) with key=[203] to table
009466: Mar 4 12:51:54.247: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
009467: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0E0A28 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
009468: Mar 4 12:51:54.247: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
009469: Mar 4 12:51:54.247: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
009470: Mar 4 12:51:54.247: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
009471: Mar 4 12:51:54.247: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x474A30BC) found for sip_user: 4095
009472: Mar 4 12:51:54.247: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
009473: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
009474: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4A0E0A28 key=E258D551@10.107.177.954095
009475: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
009476: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 4095
009477: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 100
009478: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name Manager, number 100, Calling oct3 0x00, oct_3a 0x80, Called number 4095
009479: Mar 4 12:51:54.247: //-1/742AD833BE83/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 100
009480: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
009481: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: Non dial peer leg - using RTP Supported Codecs
009482: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 18
009483: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 0
009484: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 8
009485: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 9
009486: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 4
009487: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 2
009488: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 15
009489: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIGetCallConfig: RTP Preferred Codecs supported by GW 3
009490: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIContinueNewMsgInvite: Calling name Manager, number 100, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 4095, oct3 0x00
009491: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
009492: Mar 4 12:51:54.251: //-1/742AD833BE83/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
009493: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
009494: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
009495: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
009496: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
SIP: (32208) Attribute mid, level 1 instance 1 not found.
009497: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009498: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1
009499: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
009500: Mar 4 12:51:54.251: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160
009501: Mar 4 12:51:54.251: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009502: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711ulaw
009503: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
009504: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: Requested DTMF-RELAY option(s) not found in Preferred DTMF-RELAY option list!
009505: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIStreamTypeAndDtmfRelay: DTMF Relay mode: Inband Voice
009506: Mar 4 12:51:54.251: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
009507: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
009508: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
009509: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
        payload_type=0, codec_bytes=160, codec=g711ulaw, dtmf_relay=inband-voice
        stream_type=voice-only (0), dest_ip_address=10.107.177.95, dest_port=16746
009510: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
009511: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Media/sipSPIUpdCallWithSdpInfo:
        Preferred Codec        : g729r8, bytes :20
        Preferred DTMF relay : inband-voice
        Preferred NTE payload : 101
        Early Media            : No
        Delayed Media          : No
        Bridge Done            : No
        New Media              : No
        DSP DNLD Reqd          : No

009512: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009513: Mar 4 12:51:54.251: //32208/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009514: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32208 peer 0 flags 0x201 state STATE_IDLE
009515: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 32208, sdp 0x4A606AE0 channels 0x4A0E1CC8
009516: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/copy_channels:
callId 32208 size 0 ptr 0x495086DC)
009517: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
009518: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
009519: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
009520: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5

009521: Mar 4 12:51:54.255: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009522: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
009523: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
009524: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 5 ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 1 10.107.177.95:16746
009525: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
009526: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Media/sipSPISelectCodecVersion: Codec (g729br8) is not in preferred list
009527: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: An exact codec match not configured, using interoperable codec g729r8
009528: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8
009529: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 16
009530: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 16

009531: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=20, media_ndx=1
009532: Mar 4 12:51:54.255: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729r8 ptime :20, codecbytes: 20
009533: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
009534: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 16 ptype 18 time 20, bytes 20 as channel 1 mline 1 ss 1 10.107.177.95:16746
009535: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5

009536: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 16

009537: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

009538: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32208 flags 0x100 state STATE_IDLE
009539: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
009540: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC, ccb->pld.flags_ipip 0x201

009541: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/copy_channels:
callId 32208 size 468 ptr 0x47E3CD94)
009542: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
CCSIP: Unable to report channel ind
009543: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/ccsip_update_srtp_caps: 5054: Posting Remote SRTP caps to other callleg.
009544: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind()
009545: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Media/sipSPIUpdCallWithSdpInfo:
          Stream type            : voice-only
          Media line             : 1
          State                  : STREAM_ADDING (2)
          Stream address type    : 1
          Callid                 : -1
          Negotiated Codec       : g711ulaw, bytes :160
          Nego. Codec payload    : 0 (tx), 0 (rx)
          Negotiated DTMF relay : inband-voice
          Negotiated NTE payload : 0 (tx), 0 (rx)
          Negotiated CN payload : 0
          Media Srce Addr/Port   : [172.25.30.21]:0
          Media Dest Addr/Port   : [10.107.177.95]:16746

009546: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIHandleInviteMedia:
Negotiated Codec       : g711ulaw, bytes :160
Preferred Codec        : g729r8, bytes :20
Preferred DTMF relay 1 : 0
Preferred DTMF relay 2 : 0
Negotiated DTMF relay   : 0
Preferred and Negotiated NTE payloads: 101 0
Preferred and Negotiated NSE payloads: 100 0
Preferred and Negotiated Modem Relay: 0 0
Preferred and Negotiated Modem Relay GwXid: 1 0

009547: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: Entry
009548: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
009549: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
009550: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
009551: Mar 4 12:51:54.255: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 18716 for stream 1
009552: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=18716
009553: Mar 4 12:51:54.255: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
009554: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 18716
009555: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 5, payload type 0

009556: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = E258D551@10.107.177.95
009557: Mar 4 12:51:54.255: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
009558: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
009559: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
009560: Mar 4 12:51:54.255: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 0,
009561: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Info/sipSPIShrlCall: Check peer: 0 for Shared-Line call, callid: 32208
009562: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Info/ccsip_set_bearer_capability:
Bearer Capability: Speech (0x00)
009563: Mar 4 12:51:54.259: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
009564: Mar 4 12:51:54.259: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
009565: Mar 4 12:51:54.259: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

009566: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS
009567: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 7DD0 to table
009568: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x4A3DEDB8, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
009569: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009570: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
009571: Mar 4 12:51:54.259: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4A3DEDB8, addr=10.107.177.95, port=5060, connId=0 for UDP
009572: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0E0A28 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE)
009573: Mar 4 12:51:54.259: //32208/742AD833BE83/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.107.177.95:5060
009574: Mar 4 12:51:54.259: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
009575: Mar 4 12:51:54.263: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x4A0D11F4) with key=[204] to table
009576: Mar 4 12:51:54.263: //32209/000000000000/SIP/State/sipSPIChangeState: 0x4A0D11F4 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
009577: Mar 4 12:51:54.263: //32209/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200
009578: Mar 4 12:51:54.263: //32209/000000000000/SIP/Info/ccsip_call_setup_request: midcall-signaling passthru enabled
009579: Mar 4 12:51:54.263: //32209/000000000000/SIP/Info/ccsip_call_setup_request:
This a IPIP call: Chan 0, codec 5 channel 16746, ip 10.107.177.95:16746 params 0x4A439388 caps 0x47E60E64
009580: Mar 4 12:51:54.263: //32209/000000000000/SIP/Info/ccsip_call_setup_request:
This a IPIP call: Chan 1, codec 16 channel 16746, ip 10.107.177.95:16746 params 0x4A439388 caps 0x47E60E64
009581: Mar 4 12:51:54.263: //32209/000000000000/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
009582: Mar 4 12:51:54.263: //32209/000000000000/SIP/Info/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 400000
009583: Mar 4 12:51:54.263: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : 172.24.7.14 target_port : 5060

009584: Mar 4 12:51:54.263: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP
009585: Mar 4 12:51:54.263: //32209/742AD833BE83/SIP/Info/ccsip_call_setup_request: Incrementing call counter in dial-peer [11]
009586: Mar 4 12:51:54.263: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:
009587: Mar 4 12:51:54.263: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 162)
009588: Mar 4 12:51:54.263: //32208/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 32209 chans 0x4A6AF8B8 event 162 flags 0x40001C 0x100 0x601 data 0x4A6AF8B8
009589: Mar 4 12:51:54.263: //32208/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_SET_MODE: peer ID 32209 chans 0x4A6AF8B8 event 162 flags 0x40001C 0x100 0x601 data 0x4A6AF8B8, type = 1
009590: Mar 4 12:51:54.263: //32208/742AD833BE83/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
009591: Mar 4 12:51:54.263: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
009592: Mar 4 12:51:54.267: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3
009593: Mar 4 12:51:54.267: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2
009594: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 7DD1 to table
009595: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec    bytes: 0
009596: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIGetCallConfig: Media forking disabled
009597: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
009598: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1
009599: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Media/sipSPICopyPeerDataToCCB: Firewall traversal is not enabled
009600: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled
009601: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH
009602: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIGetCallConfig: Media forking disabled
009603: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/preprocessSetup:
This is a not a SIGO Call -, could be DM call
009604: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_call_setup: No video caps posted by peer
009605: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_call_setup: xcoder high-density disabled
009606: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_call_setup: Flow Mode set to FLOW_THROUGH
009607: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
callid 32209, channels 0x47DBA6E4 caps 0x47E60E64
009608: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Peer cap provided: callid = 32209, peer dtmf = 0
009609: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: callid = 32209, peer not doing RFC2833, peer dtmf = 0, enable NTE_ASSUMED
009610: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
009611: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 16
009612: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIDtmfTranscoder: Return upon SCCP version 0
009613: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
009614: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 16
009615: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIDtmfTranscoder: Return upon SCCP version 0
009616: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
009617: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009618: Mar 4 12:51:54.267: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16534 for stream 1
009619: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101
009620: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIAddSDPPayloadAttributes:
max_event 15
009621: Mar 4 12:51:54.267: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009622: Mar 4 12:51:54.267: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
009623: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
009624: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Info/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call
009625: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
009626: Mar 4 12:51:54.267: //32209/742AD833BE83/SIP/Media/sipSPIProcessRtpSessions: No active streams.
009627: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sip_gw_pre_setup_add_sdp_container: SDP container added
009628: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg
009629: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIShrlGetInstanceInfo: Obtained the call instance 0 for non-shared-line '....' with callid: 32209
009630: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
009631: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container
009632: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_set_diversion_header: No diversion header recvd from container
009633: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/act_idle_continue_call_setup:
009634: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
009635: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
009636: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x4A0D11F4 key=742E81BB-26ED11DF-BE899914-1E9EA24D@172.25.30.21
009637: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = 742E81BB-26ED11DF-BE899914-1E9EA24D@172.25.30.21
009638: Mar 4 12:51:54.271: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 172.24.7.14,Port 5060, Transport 1, SentBy Port 5060
009639: Mar 4 12:51:54.271: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
009640: Mar 4 12:51:54.271: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar is not configured
009641: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Event/sipSPICreateRpid: Received Octet3A=0x80 -> Setting ;screen=no ;privacy=off
SIP: (32209) Group (a= group line) attribute, level 65535 instance 1 not found.
009642: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009643: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Info/sipSPISendInvite: Associated container=0x4A43A5F8 to Invite
009644: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009645: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009646: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x47DBABF4, addr=172.24.7.14, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x4197823C
009647: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009648: Mar 4 12:51:54.271: //32209/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
009649: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x47DBABF4
009650: Mar 4 12:51:54.275: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x47DBABF4, addr=172.24.7.14, port=5060, connId=2 for UDP
009651: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE
009652: Mar 4 12:51:54.275: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.
009653: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0D11F4 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)
009654: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
009655: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 32209) to the VOIP RTP library
009656: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009657: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009658: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
009659: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
        laddr = 172.25.30.21, lport = 16534, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE
        src_callid = 32209, dest_callid = -1, stream type = voice+dtmf, stream direction = RECVONLY
        media_ip_addr = - , vrf tableid = 0 media_addr_type = 1
009660: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
009661: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Info/sipSPICreateRtpSession: sess: 47DC9F20 do_rtcp:0
009662: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/Media/sipSPICreateRtpSession: stun is disabled
009663: Mar 4 12:51:54.275: //32209/742AD833BE83/SIP/State/sipSPIChangeStreamState: Stream (callid = 32209) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
009664: Mar 4 12:51:54.275: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+ccab88001db7a774e18a6626099dfafe+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>
Date: Thu, 04 Mar 2010 17:51:54 GMT
Call-ID: E258D551@10.107.177.95
CSeq: 392882336 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+ccab88001db7a774e18a6626099dfafe+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
Date: Thu, 04 Mar 2010 17:51:54 GMT
Call-ID: E258D551@10.107.177.95
CSeq: 392882336 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: <4095>;party=called;screen=no;privacy=off
Contact: <4095>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

009706: Mar 4 12:51:56.479: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [172.24.7.14]:5060
009707: Mar 4 12:51:56.479: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
009708: Mar 4 12:51:56.479: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
009709: Mar 4 12:51:56.479: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
009710: Mar 4 12:51:56.479: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
Date: Thu, 04 Mar 2010 17:51:54 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
From: "Manager" <100>;tag=244F8D1C-1153
Allow-Events: presence, kpml
Supported: replaces
Supported: Geolocation
Content-Length: 211
Require: timer
To: <4095>;tag=65785772-11d5-4cc9-a426-d79b0af58553-56847455
Contact: <4095>
Content-Type: application/sdp
Call-ID: 742E81BB-26ED11DF-BE899914-1E9EA24D@172.25.30.21
Via: SIP/2.0/UDP 172.25.30.21:5060;branch=z9hG4bK298144C
CSeq: 101 INVITE
Session-Expires: 1800;refresher=uas

v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 172.24.7.14
s=SIP Call
c=IN IP4 172.25.30.21
t=0 0
m=audio 19154 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

009711: Mar 4 12:51:56.479: //32209/742AD833BE83/SIP/Info/sipSPICheckResponse: INVITE response with no RSEQ - disable IS_REL1XX
009712: Mar 4 12:51:56.479: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
009713: Mar 4 12:51:56.479: //32209/742AD833BE83/SIP/Info/sipSPIhandle200OKInvite: Transaction active. Facilities will be queued.
009714: Mar 4 12:51:56.479: //32209/742AD833BE83/SIP/Info/sipSPIhandle200OKInvite: *** This ccb is the parent
009715: Mar 4 12:51:56.479: //32208/742AD833BE83/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 32208/32209
009716: Mar 4 12:51:56.479: //32208/742AD833BE83/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=-1, new streamcallid=32208
009717: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Error/sipSPIProcessNotifyCallInfoHeader: Call-Info header with for Unsolicited Notify Absent,Disabling Unsolicited Notifies
009718: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIUACSessionTimer:
Session-Expires value: 1800 refresher: 2
009719: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_Add_SessionExpiresParamsToContainer: Session-refresh parameters added to container minse = 0 session expire = 1800 refresher = 2
009720: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
009721: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPICompareRespMediaInfo: No Comparsion needed as 18x response SDP is either absent or ignored
009722: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
SIP: Attribute mid, level 1 instance 1 not found.
009723: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009724: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009725: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1
009726: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
009727: Mar 4 12:51:56.483: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160
009728: Mar 4 12:51:56.483: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009729: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711ulaw
009730: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
009731: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved.
009732: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
009733: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.
009734: Mar 4 12:51:56.483: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
009735: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
009736: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
009737: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/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=172.25.30.21, dest_port=19154
009738: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
009739: Mar 4 12:51:56.483: //32209/742AD833BE83/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              : No
        DSP DNLD Reqd          : No

009740: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009741: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009742: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32209 peer 32208 flags 0x401005 state STATE_RECD_PROCEEDING
009743: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 32209, sdp 0x47DC33D0 channels 0x4A0D2494
009744: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/copy_channels:
callId 32209 size 468 ptr 0x47E3CD94)
009745: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
009746: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
009747: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
009748: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5

009749: Mar 4 12:51:56.483: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009750: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
009751: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 5 ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 1 172.25.30.21:19154
009752: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
009753: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Call 32209 dtmf ptype 101 nte/oob enabled
009754: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 32209, dtmf = 6
009755: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5

009756: Mar 4 12:51:56.483: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

009757: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32209 flags 0x100 state STATE_RECD_PROCEEDING
009758: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
009759: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC00018, ccb->pld.flags_ipip 0x403005

009760: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: Post CAPS to peer.

009761: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: Entry
009762: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind:
destCallID=32208, srcCallID=32209,
                         peer_ccb->call_info.currentLocalName=Manager,
                         peer_ccb->call_info.currentRemoteName=,
                         ccb->call_info.currentLocalName=,
                         ccb->call_info.currentRemoteName=
009763: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=32208, current_seq_num=0x9D9
009764: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=32208, current_seq_num=0x0
009765: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g711ulaw, Bytes=160
009766: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
009767: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE_AND_OOB
009768: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
009769: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
009770: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
009771: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
009772: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
009773: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=0, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
009774: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Media/sipSPISetStreamInfo: 0 Active Streams
009775: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Media/sipSPISetStreamInfo: Number of active streams is zero (0)!
009776: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Media/sipSPISetStreamInfo:
caps.stream_count=0,caps.stream[0].stream_type=0xFFFF, caps.stream_list.xmitFunc=
009777: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Media/sipSPISetStreamInfo: ??unknown??, caps.stream_list.context=
009778: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Media/sipSPISetStreamInfo: 0x0 (gccb)
009779: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: Load DSP with codec : g711ulaw, Bytes=160, payload = 0
009780: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x400403
009781: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: No video caps detected in the caps posted by peer leg
009782: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: Calling cc_api_caps_ack()
009783: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
009784: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC00018, ccb->pld.flags_ipip 0x403005

009785: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/copy_channels:
callId 32209 size 240 ptr 0x47E3CD94)
009786: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:
009787: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 156)
009788: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 32209 chans 0x47E3CD94 event 156 flags 0xC0001C 0x100 0x400403 data 0x47E3CD94
009789: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_IND: peer ID 32209 chans 0x47E3CD94 event 156 flags 0xC0001C 0x100 0x400403 data 0x47E3CD94
009790: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_NEW_MEDIA
009791: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: set event->type = SIPSPI_EV_CC_NEW_MEDIA!: peer ID 32209 chans 0x47E3CD94 event 156 flags 0xC0001C 0x100 0x400403 data 0x47E3CD94
009792: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
009793: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: SIP2SIP, posting channel_ind to peer.

009794: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/ccsip_update_srtp_caps: 5033: Not Sending NULL SRTP CAPS to SIP LEG
009795: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Media/sipSPIUpdCallWithSdpInfo:
          Stream type            : voice+dtmf
          Media line             : 1
          State                  : STREAM_ADDING (2)
          Stream address type    : 1
          Callid                 : 32209
          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   : [172.25.30.21]:16534
          Media Dest Addr/Port   : [172.25.30.21]:19154

009796: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
009797: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connect_media returned: SIP_SUCCESS
009798: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0D11F4 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE)
009799: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
009800: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
009801: Mar 4 12:51:56.487: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

009802: Mar 4 12:51:56.487: //32209/742AD833BE83/SIP/Info/sipSPIShrlCall: Check peer: 11 for Shared-Line call, callid: 32209
009803: Mar 4 12:51:56.487: //32208/742AD833BE83/SIP/Info/sipSPIShrlCall: Check peer: 0 for Shared-Line call, callid: 32208
009804: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connected returned: SIP_SUCCESS
009805: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer
009806: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009807: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x47DBABF4, addr=172.24.7.14, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x419795EC
009808: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009809: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
009810: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x47DBABF4
009811: Mar 4 12:51:56.491: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x47DBABF4, addr=172.24.7.14, port=5060, connId=2 for UDP
009812: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0D11F4 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE)
009813: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x4A0D11F4
State of The Call        : STATE_ACTIVE
TCP Sockets Used         : NO
Calling Number           : 100
Called Number            : 4095
Source IP Address (Sig ): 172.25.30.21
Destn SIP Req Addr:Port : 172.24.7.14:5060
Destn SIP Resp Addr:Port : 172.24.7.14:5060
Destination Name         : 172.24.7.14

009814: Mar 4 12:51:56.491: //32209/742AD833BE83/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): 172.25.30.21
Source IP Port    (Media): 16534
Destn IP Address (Media): 172.25.30.21
Destn IP Port    (Media): 19154
Orig Destn IP Address:Port (Media): [ - ]:0

009815: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Info/sipSPICallActive: Transaction Complete. Lock on Facilities released.
009816: Mar 4 12:51:56.491: //32209/742AD833BE83/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
009817: Mar 4 12:51:56.491: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 26
009818: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callID 32208 ft: 1, inc 4, 172.25.30.21:19154, codec 5

009819: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callid 32208 state STATE_SENT_ALERTING
009820: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
callid 32208, channels 0x47E3CD94 caps 0x47E70388
009821: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Peer cap provided: callid = 32208, peer dtmf = 6
009822: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
009823: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
nego mline 1 dtmf 101 ss 1 ret 12
009824: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: CCB->pld.flags_ipip 0x400403

009825: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: channel_ind/ack payload type 0

009826: Mar 4 12:51:56.491: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009827: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info: audio channel_ind
009828: Mar 4 12:51:56.491: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
009829: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 18716
009830: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 5, payload type 0

009831: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
009832: Mar 4 12:51:56.491: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
009833: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 18716
009834: Mar 4 12:51:56.491: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 5, payload type 0

009835: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/ccsip_bridge: confID = 21265, srcCallID = 32208, dstCallID = 32209
009836: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: 32208/32209, new src/dest ccCallids: 32208/32209
009837: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=32208, new streamcallid=32208
009838: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
009839: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 1131939416, ccb xmitFunc = 1131939416
009840: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
009841: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice-only (callid 32208) to the VOIP RTP library
009842: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009843: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009844: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
009845: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
        laddr = 172.25.30.21, lport = 18716, raddr = 10.107.177.95, rport=16746, do_rtcp=TRUE
        src_callid = 32208, dest_callid = 32209, stream type = voice-only, stream direction = SENDRECV
        media_ip_addr = 10.107.177.95, vrf tableid = 0 media_addr_type = 1
009846: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
009847: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/sipSPICreateRtpSession: sess: 4A699A58 do_rtcp:1
009848: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPICreateRtpSession: stun is disabled
009849: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer:
009850: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
009851: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/Media/sipSPIGetNewLocalMediaDirection:
        New Remote Media Direction = SENDRECV
        Present Local Media Direction = SENDRECV
        New Local Media Direction = SENDRECV
        retVal = 0

009852: Mar 4 12:51:56.495: //32208/742AD833BE83/SIP/State/sipSPIChangeStreamState: Stream (callid = 32208) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
009853: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/ccsip_bridge: confID = 21265, srcCallID = 32209, dstCallID = 32208
009854: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 32209/32208
009855: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=32209, new streamcallid=32209
009856: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
009857: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 1131939416, ccb xmitFunc = 1131939416
009858: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
009859: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 32209) to the VOIP RTP library
009860: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009861: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
009862: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
009863: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
        laddr = 172.25.30.21, lport = 16534, raddr = 172.25.30.21, rport=19154, do_rtcp=TRUE
        src_callid = 32209, dest_callid = 32208, stream type = voice+dtmf, stream direction = SENDRECV
        media_ip_addr = 172.25.30.21, vrf tableid = 0 media_addr_type = 1
009864: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update
009865: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:491045B8
009866: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer:
009867: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
009868: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/sipSPIUpdateRtcpSession:
DTMF inb/oob iwf enabled 101
009869: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Media/sipSPIGetNewLocalMediaDirection:
        New Remote Media Direction = SENDRECV
        Present Local Media Direction = SENDRECV
        New Local Media Direction = SENDRECV
        retVal = 0

009870: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/State/sipSPIChangeStreamState: Stream (callid = 32209) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
009871: Mar 4 12:51:56.495: //32209/742AD833BE83/SIP/Info/ccsip_bridge:
DTMF inb/oob iwf enabled 101
009872: Mar 4 12:51:56.499: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:4095@172.24.7.14:5060 SIP/2.0
Via: SIP/2.0/UDP 172.25.30.21:5060;branch=z9hG4bK2991586
From: "Manager" <100>;tag=244F8D1C-1153
To: <4095>;tag=65785772-11d5-4cc9-a426-d79b0af58553-56847455
Date: Thu, 04 Mar 2010 17:51:54 GMT
Call-ID: 742E81BB-26ED11DF-BE899914-1E9EA24D@172.25.30.21
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0

009873: Mar 4 12:51:56.499: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_call_connect: CCSIP_CALL_CONNECT: ccb ptr 4A0E0A28

009874: Mar 4 12:51:56.499: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_CONNECT
009875: Mar 4 12:51:56.499: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 6
009876: Mar 4 12:51:56.499: //32208/742AD833BE83/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
009877: Mar 4 12:51:56.499: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_setSessionExpiresParams:
Session refresh values minse = 0 session expire = 1800 refresher = 2
009878: Mar 4 12:51:56.499: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container
009879: Mar 4 12:51:56.499: //32208/742AD833BE83/SIP/Info/preprocessConnect: Write sdp_info into msg_body
009880: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Info/preprocessConnect: Add msg_body into container 0x4A43A758
009881: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Info/sipSPIShrlGetInstanceInfo: Obtained the call instance 0 for non-shared-line '539' with callid: 32208
009882: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off
SIP: (32208) Group (a= group line) attribute, level 65535 instance 1 not found.
009883: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request
009884: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Info/sipSPISendInviteResponse: Associated container=0x4A43A758 to Invite Response 200
009885: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Transport/sipSPISendInviteResponse: Sending 200OK Response to the Transport Layer
009886: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x47DBABF4, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x41978DB0
009887: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009888: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
009889: Mar 4 12:51:56.503: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x47DBABF4, addr=10.107.177.95, port=5060, connId=0 for UDP
009890: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/Info/sentInviteResponse200: Sent 200Ok for Invite in state STATE_SENT_ALERTING
009891: Mar 4 12:51:56.503: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteResponse200: Transaction active. Facilities will be queued.
009892: Mar 4 12:51:56.503: //32208/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0E0A28 : State change from (STATE_SENT_ALERTING, SUBSTATE_NONE) to (STATE_SENT_SUCCESS, SUBSTATE_NONE)
009893: Mar 4 12:51:56.503: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
sip:4095@172.25.30.21>;party=called;screen=no;privacy=off
Contact: <4095>
Supported: replaces
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Content-Type: application/sdp
Content-Length: 191

v=0
o=CiscoSystemsSIP-GW-UserAgent 6744 3071 IN IP4 172.25.30.21
s=SIP Call
c=IN IP4 172.25.30.21
t=0 0
m=audio 18716 RTP/AVP 0
c=IN IP4 172.25.30.21
a=rtpmap:0 PCMU/8000
a=ptime:20

010303: Mar 4 12:51:56.747: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
010304: Mar 4 12:51:56.747: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
010305: Mar 4 12:51:56.747: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010306: Mar 4 12:51:56.747: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010307: Mar 4 12:51:56.747: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:4095@172.25.30.21:5060 SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+852b249a296a3cceca3ca54636ad417b+10.107.177.95+8
Allow-Events: refer
Allow-Events: message-summary
Allow-Events: dialog
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
CSeq: 392882337 ACK
Contact: "Manager"<100>
Content-Length: 0
User-Agent: Wave/10.5.3021.2152

010308: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010309: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4A0E0A28
010310: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010311: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010312: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010313: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/sipSPIProcessIncomingAckForMidCall: Processing MidCall ACK
010314: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0E0A28 : State change from (STATE_MIDCALL_LOCAL_RESP_PENDING, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE)
010315: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer:
010316: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
010317: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/ccsip_api_modify_session_done: ccsip_api_modify_session_done: start resume start notifivation
010318: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/sipSPIResumeStartNotificationRequest: sipSPIResumeStartNotificationRequest: Resume Type=Unknown
010319: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/sipSPIProcessIncomingAckForMidCall: ccsip_api_modify_session_done returned: SIP_SUCCESS
010320: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010321: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010322: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:4095@172.25.30.21:5060 SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+1266e487aad5f4bce082a2f3a75eff19+10.107.177.95+8
Allow-Events: refer
Allow-Events: message-summary
Allow-Events: dialog
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
CSeq: 392882338 INVITE
Expires: 180
Supported: replaces
Contact: "Manager"<100>
Content-Type: application/sdp
Content-Length: 167
User-Agent: Wave/10.5.3021.2152

v=0
o=InstantOffice 787 0 IN IP4 10.107.177.95
s=phone-call
c=IN IP4 10.107.177.95
t=0 0
m=audio 16746 RTP/AVP 0
a=rtpmap:0 pcmu/8000/1
a=ptime:20
a=sendrecv

010323: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010324: Mar 4 12:51:56.751: //32208/742AD833BE83/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4A0E0A28
010325: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010326: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010327: Mar 4 12:51:56.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010328: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sact_active_new_message_request: Case of Mid-Call INVITE/UPDATE in ACTIVE STATE
010329: Mar 4 12:51:56.755: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
010330: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/ccsip_api_request_offer: ccsip_api_request_offer.

010331: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/ccsip_api_request_offer: Incoming/Outgoing updates for callerid is globally disabled
010332: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
SIP: Attribute mid, level 1 instance 1 not found.
010333: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
010334: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
010335: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1
010336: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
010337: Mar 4 12:51:56.755: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160
010338: Mar 4 12:51:56.755: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
010339: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711ulaw
010340: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
010341: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: Requested DTMF-RELAY option(s) not found in Preferred DTMF-RELAY option list!
010342: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIStreamTypeAndDtmfRelay: DTMF Relay mode: Inband Voice
010343: Mar 4 12:51:56.755: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
010344: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sip_do_nse_negotiation: Remote NSE payload = local one = 0, Use it
010345: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
010346: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
010347: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
        payload_type=0, codec_bytes=160, codec=g711ulaw, dtmf_relay=inband-voice
        stream_type=voice-only (0), dest_ip_address=10.107.177.95, dest_port=16746
010348: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
010349: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Media/sipSPICompareStreams: stream 1 dest_port: old=16746 new=16746
010350: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Media/sipSPIGetNewLocalMediaDirection:
        New Remote Media Direction = SENDRECV
        Present Local Media Direction = SENDRECV
        New Local Media Direction = SENDRECV
        retVal = 0

010351: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Media/sipSPICompareStreams: Flags set for stream 1: RTP_CHANGE=No CAPS_CHANGE=No RSVP_ADDR_CHANGE=No RSVP_MEDIA_CHANGE=No
010352: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Media/sipSPICompareSDP: Flags set for call: NEW_MEDIA=No DSPDNLD_REQD=No IPIP_MEDIA=No
010353: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: Entry
010354: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
010355: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
010356: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Media/sipSPIUpdCallWithSdpInfo:
        Preferred Codec        : g711ulaw, bytes :160
        Preferred DTMF relay : inband-voice
        Preferred NTE payload : 101
        Early Media            : No
        Delayed Media          : No
        Bridge Done            : Yes
        New Media              : No
        DSP DNLD Reqd          : No

010357: Mar 4 12:51:56.755: //32208/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
010358: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
010359: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32208 peer 32209 flags 0x400407 state STATE_ACTIVE
010360: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 32208, sdp 0x4A606AE0 channels 0x4A0E1CC8
010361: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/copy_channels:
callId 32208 size 240 ptr 0x4A65F004)
010362: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
xmitFunc is set to voip_rtp_xmit for Call 32208
010363: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/ccsip_remote_codec_download_done:
callId 32208 context 0x47DAACA0
010364: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
010365: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
010366: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
010367: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5

010368: Mar 4 12:51:56.759: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
010369: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
010370: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 5 ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 1 10.107.177.95:16746
010371: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5

010372: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

010373: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32208 flags 0x120 state STATE_ACTIVE
010374: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC0401C, ccb->pld.flags_ipip 0x400407

010375: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: IN STATE 7, get new media. Post CAPS to peer.

010376: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_caps_ind: Entry
010377: Mar 4 12:51:56.759: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind:
destCallID=32209, srcCallID=32208,
                         peer_ccb->call_info.currentLocalName=,
                         peer_ccb->call_info.currentRemoteName=,
                         ccb->call_info.currentLocalName=Manager,
                         ccb->call_info.currentRemoteName=
010378: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=32209, current_seq_num=0x5D6
010379: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=32209, current_seq_num=0x5D6
010380: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_caps_ind: Load DSP with negotiated codec: g711ulaw, Bytes=160
010381: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_caps_ind: Set forking flag to 0x0
010382: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101
010383: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
010384: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
010385: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
010386: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
010387: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=0, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
010388: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Media/sipSPISetStreamInfo: 1 Active Streams
010389: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice+dtmf) from media
line 1 codec g711ulaw
010390: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Media/sipSPISetStreamInfo:
caps.stream_count=1,caps.stream[0].stream_type=0x3, caps.stream_list.xmitFunc=
010391: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context=
010392: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Media/sipSPISetStreamInfo: 0x4A654B00 (gccb)
010393: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_caps_ind: Load DSP with codec : g711ulaw, Bytes=160, payload = 0
010394: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x403485
010395: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_caps_ind: No video caps detected in the caps posted by peer leg
010396: Mar 4 12:51:56.759: //32209/742AD833BE83/SIP/Info/ccsip_caps_ind: Calling cc_api_caps_ack()
010397: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/ccsip_caps_ack: Set forking flag to 0x0
010398: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC0401C, ccb->pld.flags_ipip 0x400407

010399: Mar 4 12:51:56.759: //32208/742AD833BE83/SIP/Info/copy_channels:
callId 32208 size 240 ptr 0x491040E8)
010400: Mar 4 12:51:56.763: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler:
010401: Mar 4 12:51:56.763: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 156)
010402: Mar 4 12:51:56.763: //32209/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 32208 chans 0x491040E8 event 156 flags 0xC04018 0x100 0x403485 data 0x491040E8
010403: Mar 4 12:51:56.763: //32209/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_IND: peer ID 32208 chans 0x491040E8 event 156 flags 0xC04018 0x100 0x403485 data 0x491040E8
010404: Mar 4 12:51:56.763: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_NEW_MEDIA
010405: Mar 4 12:51:56.763: //32209/742AD833BE83/SIP/Info/ccsip_event_handler:
ccsip_event_handler: set event->type = SIPSPI_EV_CC_NEW_MEDIA!: peer ID 32208 chans 0x491040E8 event 156 flags 0xC04018 0x100 0x403485 data 0x491040E8
010406: Mar 4 12:51:56.763: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
010407: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: IN state 7, SIP2SIP, posting channel_ind to peer.

010408: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/ccsip_update_srtp_caps: 5033: Not Sending NULL SRTP CAPS to SIP LEG
010409: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Media/sipSPIUpdCallWithSdpInfo:
          Stream type            : voice-only
          Media line             : 1
          State                  : STREAM_ACTIVE (5)
          Stream address type    : 1
          Callid                 : 32208
          Negotiated Codec       : g711ulaw, bytes :160
          Nego. Codec payload    : 0 (tx), 0 (rx)
          Negotiated DTMF relay : inband-voice
          Negotiated NTE payload : 0 (tx), 0 (rx)
          Negotiated CN payload : 0
          Media Srce Addr/Port   : [172.25.30.21]:18716
          Media Dest Addr/Port   : [10.107.177.95]:16746

010410: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Media/sipSPIUpdCallWithSdpInfo:
          QoS ID              : -1
          Local QoS Strength : BestEffort
          Nego QoS Strength   : BestEffort
          Nego QoS Direction : None
          Local QoS Status    : None
          Remote QoS Status   : None
          Local Conf Required : No
          Remote Conf Required: No

010411: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/is_call_held: Remote media IP addr: 10.107.177.95
010412: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/is_call_held: Media IP Addr 10.107.177.95, RTCP Type 3
010413: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
010414: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIIncomingCallSDP: SDP already there use old SDP and update media if needed
010415: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpFixedPart: RTP port already reserved for stream 1, src_port=18716
010416: Mar 4 12:51:56.763: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
010417: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 18716
010418: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 5, payload type 0

010419: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIProcessRsvp: Entry
010420: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0E0A28 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_MIDCALL_LOCAL_RESP_PENDING, SUBSTATE_NONE)
010421: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIHandleIncomingMidCallInvite: ccsip_api_request_offer returned: SIP_SUCCESS
010422: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
010423: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x47DBABF4, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
010424: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
010425: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
010426: Mar 4 12:51:56.763: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x47DBABF4, addr=10.107.177.95, port=5060, connId=0 for UDP
010427: Mar 4 12:51:56.763: //32208/742AD833BE83/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.107.177.95:5060
010428: Mar 4 12:51:56.763: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 26
010429: Mar 4 12:51:56.763: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callID 32209 ft: 1, inc 0, 10.107.177.95:16746, codec 5

010430: Mar 4 12:51:56.763: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callid 32209 state STATE_ACTIVE
010431: Mar 4 12:51:56.763: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
callid 32209, channels 0x491040E8 caps 0x47E73108
010432: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Peer cap provided: callid = 32209, peer dtmf = 0
010433: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: callid = 32209, peer not doing RFC2833, peer dtmf = 0, enable NTE_ASSUMED
010434: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: callid = 32209, this leg negotiated dtmf = 6, peer dtmf = 0, nte/oob DTMF_IWF enabled.
010435: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
Call 32209 setting xmit func to rtp
010436: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/ccsip_remote_codec_download_done:
callId 32209 context 0x4A654B00
010437: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
010438: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
nego mline 1 dtmf 101 ss 1 ret 12
010439: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: CCB->pld.flags_ipip 0x403485

010440: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: channel_ind/ack payload type 0

010441: Mar 4 12:51:56.767: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
010442: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info: audio channel_ind
010443: Mar 4 12:51:56.767: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
010444: Mar 4 12:51:56.767: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
010445: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
010446: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Media/sipSPIProcessRtpSessions: sipSPIProcessRtpSessions
010447: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
010448: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
        laddr = 172.25.30.21, lport = 16534, raddr = 172.25.30.21, rport=19154, do_rtcp=TRUE
        src_callid = 32209, dest_callid = 32208, stream type = voice+dtmf, stream direction = SENDRECV
        media_ip_addr = 172.25.30.21, vrf tableid = 0 media_addr_type = 1
010449: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update
010450: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:47DC1DF4
010451: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer:
010452: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
010453: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIUpdateRtcpSession:
DTMF inb/oob iwf enabled 101
010454: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callID 32209: flags=12599320, flags2=256

010455: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info: CALL_HELD=0 Send Mid-call invite based on peer info
010456: Mar 4 12:51:56.767: //-1/xxxxxxxxxxxx/SIP/Error/sipsdp_src_dest_create: SRC SDP already there use old SRC SDP
010457: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpFixedPart: RTP port already reserved for stream 1, src_port=16534
010458: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Error/sipSPIUpdateSrcSdpFixedPart: owner_sessionid is already their OR src_sdp
is corrupted
010459: Mar 4 12:51:56.767: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
010460: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16534
010461: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 5, payload type 0

010462: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101

010463: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_reinvite_delayed_media_update_rtp: Update QoS again before sending reInvite
010464: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIUpdateSDPQoSAttributes: Entry
010465: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIUpdateSDPQoSAttributes: 4 a-line(s) found for stream 1
010466: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_reinvite_delayed_media_update_rtp: No video stream when sending out reInvite.

010467: Mar 4 12:51:56.767: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckForSDPModification: prev send SDP size = 246, curr send SDP size =
246
010468: Mar 4 12:51:56.767: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckForSDPModification: prev send SDP and curr send SDP are
same
010469: Mar 4 12:51:56.767: //32209/742AD833BE83/SIP/Info/sipSPIHandleSDPOwnerVersionIDChange: SDP owner_version ID not incremented ..
010470: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0D11F4 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_SEND_MIDCALL_INVITE_PENDING, SUBSTATE_NONE)
010471: Mar 4 12:51:56.771: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 172.24.7.14,Port 5060, Transport 1, SentBy Port 5060
010472: Mar 4 12:51:56.771: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010473: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Event/sipSPICreateRpid: Received Octet3A=0x80 -> Setting ;screen=no ;privacy=off
SIP: (32209) Group (a= group line) attribute, level 65535 instance 1 not found.
010474: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request
010475: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Info/sipSPISendInvite: Associated container=0x4A43A758 to Invite
010476: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
010477: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
010478: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x4A4699A0, addr=172.24.7.14, port=5060, sentBy_port=0, is_req=1, transport=1, switch=0, callBack=0x4197823C
010479: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
010480: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
010481: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x4A4699A0
010482: Mar 4 12:51:56.771: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4A4699A0, addr=172.24.7.14, port=5060, connId=2 for UDP
010483: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Info/sentInviteRequest: Sent Invite in state STATE_SEND_MIDCALL_INVITE_PENDING
010484: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/State/sipSPIChangeState: 0x4A0D11F4 : State change from (STATE_SEND_MIDCALL_INVITE_PENDING, SUBSTATE_NONE) to (STATE_SENT_MIDCALL_INVITE, SUBSTATE_NONE)
010485: Mar 4 12:51:56.771: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_handle_channel_info: Setting re_invite_init_flag

010486: Mar 4 12:51:56.775: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+1266e487aad5f4bce082a2f3a75eff19+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
Date: Thu, 04 Mar 2010 17:51:56 GMT
Call-ID: E258D551@10.107.177.95
CSeq: 392882338 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

010487: Mar 4 12:51:56.775: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:4095@172.24.7.14:5060 SIP/2.0
Via: SIP/2.0/UDP 172.25.30.21:5060;branch=z9hG4bK29C1444
Remote-Party-ID: "Manager" <100>;party=calling;screen=no;privacy=off
From: "Manager" <100>;tag=244F8D1C-1153
To: <4095>;tag=65785772-11d5-4cc9-a426-d79b0af58553-56847455
Date: Thu, 04 Mar 2010 17:51:56 GMT
Call-ID: 742E81BB-26ED11DF-BE899914-1E9EA24D@172.25.30.21
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 1948964915-653070815-3196295444-513712717
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 103 INVITE
Max-Forwards: 70
Timestamp: 1267725116
Contact: <100>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 246

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

010488: Mar 4 12:51:56.779: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [172.24.7.14]:5060
010489: Mar 4 12:51:56.779: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010490: Mar 4 12:51:56.779: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010491: Mar 4 12:51:56.779: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010492: Mar 4 12:51:56.783: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
Date: Thu, 04 Mar 2010 17:51:56 GMT
From: "Manager" <100>;tag=244F8D1C-1153
Allow-Events: presence, kpml
Content-Length: 0
To: <4095>;tag=65785772-11d5-4cc9-a426-d79b0af58553-56847455
Call-ID: 742E81BB-26ED11DF-BE899914-1E9EA24D@172.25.30.21
Via: SIP/2.0/UDP 172.25.30.21:5060;branch=z9hG4bK29C1444
CSeq: 103 INVITE

010493: Mar 4 12:51:56.783: //32209/742AD833BE83/SIP/Info/sipSPICheckResponse: INVITE response with no RSEQ - disable IS_REL1XX
010494: Mar 4 12:51:56.783: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [172.24.7.14]:5060
010495: Mar 4 12:51:56.787: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010496: Mar 4 12:51:56.787: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010497: Mar 4 12:51:56.787: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010498: Mar 4 12:51:56.787: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
Date: Thu, 04 Mar 2010 17:51:56 GMT
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
From: "Manager" <100>;tag=244F8D1C-1153
Allow-Events: presence, kpml
Supported: replaces
Content-Length: 211
To: <4095>;tag=65785772-11d5-4cc9-a426-d79b0af58553-56847455
Contact: <4095>
Content-Type: application/sdp
Call-ID: 742E81BB-26ED11DF-BE899914-1E9EA24D@172.25.30.21
Via: SIP/2.0/UDP 172.25.30.21:5060;branch=z9hG4bK29C1444
CSeq: 103 INVITE

v=0
o=CiscoSystemsCCM-SIP 2000 2 IN IP4 172.24.7.14
s=SIP Call
c=IN IP4 172.25.30.21
t=0 0
m=audio 19154 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

010499: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPICheckResponse: INVITE response with no RSEQ - disable IS_REL1XX
010500: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/ccsip_api_response_answer: ccsip_api_response_answer.

010501: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
SIP: Attribute mid, level 1 instance 1 not found.
010502: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
010503: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
010504: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1
010505: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
010506: Mar 4 12:51:56.787: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160
010507: Mar 4 12:51:56.787: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
010508: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711ulaw
010509: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
010510: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
010511: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.
010512: Mar 4 12:51:56.787: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0
010513: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sip_do_nse_negotiation: Remote NSE payload = local one = 0, Use it
010514: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
010515: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
010516: Mar 4 12:51:56.787: //32209/742AD833BE83/SIP/Info/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=172.25.30.21, dest_port=19154
010517: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
010518: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Media/sipSPICompareStreams: stream 1 dest_port: old=19154 new=19154
010519: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Media/sipSPIGetNewLocalMediaDirection:
        New Remote Media Direction = SENDRECV
        Present Local Media Direction = SENDRECV
        New Local Media Direction = SENDRECV
        retVal = 0

010520: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Media/sipSPICompareStreams: Flags set for stream 1: RTP_CHANGE=Yes CAPS_CHANGE=Yes RSVP_ADDR_CHANGE=No RSVP_MEDIA_CHANGE=No
010521: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPICompareVersionSessionId: No change in sessid/version id but change in codec/addr/port !!
010522: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Media/sipSPICompareSDP: Flags set for call: NEW_MEDIA=Yes DSPDNLD_REQD=Yes IPIP_MEDIA=Yes
010523: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: Entry
010524: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
010525: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
010526: Mar 4 12:51:56.791: //32209/742AD833BE83/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            : Yes
        New Media              : Yes
        DSP DNLD Reqd          : Yes

010527: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
010528: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 172.25.30.21
010529: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32209 peer 32208 flags 0x407485 state STATE_SENT_MIDCALL_INVITE
010530: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 32209, sdp 0x47DAEDCC channels 0x4A0D2494
010531: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/copy_channels:
callId 32209 size 240 ptr 0x4A3C0764)
010532: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
xmitFunc is set to voip_rtp_xmit for Call 32209
010533: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/ccsip_remote_codec_download_done:
callId 32209 context 0x4A654B00
010534: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
010535: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
010536: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/codec_found:
Codec to be matched: 5
010537: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5

010538: Mar 4 12:51:56.791: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
010539: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
010540: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 5 ptype 0 time 20, bytes 160 as channel 0 mline 1 ss 1 172.25.30.21:19154
010541: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
010542: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Call 32209 dtmf ptype 101 nte/oob enabled
010543: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 32209, dtmf = 6
010544: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5

010545: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

010546: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 32209 flags 0x100 state STATE_SENT_MIDCALL_INVITE
010547: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC04018, ccb->pld.flags_ipip 0x407485

010548: Mar 4 12:51:56.791: //32209/742AD833BE83/SIP/Info/sipSPI_ipip_report_media_to_peer: IN STATE 18, get new media. Post CAPS to peer.

010549: Mar 4 12:51:56.791: //32208/742AD833BE83/SIP/Info/ccsip_caps_ind: Entry
010550: Mar 4 12:51:56.791: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind:
destCallID=32208, srcCallID=32209,
                         peer_ccb->call_info.currentLocalName=Manager,
                         peer_ccb->call_info.currentRemoteName=,
                         ccb->call_info.currentLocalName=,
                         ccb->call_info.currentRemoteName=
010551: Mar 4 12:51:56.791: //32208/742AD833BE83/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=32208, current_seq_num=0x6EE
010552: Mar 4 12:51:56.791: //32208/742AD833BE83/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=32208, current_seq_num=0x6EE
010723: Mar 4 12:51:56.827: //32208/742AD833BE83/SIP/Info/sipSPIResumeStartNotificationRequest: sipSPIResumeStartNotificationRequest: Resume Type=Unknown
010724: Mar 4 12:51:56.827: //32208/742AD833BE83/SIP/Info/sipSPIProcessIncomingAckForMidCall: ccsip_api_modify_session_done returned: SIP_SUCCESS
010725: Mar 4 12:52:05.763: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnAgeing: Holder=0x4A65F574 Connection=0x48F94D54, addr=0.0.0.1, port=-1407711474, connid=0 has been REFRESHED
010726: Mar 4 12:52:05.763: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x4A65F574,addr=172.24.7.14
010727: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
010728: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010729: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010730: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INFO sip:4095@172.25.30.21:5060 SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+d5ec76637c136c8db05a118796ab3a14+10.107.177.95+8
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
CSeq: 392882339 INFO
Supported: replaces
Content-Type: application/dtmf-relay
Content-Length: 24
User-Agent: Wave/10.5.3021.2152

Signal=1
Duration=100

010731: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010732: Mar 4 12:52:13.591: //32208/742AD833BE83/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4A0E0A28
010733: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010734: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010735: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010736: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentBsoft: No Broadsoft body found in inbound container
010737: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
010738: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
010739: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
010740: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/sip_info_parse_dtmf: Parsed digit=1, duration=100ms, retval=1
010741: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentMediaControl: No media_control body found in inbound container
010742: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_INFO_RESP
010743: Mar 4 12:52:13.591: //32208/742AD833BE83/SIP/Info/sipSPIHandleInfoRequest: ccsip_api_call_info_ind returned: SIP_SUCCESS
010744: Mar 4 12:52:13.591: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 34
010745: Mar 4 12:52:13.591: //32208/742AD833BE83/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
010746: Mar 4 12:52:13.591: //32208/742AD833BE83/SIP/Transport/sipSPISendResponse: Sending INFO Response to the transport layer
010747: Mar 4 12:52:13.591: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x4A3DEDB8, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
010748: Mar 4 12:52:13.591: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
010749: Mar 4 12:52:13.595: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
010750: Mar 4 12:52:13.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4A3DEDB8, addr=10.107.177.95, port=5060, connId=0 for UDP
010751: Mar 4 12:52:13.595: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+d5ec76637c136c8db05a118796ab3a14+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
Date: Thu, 04 Mar 2010 17:52:13 GMT
Call-ID: E258D551@10.107.177.95
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 392882339 INFO
Contact: <4095>
Content-Length: 0

010752: Mar 4 12:52:14.155: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
010753: Mar 4 12:52:14.155: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010754: Mar 4 12:52:14.155: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010755: Mar 4 12:52:14.155: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INFO sip:4095@172.25.30.21:5060 SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+236770c02920565fe0d05aa8587cd7fb+10.107.177.95+8
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
CSeq: 392882340 INFO
Supported: replaces
Content-Type: application/dtmf-relay
Content-Length: 24
User-Agent: Wave/10.5.3021.2152

Signal=2
Duration=100

010756: Mar 4 12:52:14.155: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010757: Mar 4 12:52:14.159: //32208/742AD833BE83/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4A0E0A28
010758: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010759: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010760: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010761: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentBsoft: No Broadsoft body found in inbound container
010762: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
010763: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
010764: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
010765: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/sip_info_parse_dtmf: Parsed digit=2, duration=100ms, retval=1
010766: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentMediaControl: No media_control body found in inbound container
010767: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_INFO_RESP
010768: Mar 4 12:52:14.159: //32208/742AD833BE83/SIP/Info/sipSPIHandleInfoRequest: ccsip_api_call_info_ind returned: SIP_SUCCESS
010769: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 34
010770: Mar 4 12:52:14.159: //32208/742AD833BE83/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
010771: Mar 4 12:52:14.159: //32208/742AD833BE83/SIP/Transport/sipSPISendResponse: Sending INFO Response to the transport layer
010772: Mar 4 12:52:14.159: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x47DBABF4, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
010773: Mar 4 12:52:14.159: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
010774: Mar 4 12:52:14.159: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
010775: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x47DBABF4, addr=10.107.177.95, port=5060, connId=0 for UDP
010776: Mar 4 12:52:14.159: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+236770c02920565fe0d05aa8587cd7fb+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
Date: Thu, 04 Mar 2010 17:52:14 GMT
Call-ID: E258D551@10.107.177.95
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 392882340 INFO
Contact: <4095>
Content-Length: 0

010777: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
010778: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010779: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010780: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INFO sip:4095@172.25.30.21:5060 SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+abd9675718a3a55dbe2bcdf653fe09ed+10.107.177.95+8
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
CSeq: 392882341 INFO
Supported: replaces
Content-Type: application/dtmf-relay
Content-Length: 24
User-Agent: Wave/10.5.3021.2152

Signal=3
Duration=100

010781: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010782: Mar 4 12:52:14.339: //32208/742AD833BE83/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4A0E0A28
010783: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010784: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010785: Mar 4 12:52:14.339: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010786: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentBsoft: No Broadsoft body found in inbound container
010787: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
010788: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
010789: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
010790: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Info/sip_info_parse_dtmf: Parsed digit=3, duration=100ms, retval=1
010791: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentMediaControl: No media_control body found in inbound container
010792: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_INFO_RESP
010793: Mar 4 12:52:14.343: //32208/742AD833BE83/SIP/Info/sipSPIHandleInfoRequest: ccsip_api_call_info_ind returned: SIP_SUCCESS
010794: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 34
010795: Mar 4 12:52:14.343: //32208/742AD833BE83/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
010796: Mar 4 12:52:14.343: //32208/742AD833BE83/SIP/Transport/sipSPISendResponse: Sending INFO Response to the transport layer
010797: Mar 4 12:52:14.343: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x4958CDB0, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
010798: Mar 4 12:52:14.343: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
010799: Mar 4 12:52:14.343: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
010800: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4958CDB0, addr=10.107.177.95, port=5060, connId=0 for UDP
010801: Mar 4 12:52:14.343: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+abd9675718a3a55dbe2bcdf653fe09ed+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
Date: Thu, 04 Mar 2010 17:52:14 GMT
Call-ID: E258D551@10.107.177.95
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 392882341 INFO
Contact: <4095>
Content-Length: 0

010802: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
010803: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010804: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010805: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INFO sip:4095@172.25.30.21:5060 SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+65ea2382cfa185fad97ab2f0db54a12a+10.107.177.95+8
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
CSeq: 392882342 INFO
Supported: replaces
Content-Type: application/dtmf-relay
Content-Length: 24
User-Agent: Wave/10.5.3021.2152

Signal=4
Duration=100

010806: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010807: Mar 4 12:52:14.751: //32208/742AD833BE83/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4A0E0A28
010808: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010809: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010810: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010811: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentBsoft: No Broadsoft body found in inbound container
010812: Mar 4 12:52:14.751: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
010813: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
010814: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
010815: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Info/sip_info_parse_dtmf: Parsed digit=4, duration=100ms, retval=1
010816: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentMediaControl: No media_control body found in inbound container
010817: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_INFO_RESP
010818: Mar 4 12:52:14.755: //32208/742AD833BE83/SIP/Info/sipSPIHandleInfoRequest: ccsip_api_call_info_ind returned: SIP_SUCCESS
010819: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 34
010820: Mar 4 12:52:14.755: //32208/742AD833BE83/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
010821: Mar 4 12:52:14.755: //32208/742AD833BE83/SIP/Transport/sipSPISendResponse: Sending INFO Response to the transport layer
010822: Mar 4 12:52:14.755: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x4A3DEDB8, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
010823: Mar 4 12:52:14.755: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
010824: Mar 4 12:52:14.755: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
010825: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x4A3DEDB8, addr=10.107.177.95, port=5060, connId=0 for UDP
010826: Mar 4 12:52:14.755: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+65ea2382cfa185fad97ab2f0db54a12a+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
Date: Thu, 04 Mar 2010 17:52:14 GMT
Call-ID: E258D551@10.107.177.95
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 392882342 INFO
Contact: <4095>
Content-Length: 0

010827: Mar 4 12:52:15.743: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.107.177.95]:5060
010828: Mar 4 12:52:15.743: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
010829: Mar 4 12:52:15.743: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x00000000
010830: Mar 4 12:52:15.743: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INFO sip:4095@172.25.30.21:5060 SIP/2.0
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+64595c2c972c7ec79289c7094af63b9a+10.107.177.95+8
Max-Forwards: 70
Call-ID: E258D551@10.107.177.95
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
CSeq: 392882343 INFO
Supported: replaces
Content-Type: application/dtmf-relay
Content-Length: 25
User-Agent: Wave/10.5.3021.2152

Signal=11
Duration=100

010831: Mar 4 12:52:15.743: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
010832: Mar 4 12:52:15.743: //32208/742AD833BE83/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x4A0E0A28
010833: Mar 4 12:52:15.743: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010834: Mar 4 12:52:15.743: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
010835: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.107.177.95,Port 5060, Transport 1, SentBy Port 5060
010836: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentBsoft: No Broadsoft body found in inbound container
010837: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
010838: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
010839: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
010840: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Info/sip_info_parse_dtmf: Parsed digit=1, duration=100ms, retval=1
010841: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentMediaControl: No media_control body found in inbound container
010842: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_INFO_RESP
010843: Mar 4 12:52:15.747: //32208/742AD833BE83/SIP/Info/sipSPIHandleInfoRequest: ccsip_api_call_info_ind returned: SIP_SUCCESS
010844: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 34
010845: Mar 4 12:52:15.747: //32208/742AD833BE83/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
010846: Mar 4 12:52:15.747: //32208/742AD833BE83/SIP/Transport/sipSPISendResponse: Sending INFO Response to the transport layer
010847: Mar 4 12:52:15.747: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: msg=0x47DBABF4, addr=10.107.177.95, port=5060, sentBy_port=5060, is_req=0, transport=1, switch=0, callBack=0x00000000
010848: Mar 4 12:52:15.747: //32208/742AD833BE83/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
010849: Mar 4 12:52:15.747: //32208/742AD833BE83/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
010850: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x47DBABF4, addr=10.107.177.95, port=5060, connId=0 for UDP
010851: Mar 4 12:52:15.747: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.107.177.95;branch=z9hG4bK+64595c2c972c7ec79289c7094af63b9a+10.107.177.95+8
From: "Manager"<100>;tag=10.107.177.95+8+1740001+dc7af6ae
To: ""<4095>;tag=244F8DC4-21CE
Date: Thu, 04 Mar 2010 17:52:15 GMT
Call-ID: E258D551@10.107.177.95
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 392882343 INFO
Contact: <4095>
Content-Length: 0

AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#
AAPUSVAARPTVG02#no debug all
All possible debugging has been turned off
AAPUSVAARPTVG02#exit